[Samba] disappearing directory
Michael Tokarev
mjt at tls.msk.ru
Tue Nov 12 18:46:19 UTC 2024
12.11.2024 20:24, Jeremy Allison wrote:
> On Tue, Nov 12, 2024 at 02:37:40PM +0300, Michael Tokarev via samba wrote:
>>
>> So it looks like a bug in samba.
>>
>> Any help I can provide to find and fix this one, while the issue can
>> be reproduced here?
>
> Debug level 10 logs. They will allow you to trace through all
> codepaths.
Heh. I had debug 9 logs before sending the original report.
And the prob is still reproducible.
Attached is a debug10 log with immediate attempt to chdir to
the famous dir, "strakh/release.4/Rossita_prepare", which is
still there but reported as non-existent. And it is quite
apparent that samba is trying to open just the last component
of it, not whole path.
/mjt
-------------- next part --------------
[2024/11/12 21:38:45.946996, 5, pid=92084, effective(0, 0), real(0, 0)] lib/util/debug.c:912(debug_dump_status)
INFO: Current debug levels:
all: 10
tdb: 10
printdrivers: 10
lanman: 10
smb: 10
rpc_parse: 10
rpc_srv: 10
rpc_cli: 10
passdb: 10
sam: 10
auth: 10
winbind: 10
vfs: 10
idmap: 10
quota: 10
acls: 10
locking: 10
msdfs: 10
dmapi: 10
registry: 10
scavenger: 10
dns: 10
ldb: 10
tevent: 10
auth_audit: 10
auth_json_audit: 10
kerberos: 10
drs_repl: 10
smb2: 10
smb2_credits: 10
dsdb_audit: 10
dsdb_json_audit: 10
dsdb_password_audit: 10
dsdb_password_json_audit: 10
dsdb_transaction_audit: 10
dsdb_transaction_json_audit: 10
dsdb_group_audit: 10
dsdb_group_json_audit: 10
ldapsrv: 10
[2024/11/12 21:38:48.134101, 10, pid=92084, effective(0, 0), real(0, 0), class=smb2] source3/smbd/smb2_server.c:5099(smbd_smb2_advance_incoming)
smbd_smb2_request idx[1] of 5 vectors
[2024/11/12 21:38:48.134170, 10, pid=92084, effective(0, 0), real(0, 0), class=smb2_credits] source3/smbd/smb2_server.c:799(smb2_validate_sequence_number)
smb2_validate_sequence_number: smb2_validate_sequence_number: clearing id 2602 (position 2602) from bitmap
[2024/11/12 21:38:48.134211, 10, pid=92084, effective(0, 0), real(0, 0), class=smb2] source3/smbd/smb2_server.c:3066(smbd_smb2_request_dispatch)
smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 2602
[2024/11/12 21:38:48.134244, 4, pid=92084, effective(0, 0), real(0, 0)] source3/smbd/sec_ctx.c:317(set_sec_ctx_internal)
setting sec ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2024/11/12 21:38:48.134288, 5, pid=92084, effective(0, 0), real(0, 0)] libcli/security/security_token.c:133(security_token_debug)
Security token SIDs (27):
SID[ 0]: S-1-5-21-411424318-379842365-2075518510-3000
SID[ 1]: S-1-5-21-411424318-379842365-2075518510-513
SID[ 2]: S-1-5-21-411424318-379842365-2075518510-555
SID[ 3]: S-1-5-21-411424318-379842365-2075518510-6738
SID[ 4]: S-1-18-1
SID[ 5]: S-1-5-21-0-0-0-497
SID[ 6]: S-1-22-2-1000
SID[ 7]: S-1-22-2-50
SID[ 8]: S-1-22-2-100
SID[ 9]: S-1-22-2-115
SID[ 10]: S-1-22-2-503
SID[ 11]: S-1-22-2-506
SID[ 12]: S-1-22-2-628
SID[ 13]: S-1-22-2-633
SID[ 14]: S-1-22-2-624
SID[ 15]: S-1-22-2-802
SID[ 16]: S-1-22-2-817
SID[ 17]: S-1-22-2-2005
SID[ 18]: S-1-1-0
SID[ 19]: S-1-5-2
SID[ 20]: S-1-5-11
SID[ 21]: S-1-5-32-545
SID[ 22]: S-1-22-1-1000
SID[ 23]: S-1-22-2-3004
SID[ 24]: S-1-22-2-5000
SID[ 25]: S-1-22-2-5001
SID[ 26]: S-1-22-2-5002
Privileges (0x 0):
Rights (0x 0):
[2024/11/12 21:38:48.134502, 5, pid=92084, effective(0, 0), real(0, 0)] source3/auth/token_util.c:912(debug_unix_user_token)
UNIX token of user 1000
Primary group is 1000 and contains 16 supplementary groups
Group[ 0]: 3004
Group[ 1]: 1000
Group[ 2]: 50
Group[ 3]: 100
Group[ 4]: 115
Group[ 5]: 503
Group[ 6]: 506
Group[ 7]: 628
Group[ 8]: 633
Group[ 9]: 624
Group[ 10]: 802
Group[ 11]: 817
Group[ 12]: 2005
Group[ 13]: 5000
Group[ 14]: 5001
Group[ 15]: 5002
[2024/11/12 21:38:48.134667, 4, pid=92084, effective(1000, 1000), real(1000, 0), class=vfs] source3/smbd/vfs.c:938(vfs_ChDir)
vfs_ChDir to /ws/ws
[2024/11/12 21:38:48.134705, 5, pid=92084, effective(1000, 1000), real(1000, 0), class=vfs] source3/smbd/vfs.c:1000(vfs_ChDir)
vfs_ChDir: vfs_ChDir got /ws/ws
[2024/11/12 21:38:48.134727, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/uid.c:465(print_impersonation_info)
print_impersonation_info: Impersonated user: uid=(1000,1000), gid=(0,1000), cwd=[/ws/ws]
[2024/11/12 21:38:48.134791, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2] source3/smbd/smb2_create.c:289(smbd_smb2_request_process_create)
smbd_smb2_request_process_create:
Got 2 create blobs
[0]
[0000] 4D 78 41 63 MxAc
[1]
[0000] 52 71 4C 73 RqLs
[0000] 7E D9 30 C1 5B EE B9 54 36 EF 84 3C 39 B6 31 FC ~.0.[..T 6..<9.1.
[0010] 07 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........
[0020] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........
[0030] 00 00 00 00 ....
[2024/11/12 21:38:48.134869, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2] source3/smbd/smb2_create.c:812(smbd_smb2_create_send)
smbd_smb2_create_send: name [strakh\release.4\Rossita_prepare]
[2024/11/12 21:38:48.134888, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2] source3/smbd/smb2_create.c:1449(smbd_smb2_create_before_exec)
Got lease request size 52
[2024/11/12 21:38:48.134941, 1, pid=92084, effective(1000, 1000), real(1000, 0), class=rpc_parse] source3/smbd/smb2_create.c:1451(smbd_smb2_create_before_exec)
state->lease_ptr: struct smb2_lease
lease_key: struct smb2_lease_key
data: ARRAY(2)
data : 0x54b9ee5bc130d97e (6105172847728056702)
data : 0xfc31b6393c84ef36 (-274237745348153546)
lease_state : 0x00000007 (7)
1: SMB2_LEASE_READ
1: SMB2_LEASE_HANDLE
1: SMB2_LEASE_WRITE
lease_flags : 0x00000000 (0)
lease_duration : 0x0000000000000000 (0)
parent_lease_key: struct smb2_lease_key
data: ARRAY(2)
data : 0x0000000000000000 (0)
data : 0x0000000000000000 (0)
lease_version : 0x0002 (2)
lease_epoch : 0x0000 (0)
[2024/11/12 21:38:48.135078, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2] source3/smbd/smb2_create.c:948(smbd_smb2_create_send)
smbd_smb2_create_send: open execution phase
[2024/11/12 21:38:48.135098, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:563(openat_pathref_fsp)
openat_pathref_fsp: smb_fname [.]
[2024/11/12 21:38:48.135114, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:463(openat_pathref_fullname)
openat_pathref_fullname: smb_fname [.]
[2024/11/12 21:38:48.135130, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:78(fsp_new)
fsp_new: allocated files structure (9 used)
[2024/11/12 21:38:48.135148, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:2490(file_name_hash)
file_name_hash: /ws/ws/. hash 0x3eac6da4
[2024/11/12 21:38:48.135180, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/open.c:926(fd_openat)
fd_openat: name ., flags = 04000 mode = 00, fd = 13
[2024/11/12 21:38:48.135197, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:532(openat_pathref_fullname)
openat_pathref_fullname: fsp [.]: OK
[2024/11/12 21:38:48.135214, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:78(fsp_new)
fsp_new: allocated files structure (10 used)
[2024/11/12 21:38:48.135230, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:2490(file_name_hash)
file_name_hash: /ws/ws/Rossita_prepare hash 0xcf37db52
[2024/11/12 21:38:48.135253, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/mangle_hash2.c:415(is_mangled)
is_mangled Rossita_prepare ?
[2024/11/12 21:38:48.135270, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/mangle_hash2.c:354(is_mangled_component)
is_mangled_component Rossita_prepare (len 15) ?
[2024/11/12 21:38:48.135286, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:78(fsp_new)
fsp_new: allocated files structure (11 used)
[2024/11/12 21:38:48.135301, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:116(fsp_bind_smb)
fsp_bind_smb: INTERNAL_OPEN_ONLY, skipping smbXsrv_open
[2024/11/12 21:38:48.135315, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:180(file_new)
file_new: new file fnum [invalid value]
[2024/11/12 21:38:48.135331, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:2490(file_name_hash)
file_name_hash: /ws/ws/. hash 0x3eac6da4
[2024/11/12 21:38:48.135358, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/open.c:926(fd_openat)
fd_openat: name ., flags = 0400000 mode = 00, fd = 37
[2024/11/12 21:38:48.135402, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:2277(file_free)
file_free: freed files structure 0 (10 used)
[2024/11/12 21:38:48.135419, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:954(smb_vfs_openat_ci)
smb_vfs_openat_ci: get_real_filename_at() failed: NT_STATUS_OBJECT_NAME_NOT_FOUND
[2024/11/12 21:38:48.135437, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:1534(openat_pathref_fsp_lcomp)
openat_pathref_fsp_lcomp: smb_vfs_openat(./Rossita_prepare) failed: No such file or directory
[2024/11/12 21:38:48.135457, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:2277(file_free)
file_free: freed files structure 0 (9 used)
[2024/11/12 21:38:48.135483, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/mangle_hash2.c:415(is_mangled)
is_mangled Rossita_prepare ?
[2024/11/12 21:38:48.135499, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/mangle_hash2.c:354(is_mangled_component)
is_mangled_component Rossita_prepare (len 15) ?
[2024/11/12 21:38:48.135515, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/open.c:6653(create_file_default)
create_file_default: access_mask = 0x1048705 file_attributes = 0x0 share_access = 0x7 create_disposition = 0x1 create_options = 0x0 oplock_request = 0x256 private_flags = 0x0 ea_list = (nil), sd = (nil), fname = Rossita_prepare
[2024/11/12 21:38:48.135534, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/open.c:6046(create_file_unixpath)
create_file_unixpath: access_mask = 0x100081 file_attributes = 0x0 share_access = 0x7 create_disposition = 0x1 create_options = 0x0 oplock_request = 0x100 private_flags = 0x0 ea_list = (nil), sd = (nil), fname = Rossita_prepare
[2024/11/12 21:38:48.135551, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=locking] source3/locking/leases_db.c:79(leases_db_key)
leases_db_key:
[2024/11/12 21:38:48.135590, 1, pid=92084, effective(1000, 1000), real(1000, 0), class=rpc_parse] source3/locking/leases_db.c:80(leases_db_key)
&db_key: struct leases_db_key
client_guid : 5fe88cc7-9563-11ef-a2a9-7824af9a178d
lease_key: struct smb2_lease_key
data: ARRAY(2)
data : 0x54b9ee5bc130d97e (6105172847728056702)
data : 0xfc31b6393c84ef36 (-274237745348153546)
[2024/11/12 21:38:48.135648, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:78(fsp_new)
fsp_new: allocated files structure (10 used)
[2024/11/12 21:38:48.135671, 5, pid=92084, effective(1000, 1000), real(1000, 0)] lib/dbwrap/dbwrap.c:172(dbwrap_lock_order_lock)
dbwrap_lock_order_lock: check lock order 1 for /run/samba/smbXsrv_open_global.tdb
[2024/11/12 21:38:48.135686, 10, pid=92084, effective(1000, 1000), real(1000, 0)] lib/dbwrap/dbwrap.c:157(debug_lock_order)
lock order: 1:/run/samba/smbXsrv_open_global.tdb 2:<none> 3:<none> 4:<none>
[2024/11/12 21:38:48.135713, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/smbXsrv_open.c:346(smbXsrv_open_global_store)
smbXsrv_open_global_store: key '413366E7' stored
[2024/11/12 21:38:48.135847, 1, pid=92084, effective(1000, 1000), real(1000, 0), class=rpc_parse] source3/smbd/smbXsrv_open.c:347(smbXsrv_open_global_store)
&global_blob: struct smbXsrv_open_globalB
version : SMBXSRV_VERSION_0 (0)
seqnum : 0x00000001 (1)
info : union smbXsrv_open_globalU(case 0)
info0 : *
info0: struct smbXsrv_open_global0
server_id: struct server_id
pid : 0x00000000000167b4 (92084)
task_id : 0x00000000 (0)
vnn : 0xffffffff (4294967295)
unique_id : 0x6c4ec124f455fa82 (7804387568741907074)
open_global_id : 0x413366e7 (1093887719)
open_persistent_id : 0x00000000413366e7 (1093887719)
open_volatile_id : 0x000000007b971150 (2073497936)
open_owner : S-1-5-21-411424318-379842365-2075518510-3000
open_time : Tue Nov 12 21:38:48 2024 MSK
create_guid : 00000000-0000-0000-0000-000000000000
client_guid : 5fe88cc7-9563-11ef-a2a9-7824af9a178d
app_instance_id : 00000000-0000-0000-0000-000000000000
disconnect_time : NTTIME(0)
durable_timeout_msec : 0x00000000 (0)
durable : 0x00 (0)
backend_cookie : DATA_BLOB length=0
channel_sequence : 0x0000 (0)
channel_generation : 0x0000000000000000 (0)
lock_sequence_array: ARRAY(64)
[0000] FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........
[0010] FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........
[0020] FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........
[0030] FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........
[2024/11/12 21:38:48.136075, 5, pid=92084, effective(1000, 1000), real(1000, 0)] lib/dbwrap/dbwrap.c:204(dbwrap_lock_order_unlock)
dbwrap_lock_order_unlock: release lock order 1 for /run/samba/smbXsrv_open_global.tdb
[2024/11/12 21:38:48.136092, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/smbXsrv_open.c:463(smbXsrv_open_global_allocate)
smbXsrv_open_global_allocate: Found slot 1093887719
[2024/11/12 21:38:48.136107, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/smbXsrv_open.c:605(smbXsrv_open_create)
smbXsrv_open_create: global_id (0x413366e7) stored
[2024/11/12 21:38:48.136235, 1, pid=92084, effective(1000, 1000), real(1000, 0), class=rpc_parse] source3/smbd/smbXsrv_open.c:607(smbXsrv_open_create)
&open_blob: struct smbXsrv_openB
version : SMBXSRV_VERSION_0 (0)
reserved : 0x00000000 (0)
info : union smbXsrv_openU(case 0)
info0 : *
info0: struct smbXsrv_open
table : *
local_id : 0x7b971150 (2073497936)
global : *
global: struct smbXsrv_open_global0
server_id: struct server_id
pid : 0x00000000000167b4 (92084)
task_id : 0x00000000 (0)
vnn : 0xffffffff (4294967295)
unique_id : 0x6c4ec124f455fa82 (7804387568741907074)
open_global_id : 0x413366e7 (1093887719)
open_persistent_id : 0x00000000413366e7 (1093887719)
open_volatile_id : 0x000000007b971150 (2073497936)
open_owner : S-1-5-21-411424318-379842365-2075518510-3000
open_time : Tue Nov 12 21:38:48 2024 MSK
create_guid : 00000000-0000-0000-0000-000000000000
client_guid : 5fe88cc7-9563-11ef-a2a9-7824af9a178d
app_instance_id : 00000000-0000-0000-0000-000000000000
disconnect_time : NTTIME(0)
durable_timeout_msec : 0x00000000 (0)
durable : 0x00 (0)
backend_cookie : DATA_BLOB length=0
channel_sequence : 0x0000 (0)
channel_generation : 0x0000000000000000 (0)
lock_sequence_array: ARRAY(64)
[0000] FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........
[0010] FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........
[0020] FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........
[0030] FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........
status : NT_STATUS_OK
idle_time : Tue Nov 12 21:38:48 2024 MSK
compat : NULL
flags : 0x00 (0)
0: SMBXSRV_OPEN_NEED_REPLAY_CACHE
0: SMBXSRV_OPEN_HAVE_REPLAY_CACHE
create_action : 0x00000000 (0)
request_count : 0x0000000000000000 (0)
pre_request_count : 0x0000000000000000 (0)
[2024/11/12 21:38:48.136544, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:136(fsp_bind_smb)
fsp_bind_smb: fsp [] mid [2602]
[2024/11/12 21:38:48.136560, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:180(file_new)
file_new: new file fnum 2073497936
[2024/11/12 21:38:48.136577, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:2490(file_name_hash)
file_name_hash: /ws/ws/Rossita_prepare hash 0xcf37db52
[2024/11/12 21:38:48.136595, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/dosmode.c:194(unix_mode)
unix_mode: unix_mode(Rossita_prepare) returning 0664
[2024/11/12 21:38:48.136611, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/open.c:3943(open_file_ntcreate)
open_file_ntcreate: fname=Rossita_prepare, dos_attrs=0x0 access_mask=0x100081 share_access=0x7 create_disposition = 0x1 create_options=0x0 unix mode=0664 oplock_request=256 private_flags = 0x0
[2024/11/12 21:38:48.136628, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/open.c:4028(open_file_ntcreate)
open_file_ntcreate: FILE_OPEN requested for file Rossita_prepare and file doesn't exist.
[2024/11/12 21:38:48.136643, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/open.c:6604(create_file_unixpath)
create_file_unixpath: NT_STATUS_OBJECT_NAME_NOT_FOUND
[2024/11/12 21:38:48.136660, 5, pid=92084, effective(1000, 1000), real(1000, 0)] lib/dbwrap/dbwrap.c:172(dbwrap_lock_order_lock)
dbwrap_lock_order_lock: check lock order 1 for /run/samba/smbXsrv_open_global.tdb
[2024/11/12 21:38:48.136674, 10, pid=92084, effective(1000, 1000), real(1000, 0)] lib/dbwrap/dbwrap.c:157(debug_lock_order)
lock order: 1:/run/samba/smbXsrv_open_global.tdb 2:<none> 3:<none> 4:<none>
[2024/11/12 21:38:48.136695, 5, pid=92084, effective(1000, 1000), real(1000, 0)] lib/dbwrap/dbwrap.c:204(dbwrap_lock_order_unlock)
dbwrap_lock_order_unlock: release lock order 1 for /run/samba/smbXsrv_open_global.tdb
[2024/11/12 21:38:48.136711, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:2277(file_free)
file_free: freed files structure 2073497936 (9 used)
[2024/11/12 21:38:48.136727, 10, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/open.c:6796(create_file_default)
create_file: NT_STATUS_OBJECT_NAME_NOT_FOUND
[2024/11/12 21:38:48.136746, 3, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2] source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex)
smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at source3/smbd/smb2_create.c:362
[2024/11/12 21:38:48.136763, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2] source3/smbd/smb2_server.c:3937(smbd_smb2_request_done_ex)
smbd_smb2_request_done_ex: mid [2602] idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] body[8] dyn[yes:1] at source3/smbd/smb2_server.c:4103
[2024/11/12 21:38:48.136780, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2_credits] source3/smbd/smb2_server.c:1056(smb2_set_operation_credit)
smb2_set_operation_credit: smb2_set_operation_credit: requested 1, charge 1, granted 1, current possible/max 8019/8192, total granted/max/low/range 174/8192/2603/174
[2024/11/12 21:38:48.136827, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/files.c:2277(file_free)
file_free: freed files structure 0 (8 used)
[2024/11/12 21:38:48.165560, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2] source3/smbd/smb2_server.c:5099(smbd_smb2_advance_incoming)
smbd_smb2_request idx[1] of 5 vectors
[2024/11/12 21:38:48.165612, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2_credits] source3/smbd/smb2_server.c:799(smb2_validate_sequence_number)
smb2_validate_sequence_number: smb2_validate_sequence_number: clearing id 2603 (position 2603) from bitmap
[2024/11/12 21:38:48.165667, 10, pid=92084, effective(1000, 1000), real(1000, 0), class=smb2] source3/smbd/smb2_server.c:3066(smbd_smb2_request_dispatch)
smbd_smb2_request_dispatch: opcode[SMB2_OP_TCON] mid = 2603
[2024/11/12 21:38:48.165699, 4, pid=92084, effective(1000, 1000), real(1000, 0)] source3/smbd/sec_ctx.c:317(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2024/11/12 21:38:48.165718, 5, pid=92084, effective(1000, 1000), real(1000, 0)] libcli/security/security_token.c:114(security_token_debug)
Security token: (NULL)
[2024/11/12 21:38:48.165740, 5, pid=92084, effective(1000, 1000), real(1000, 0)] source3/auth/token_util.c:912(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2024/11/12 21:38:48.165785, 5, pid=92084, effective(0, 0), real(0, 0)] source3/smbd/uid.c:665(smbd_change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2024/11/12 21:38:48.165813, 10, pid=92084, effective(0, 0), real(0, 0), class=smb2] source3/smbd/smb2_tcon.c:233(smbd_smb2_tree_connect)
smbd_smb2_tree_connect: path[\\tsrv\IPC$] share[IPC$]
[2024/11/12 21:38:48.165852, 5, pid=92084, effective(0, 0), real(0, 0)] lib/dbwrap/dbwrap.c:172(dbwrap_lock_order_lock)
dbwrap_lock_order_lock: check lock order 1 for /run/samba/smbXsrv_tcon_global.tdb
[2024/11/12 21:38:48.165869, 10, pid=92084, effective(0, 0), real(0, 0)] lib/dbwrap/dbwrap.c:157(debug_lock_order)
lock order: 1:/run/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none> 4:<none>
[2024/11/12 21:38:48.165886, 10, pid=92084, effective(0, 0), real(0, 0)] lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
db_tdb_log_key: Locking key 7614D014
[2024/11/12 21:38:48.165906, 10, pid=92084, effective(0, 0), real(0, 0)] lib/dbwrap/dbwrap_tdb.c:153(db_tdb_fetch_locked_internal)
db_tdb_fetch_locked_internal: Allocated locked data 0x5556fdbf8920
[2024/11/12 21:38:48.165949, 10, pid=92084, effective(0, 0), real(0, 0)] source3/smbd/smbXsrv_tcon.c:707(smbXsrv_tcon_global_store)
smbXsrv_tcon_global_store: key '7614D014' stored
[2024/11/12 21:38:48.166024, 1, pid=92084, effective(0, 0), real(0, 0), class=rpc_parse] source3/smbd/smbXsrv_tcon.c:708(smbXsrv_tcon_global_store)
&global_blob: struct smbXsrv_tcon_globalB
version : SMBXSRV_VERSION_0 (0)
seqnum : 0x00000001 (1)
info : union smbXsrv_tcon_globalU(case 0)
info0 : *
info0: struct smbXsrv_tcon_global0
db_rec : *
tcon_global_id : 0x7614d014 (1981075476)
tcon_wire_id : 0x7614d014 (1981075476)
server_id: struct server_id
pid : 0x00000000000167b4 (92084)
task_id : 0x00000000 (0)
vnn : 0xffffffff (4294967295)
unique_id : 0x6c4ec124f455fa82 (7804387568741907074)
creation_time : Tue Nov 12 21:38:48 2024 MSK
share_name : 'IPC$'
encryption_flags : 0x00 (0)
0: SMBXSRV_ENCRYPTION_REQUIRED
0: SMBXSRV_ENCRYPTION_DESIRED
0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET
0: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET
session_global_id : 0x09b3be3a (162774586)
signing_flags : 0x00 (0)
0: SMBXSRV_SIGNING_REQUIRED
0: SMBXSRV_PROCESSED_SIGNED_PACKET
0: SMBXSRV_PROCESSED_UNSIGNED_PACKET
[2024/11/12 21:38:48.166210, 10, pid=92084, effective(0, 0), real(0, 0)] lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
db_tdb_log_key: Unlocking key 7614D014
[2024/11/12 21:38:48.166226, 5, pid=92084, effective(0, 0), real(0, 0)] lib/dbwrap/dbwrap.c:204(dbwrap_lock_order_unlock)
dbwrap_lock_order_unlock: release lock order 1 for /run/samba/smbXsrv_tcon_global.tdb
[2024/11/12 21:38:48.166261, 10, pid=92084, effective(0, 0), real(0, 0)] source3/smbd/smbXsrv_tcon.c:842(smbXsrv_tcon_create)
smbXsrv_tcon_create: global_id (0x7614d014) stored
[2024/11/12 21:38:48.166345, 1, pid=92084, effective(0, 0), real(0, 0), class=rpc_parse] source3/smbd/smbXsrv_tcon.c:844(smbXsrv_tcon_create)
&tcon_blob: struct smbXsrv_tconB
version : SMBXSRV_VERSION_0 (0)
reserved : 0x00000000 (0)
info : union smbXsrv_tconU(case 0)
info0 : *
info0: struct smbXsrv_tcon
table : *
db_rec : NULL
local_id : 0x7614d014 (1981075476)
global : *
global: struct smbXsrv_tcon_global0
db_rec : NULL
tcon_global_id : 0x7614d014 (1981075476)
tcon_wire_id : 0x7614d014 (1981075476)
server_id: struct server_id
pid : 0x00000000000167b4 (92084)
task_id : 0x00000000 (0)
vnn : 0xffffffff (4294967295)
unique_id : 0x6c4ec124f455fa82 (7804387568741907074)
creation_time : Tue Nov 12 21:38:48 2024 MSK
share_name : 'IPC$'
encryption_flags : 0x00 (0)
0: SMBXSRV_ENCRYPTION_REQUIRED
0: SMBXSRV_ENCRYPTION_DESIRED
0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET
0: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET
session_global_id : 0x09b3be3a (162774586)
signing_flags : 0x00 (0)
0: SMBXSRV_SIGNING_REQUIRED
0: SMBXSRV_PROCESSED_SIGNED_PACKET
0: SMBXSRV_PROCESSED_UNSIGNED_PACKET
status : NT_STATUS_INTERNAL_ERROR
idle_time : Tue Nov 12 21:38:48 2024 MSK
compat : NULL
[2024/11/12 21:38:48.166601, 3, pid=92084, effective(0, 0), real(0, 0)] lib/util/access.c:372(allow_access)
Allowed connection from 192.168.19.16 (192.168.19.16)
[2024/11/12 21:38:48.166621, 10, pid=92084, effective(0, 0), real(0, 0)] source3/smbd/share_access.c:117(user_ok_token)
user_ok_token: share IPC$ is ok for unix user TLS\mjt
[2024/11/12 21:38:48.166673, 10, pid=92084, effective(0, 0), real(0, 0)] source3/smbd/smb2_service.c:71(set_conn_connectpath)
set_conn_connectpath: service IPC$, connectpath = /tmp
[2024/11/12 21:38:48.166692, 3, pid=92084, effective(0, 0), real(0, 0)] source3/smbd/smb2_service.c:584(make_connection_snum)
make_connection_snum: Connect path is '/tmp' for service [IPC$]
[2024/1