[2019/08/02 09:33:00.096703, 6, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2336(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Fri Aug 2 09:31:54 2019 [2019/08/02 09:33:00.096744, 3, pid=28084, effective(0, 0), real(0, 0), class=locking] ../source3/smbd/oplock.c:1389(init_oplocks) init_oplocks: initializing messages. [2019/08/02 09:33:00.096756, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 774 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.096767, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 778 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.096776, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 770 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.096784, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 787 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.096793, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 779 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.096802, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 15 - private_data=(nil) [2019/08/02 09:33:00.096811, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:724(messaging_register) Overriding messaging pointer for type 15 - private_data=(nil) [2019/08/02 09:33:00.096820, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:756(messaging_deregister) Deregistering messaging pointer for type 16 - private_data=(nil) [2019/08/02 09:33:00.096829, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 16 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.096856, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:756(messaging_deregister) Deregistering messaging pointer for type 33 - private_data=0x55c3af3a6130 [2019/08/02 09:33:00.096865, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 33 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.096873, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:756(messaging_deregister) Deregistering messaging pointer for type 790 - private_data=(nil) [2019/08/02 09:33:00.096882, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 790 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.096891, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:756(messaging_deregister) Deregistering messaging pointer for type 791 - private_data=(nil) [2019/08/02 09:33:00.096900, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:756(messaging_deregister) Deregistering messaging pointer for type 1 - private_data=(nil) [2019/08/02 09:33:00.096908, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 1 - private_data=(nil) [2019/08/02 09:33:00.096922, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/util_event.c:100(event_add_idle) event_add_idle: idle_evt(keepalive) 0x55c3af3d2190 [2019/08/02 09:33:00.096931, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/util_event.c:100(event_add_idle) event_add_idle: idle_evt(deadtime) 0x55c3af3d23f0 [2019/08/02 09:33:00.096942, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/util_event.c:100(event_add_idle) event_add_idle: idle_evt(housekeeping) 0x55c3af3d2650 [2019/08/02 09:33:00.097046, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/util_sock.c:248(read_smb_length_return_keepalive) got smb length of 174 [2019/08/02 09:33:00.097068, 6, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1954(process_smb) got message type 0x0 of len 0xae [2019/08/02 09:33:00.097078, 3, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1956(process_smb) Transaction 0 of length 178 (0 toread) [2019/08/02 09:33:00.097091, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:3556(smbd_smb2_process_negprot) smbd_smb2_first_negprot: packet length 174 [2019/08/02 09:33:00.097123, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:679(smb2_validate_sequence_number) smb2_validate_sequence_number: smb2_validate_sequence_number: clearing id 0 (position 0) from bitmap [2019/08/02 09:33:00.097142, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:2323(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_NEGPROT] mid = 0 [2019/08/02 09:33:00.097163, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.097178, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.097193, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.097220, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:486(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2019/08/02 09:33:00.097251, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.097265, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:558(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2019/08/02 09:33:00.097274, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.097283, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.097291, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.097340, 10, pid=28084, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:301(gencache_set_data_blob) gencache_set_data_blob: Adding cache entry with key=[RA/5a4d131b-b358-11e9-80fe-525400d13910] and timeout=[Wed Dec 31 07:00:00 PM 1969 EST] (-1564752780 seconds in the past) [2019/08/02 09:33:00.097378, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.097389, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/util.c:1211(set_remote_arch) set_remote_arch: Client arch is 'Vista' [2019/08/02 09:33:00.097418, 6, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2336(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Fri Aug 2 09:31:54 2019 [2019/08/02 09:33:00.097439, 3, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_negprot.c:294(smbd_smb2_request_process_negprot) Selected protocol SMB3_11 [2019/08/02 09:33:00.097456, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:536(make_auth3_context_for_ntlm) Making default auth method list for server role = 'standalone server', encrypt passwords = yes [2019/08/02 09:33:00.097470, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend anonymous [2019/08/02 09:33:00.097489, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'anonymous' [2019/08/02 09:33:00.097499, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend sam [2019/08/02 09:33:00.097508, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'sam' [2019/08/02 09:33:00.097517, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend sam_ignoredomain [2019/08/02 09:33:00.097526, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'sam_ignoredomain' [2019/08/02 09:33:00.097534, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend sam_netlogon3 [2019/08/02 09:33:00.097543, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'sam_netlogon3' [2019/08/02 09:33:00.097554, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend winbind [2019/08/02 09:33:00.097564, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'winbind' [2019/08/02 09:33:00.097573, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:412(load_auth_module) load_auth_module: Attempting to find an auth method to match anonymous [2019/08/02 09:33:00.097582, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:437(load_auth_module) load_auth_module: auth method anonymous has a valid init [2019/08/02 09:33:00.097591, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:412(load_auth_module) load_auth_module: Attempting to find an auth method to match sam_ignoredomain [2019/08/02 09:33:00.097601, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:437(load_auth_module) load_auth_module: auth method sam_ignoredomain has a valid init [2019/08/02 09:33:00.099270, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'gssapi_spnego' registered [2019/08/02 09:33:00.099300, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'gssapi_krb5' registered [2019/08/02 09:33:00.099310, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'gssapi_krb5_sasl' registered [2019/08/02 09:33:00.099322, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'spnego' registered [2019/08/02 09:33:00.099334, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'schannel' registered [2019/08/02 09:33:00.099345, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'naclrpc_as_system' registered [2019/08/02 09:33:00.099354, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'sasl-EXTERNAL' registered [2019/08/02 09:33:00.099366, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'ntlmssp' registered [2019/08/02 09:33:00.099375, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'ntlmssp_resume_ccache' registered [2019/08/02 09:33:00.099385, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'http_basic' registered [2019/08/02 09:33:00.099401, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'http_ntlm' registered [2019/08/02 09:33:00.099411, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:977(gensec_register) GENSEC backend 'http_negotiate' registered [2019/08/02 09:33:00.099477, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:739(gensec_start_mech) Starting GENSEC mechanism spnego [2019/08/02 09:33:00.099509, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:739(gensec_start_mech) Starting GENSEC submechanism ntlmssp [2019/08/02 09:33:00.099541, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:440(gensec_update_send) gensec_update_send: spnego[0x55c3af3d3f60]: subreq: 0x55c3af3d5610 [2019/08/02 09:33:00.099565, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:498(gensec_update_done) gensec_update_done: spnego[0x55c3af3d3f60]: NT_STATUS_MORE_PROCESSING_REQUIRED tevent_req[0x55c3af3d5610/../auth/gensec/spnego.c:1601]: state[2] error[0 (0x0)] state[struct gensec_spnego_update_state (0x55c3af3d57c0)] timer[(nil)] finish[../auth/gensec/spnego.c:2070] [2019/08/02 09:33:00.099615, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:3081(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[64] dyn[yes:140] at ../source3/smbd/smb2_negprot.c:662 [2019/08/02 09:33:00.099632, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:937(smb2_set_operation_credit) smb2_set_operation_credit: smb2_set_operation_credit: requested 33, charge 1, granted 1, current possible/max 512/512, total granted/max/low/range 1/8192/1/1 [2019/08/02 09:33:00.224052, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:3953(smbd_smb2_io_handler) smbd_smb2_request idx[1] of 5 vectors [2019/08/02 09:33:00.224109, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:679(smb2_validate_sequence_number) smb2_validate_sequence_number: smb2_validate_sequence_number: clearing id 1 (position 1) from bitmap [2019/08/02 09:33:00.224124, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:2323(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_SESSSETUP] mid = 1 [2019/08/02 09:33:00.224136, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.224147, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.224157, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.224178, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:486(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2019/08/02 09:33:00.224205, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.224224, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_session_global.tdb 2: 3: [2019/08/02 09:33:00.224244, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key AAD2647B [2019/08/02 09:33:00.224269, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3b9eb0 [2019/08/02 09:33:00.224373, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:948(smbXsrv_session_global_store) [2019/08/02 09:33:00.224385, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:950(smbXsrv_session_global_store) smbXsrv_session_global_store: key 'AAD2647B' stored [2019/08/02 09:33:00.224396, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &global_blob: struct smbXsrv_session_globalB version : SMBXSRV_VERSION_0 (0) seqnum : 0x00000001 (1) info : union smbXsrv_session_globalU(case 0) info0 : * info0: struct smbXsrv_session_global0 db_rec : * session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0311 (785) signing_flags : 0x00 (0) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 0: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x00 (0) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 0: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000000 (0) connection : * encryption_cipher : 0x0000 (0) [2019/08/02 09:33:00.224546, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.224557, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key AAD2647B [2019/08/02 09:33:00.224567, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1323(smbXsrv_session_create) [2019/08/02 09:33:00.224576, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1331(smbXsrv_session_create) smbXsrv_session_create: global_id (0xaad2647b) stored [2019/08/02 09:33:00.224584, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &session_blob: struct smbXsrv_sessionB version : SMBXSRV_VERSION_0 (0) reserved : 0x00000000 (0) info : union smbXsrv_sessionU(case 0) info0 : * info0: struct smbXsrv_session table : * db_rec : NULL client : * local_id : 0xaad2647b (2865915003) global : * global: struct smbXsrv_session_global0 db_rec : NULL session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0311 (785) signing_flags : 0x00 (0) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 0: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x00 (0) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 0: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000000 (0) connection : * encryption_cipher : 0x0000 (0) status : NT_STATUS_MORE_PROCESSING_REQUIRED idle_time : Fri Aug 2 09:33:00 AM 2019 EDT nonce_high_random : 0x0000000000000000 (0) nonce_high_max : 0x0000000000000000 (0) nonce_high : 0x0000000000000000 (0) nonce_low : 0x0000000000000000 (0) compat : NULL tcon_table : * pending_auth : NULL [2019/08/02 09:33:00.224775, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:536(make_auth3_context_for_ntlm) Making default auth method list for server role = 'standalone server', encrypt passwords = yes [2019/08/02 09:33:00.224789, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:412(load_auth_module) load_auth_module: Attempting to find an auth method to match anonymous [2019/08/02 09:33:00.224801, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:437(load_auth_module) load_auth_module: auth method anonymous has a valid init [2019/08/02 09:33:00.224810, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:412(load_auth_module) load_auth_module: Attempting to find an auth method to match sam_ignoredomain [2019/08/02 09:33:00.224819, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:437(load_auth_module) load_auth_module: auth method sam_ignoredomain has a valid init [2019/08/02 09:33:00.224899, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:739(gensec_start_mech) Starting GENSEC mechanism spnego [2019/08/02 09:33:00.224912, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.224922, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_session_global.tdb 2: 3: [2019/08/02 09:33:00.224933, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key AAD2647B [2019/08/02 09:33:00.224944, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3d7990 [2019/08/02 09:33:00.224959, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:948(smbXsrv_session_global_store) [2019/08/02 09:33:00.224967, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:950(smbXsrv_session_global_store) smbXsrv_session_global_store: key 'AAD2647B' stored [2019/08/02 09:33:00.224976, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &global_blob: struct smbXsrv_session_globalB version : SMBXSRV_VERSION_0 (0) seqnum : 0x00000002 (2) info : union smbXsrv_session_globalU(case 0) info0 : * info0: struct smbXsrv_session_global0 db_rec : * session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0311 (785) signing_flags : 0x00 (0) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 0: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x00 (0) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 0: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000000 (0) connection : * encryption_cipher : 0x0000 (0) [2019/08/02 09:33:00.225106, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.225133, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key AAD2647B [2019/08/02 09:33:00.225142, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1418(smbXsrv_session_update) [2019/08/02 09:33:00.225149, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1426(smbXsrv_session_update) smbXsrv_session_update: global_id (0xaad2647b) stored [2019/08/02 09:33:00.225157, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &session_blob: struct smbXsrv_sessionB version : SMBXSRV_VERSION_0 (0) reserved : 0x00000000 (0) info : union smbXsrv_sessionU(case 0) info0 : * info0: struct smbXsrv_session table : * db_rec : NULL client : * local_id : 0xaad2647b (2865915003) global : * global: struct smbXsrv_session_global0 db_rec : NULL session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0311 (785) signing_flags : 0x00 (0) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 0: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x00 (0) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 0: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000000 (0) connection : * encryption_cipher : 0x0000 (0) status : NT_STATUS_MORE_PROCESSING_REQUIRED idle_time : Fri Aug 2 09:33:00 AM 2019 EDT nonce_high_random : 0x0000000000000000 (0) nonce_high_max : 0x0000000000000000 (0) nonce_high : 0x0000000000000000 (0) nonce_low : 0x0000000000000000 (0) compat : NULL tcon_table : * pending_auth : * pending_auth: struct smbXsrv_session_auth0 prev : * next : NULL session : * connection : * gensec : * preauth : * in_flags : 0x00 (0) in_security_mode : 0x01 (1) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT idle_time : Fri Aug 2 09:33:00 AM 2019 EDT [2019/08/02 09:33:00.225385, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.225397, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:558(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2019/08/02 09:33:00.225406, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.225415, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.225424, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.225477, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec_start.c:739(gensec_start_mech) Starting GENSEC submechanism ntlmssp [2019/08/02 09:33:00.225501, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/ntlmssp/ntlmssp_util.c:72(debug_ntlmssp_flags) Got NTLMSSP neg_flags=0xe2088297 NTLMSSP_NEGOTIATE_UNICODE NTLMSSP_NEGOTIATE_OEM NTLMSSP_REQUEST_TARGET NTLMSSP_NEGOTIATE_SIGN NTLMSSP_NEGOTIATE_LM_KEY NTLMSSP_NEGOTIATE_NTLM NTLMSSP_NEGOTIATE_ALWAYS_SIGN NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY NTLMSSP_NEGOTIATE_VERSION NTLMSSP_NEGOTIATE_128 NTLMSSP_NEGOTIATE_KEY_EXCH NTLMSSP_NEGOTIATE_56 [2019/08/02 09:33:00.225743, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) negotiate: struct NEGOTIATE_MESSAGE Signature : 'NTLMSSP' MessageType : NtLmNegotiate (1) NegotiateFlags : 0xe2088297 (3792208535) 1: NTLMSSP_NEGOTIATE_UNICODE 1: NTLMSSP_NEGOTIATE_OEM 1: NTLMSSP_REQUEST_TARGET 1: NTLMSSP_NEGOTIATE_SIGN 0: NTLMSSP_NEGOTIATE_SEAL 0: NTLMSSP_NEGOTIATE_DATAGRAM 1: NTLMSSP_NEGOTIATE_LM_KEY 0: NTLMSSP_NEGOTIATE_NETWARE 1: NTLMSSP_NEGOTIATE_NTLM 0: NTLMSSP_NEGOTIATE_NT_ONLY 0: NTLMSSP_ANONYMOUS 0: NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED 0: NTLMSSP_NEGOTIATE_OEM_WORKSTATION_SUPPLIED 0: NTLMSSP_NEGOTIATE_THIS_IS_LOCAL_CALL 1: NTLMSSP_NEGOTIATE_ALWAYS_SIGN 0: NTLMSSP_TARGET_TYPE_DOMAIN 0: NTLMSSP_TARGET_TYPE_SERVER 0: NTLMSSP_TARGET_TYPE_SHARE 1: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY 0: NTLMSSP_NEGOTIATE_IDENTIFY 0: NTLMSSP_REQUEST_NON_NT_SESSION_KEY 0: NTLMSSP_NEGOTIATE_TARGET_INFO 1: NTLMSSP_NEGOTIATE_VERSION 1: NTLMSSP_NEGOTIATE_128 1: NTLMSSP_NEGOTIATE_KEY_EXCH 1: NTLMSSP_NEGOTIATE_56 DomainNameLen : 0x0000 (0) DomainNameMaxLen : 0x0000 (0) DomainName : NULL WorkstationLen : 0x0000 (0) WorkstationMaxLen : 0x0000 (0) Workstation : NULL Version: struct ntlmssp_VERSION ProductMajorVersion : NTLMSSP_WINDOWS_MAJOR_VERSION_10 (10) ProductMinorVersion : NTLMSSP_WINDOWS_MINOR_VERSION_0 (0) ProductBuild : 0x4563 (17763) Reserved: ARRAY(3) [0] : 0x00 (0) [1] : 0x00 (0) [2] : 0x00 (0) NTLMRevisionCurrent : NTLMSSP_REVISION_W2K3 (15) [2019/08/02 09:33:00.225948, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) challenge: struct CHALLENGE_MESSAGE Signature : 'NTLMSSP' MessageType : NtLmChallenge (0x2) TargetNameLen : 0x0022 (34) TargetNameMaxLen : 0x0022 (34) TargetName : * TargetName : 'CI-VM-10-0-138-64' NegotiateFlags : 0xe28a8215 (3800728085) 1: NTLMSSP_NEGOTIATE_UNICODE 0: NTLMSSP_NEGOTIATE_OEM 1: NTLMSSP_REQUEST_TARGET 1: NTLMSSP_NEGOTIATE_SIGN 0: NTLMSSP_NEGOTIATE_SEAL 0: NTLMSSP_NEGOTIATE_DATAGRAM 0: NTLMSSP_NEGOTIATE_LM_KEY 0: NTLMSSP_NEGOTIATE_NETWARE 1: NTLMSSP_NEGOTIATE_NTLM 0: NTLMSSP_NEGOTIATE_NT_ONLY 0: NTLMSSP_ANONYMOUS 0: NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED 0: NTLMSSP_NEGOTIATE_OEM_WORKSTATION_SUPPLIED 0: NTLMSSP_NEGOTIATE_THIS_IS_LOCAL_CALL 1: NTLMSSP_NEGOTIATE_ALWAYS_SIGN 0: NTLMSSP_TARGET_TYPE_DOMAIN 1: NTLMSSP_TARGET_TYPE_SERVER 0: NTLMSSP_TARGET_TYPE_SHARE 1: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY 0: NTLMSSP_NEGOTIATE_IDENTIFY 0: NTLMSSP_REQUEST_NON_NT_SESSION_KEY 1: NTLMSSP_NEGOTIATE_TARGET_INFO 1: NTLMSSP_NEGOTIATE_VERSION 1: NTLMSSP_NEGOTIATE_128 1: NTLMSSP_NEGOTIATE_KEY_EXCH 1: NTLMSSP_NEGOTIATE_56 ServerChallenge : a9f7fbdd542f224b Reserved : 0000000000000000 TargetInfoLen : 0x0100 (256) TargetInfoMaxLen : 0x0100 (256) TargetInfo : * TargetInfo: struct AV_PAIR_LIST count : 0x00000006 (6) pair: ARRAY(6) pair: struct AV_PAIR AvId : MsvAvNbDomainName (0x2) AvLen : 0x0022 (34) Value : union ntlmssp_AvValue(case 0x2) AvNbDomainName : 'CI-VM-10-0-138-64' pair: struct AV_PAIR AvId : MsvAvNbComputerName (0x1) AvLen : 0x0022 (34) Value : union ntlmssp_AvValue(case 0x1) AvNbComputerName : 'CI-VM-10-0-138-64' pair: struct AV_PAIR AvId : MsvAvDnsDomainName (0x4) AvLen : 0x003c (60) Value : union ntlmssp_AvValue(case 0x4) AvDnsDomainName : 'hosted.upshift.rdu2.redhat.com' pair: struct AV_PAIR AvId : MsvAvDnsComputerName (0x3) AvLen : 0x0060 (96) Value : union ntlmssp_AvValue(case 0x3) AvDnsComputerName : 'ci-vm-10-0-138-64.hosted.upshift.rdu2.redhat.com' pair: struct AV_PAIR AvId : MsvAvTimestamp (0x7) AvLen : 0x0008 (8) Value : union ntlmssp_AvValue(case 0x7) AvTimestamp : Fri Aug 2 09:33:00 AM 2019 EDT pair: struct AV_PAIR AvId : MsvAvEOL (0x0) AvLen : 0x0000 (0) Value : union ntlmssp_AvValue(case 0x0) Version: struct ntlmssp_VERSION ProductMajorVersion : NTLMSSP_WINDOWS_MAJOR_VERSION_6 (0x6) ProductMinorVersion : NTLMSSP_WINDOWS_MINOR_VERSION_1 (0x1) ProductBuild : 0x0000 (0) Reserved : 000000 NTLMRevisionCurrent : NTLMSSP_REVISION_W2K3 (0xF) [2019/08/02 09:33:00.226204, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:440(gensec_update_send) gensec_update_send: ntlmssp[0x55c3af3d9820]: subreq: 0x55c3af3d7c80 [2019/08/02 09:33:00.226215, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:440(gensec_update_send) gensec_update_send: spnego[0x55c3af3d74e0]: subreq: 0x55c3af3d9200 [2019/08/02 09:33:00.226232, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 smbd_smb2_request_pending_queue: req->current_idx = 1 req->in.vector[0].iov_len = 0 req->in.vector[1].iov_len = 0 req->in.vector[2].iov_len = 64 req->in.vector[3].iov_len = 24 req->in.vector[4].iov_len = 74 req->out.vector[0].iov_len = 4 req->out.vector[1].iov_len = 0 req->out.vector[2].iov_len = 64 req->out.vector[3].iov_len = 8 req->out.vector[4].iov_len = 0 [2019/08/02 09:33:00.226277, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:498(gensec_update_done) gensec_update_done: ntlmssp[0x55c3af3d9820]: NT_STATUS_MORE_PROCESSING_REQUIRED tevent_req[0x55c3af3d7c80/../auth/ntlmssp/ntlmssp.c:181]: state[2] error[0 (0x0)] state[struct gensec_ntlmssp_update_state (0x55c3af3d7e30)] timer[(nil)] finish[../auth/ntlmssp/ntlmssp.c:215] [2019/08/02 09:33:00.226306, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:498(gensec_update_done) gensec_update_done: spnego[0x55c3af3d74e0]: NT_STATUS_MORE_PROCESSING_REQUIRED tevent_req[0x55c3af3d9200/../auth/gensec/spnego.c:1601]: state[2] error[0 (0x0)] state[struct gensec_spnego_update_state (0x55c3af3d93b0)] timer[(nil)] finish[../auth/gensec/spnego.c:2070] [2019/08/02 09:33:00.226321, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.226331, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:558(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2019/08/02 09:33:00.226340, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.226349, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.226357, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.226378, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.226389, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:3081(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_MORE_PROCESSING_REQUIRED] body[8] dyn[yes:381] at ../source3/smbd/smb2_sesssetup.c:174 [2019/08/02 09:33:00.226404, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:937(smb2_set_operation_credit) smb2_set_operation_credit: smb2_set_operation_credit: requested 33, charge 1, granted 1, current possible/max 512/512, total granted/max/low/range 1/8192/2/1 [2019/08/02 09:33:00.350888, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:3953(smbd_smb2_io_handler) smbd_smb2_request idx[1] of 5 vectors [2019/08/02 09:33:00.350942, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:679(smb2_validate_sequence_number) smb2_validate_sequence_number: smb2_validate_sequence_number: clearing id 2 (position 2) from bitmap [2019/08/02 09:33:00.350959, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:2323(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_SESSSETUP] mid = 2 [2019/08/02 09:33:00.350975, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.350987, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_session_global.tdb 2: 3: [2019/08/02 09:33:00.351004, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key AAD2647B [2019/08/02 09:33:00.351018, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3e2530 [2019/08/02 09:33:00.351050, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:948(smbXsrv_session_global_store) [2019/08/02 09:33:00.351058, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:950(smbXsrv_session_global_store) smbXsrv_session_global_store: key 'AAD2647B' stored [2019/08/02 09:33:00.351069, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &global_blob: struct smbXsrv_session_globalB version : SMBXSRV_VERSION_0 (0) seqnum : 0x00000003 (3) info : union smbXsrv_session_globalU(case 0) info0 : * info0: struct smbXsrv_session_global0 db_rec : * session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0311 (785) signing_flags : 0x04 (4) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 1: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x08 (8) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 1: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000000 (0) connection : * encryption_cipher : 0x0000 (0) [2019/08/02 09:33:00.351236, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.351248, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key AAD2647B [2019/08/02 09:33:00.351258, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1418(smbXsrv_session_update) [2019/08/02 09:33:00.351265, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1426(smbXsrv_session_update) smbXsrv_session_update: global_id (0xaad2647b) stored [2019/08/02 09:33:00.351274, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &session_blob: struct smbXsrv_sessionB version : SMBXSRV_VERSION_0 (0) reserved : 0x00000000 (0) info : union smbXsrv_sessionU(case 0) info0 : * info0: struct smbXsrv_session table : * db_rec : NULL client : * local_id : 0xaad2647b (2865915003) global : * global: struct smbXsrv_session_global0 db_rec : NULL session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0311 (785) signing_flags : 0x04 (4) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 1: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x08 (8) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 1: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000000 (0) connection : * encryption_cipher : 0x0000 (0) status : NT_STATUS_MORE_PROCESSING_REQUIRED idle_time : Fri Aug 2 09:33:00 AM 2019 EDT nonce_high_random : 0x0000000000000000 (0) nonce_high_max : 0x0000000000000000 (0) nonce_high : 0x0000000000000000 (0) nonce_low : 0x0000000000000000 (0) compat : NULL tcon_table : * pending_auth : * pending_auth: struct smbXsrv_session_auth0 prev : * next : NULL session : * connection : * gensec : * preauth : * in_flags : 0x00 (0) in_security_mode : 0x01 (1) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT idle_time : Fri Aug 2 09:33:00 AM 2019 EDT [2019/08/02 09:33:00.351539, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.351550, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.351560, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.351582, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:486(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2019/08/02 09:33:00.351598, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.351607, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_session_global.tdb 2: 3: [2019/08/02 09:33:00.351619, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key AAD2647B [2019/08/02 09:33:00.351629, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3d6c00 [2019/08/02 09:33:00.351645, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:948(smbXsrv_session_global_store) [2019/08/02 09:33:00.351653, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:950(smbXsrv_session_global_store) smbXsrv_session_global_store: key 'AAD2647B' stored [2019/08/02 09:33:00.351662, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &global_blob: struct smbXsrv_session_globalB version : SMBXSRV_VERSION_0 (0) seqnum : 0x00000004 (4) info : union smbXsrv_session_globalU(case 0) info0 : * info0: struct smbXsrv_session_global0 db_rec : * session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0311 (785) signing_flags : 0x04 (4) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 1: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x08 (8) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 1: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000000 (0) connection : * encryption_cipher : 0x0000 (0) [2019/08/02 09:33:00.351791, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.351801, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key AAD2647B [2019/08/02 09:33:00.351811, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1418(smbXsrv_session_update) [2019/08/02 09:33:00.351818, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1426(smbXsrv_session_update) smbXsrv_session_update: global_id (0xaad2647b) stored [2019/08/02 09:33:00.351836, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &session_blob: struct smbXsrv_sessionB version : SMBXSRV_VERSION_0 (0) reserved : 0x00000000 (0) info : union smbXsrv_sessionU(case 0) info0 : * info0: struct smbXsrv_session table : * db_rec : NULL client : * local_id : 0xaad2647b (2865915003) global : * global: struct smbXsrv_session_global0 db_rec : NULL session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0311 (785) signing_flags : 0x04 (4) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 1: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x08 (8) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 1: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000000 (0) connection : * encryption_cipher : 0x0000 (0) status : NT_STATUS_MORE_PROCESSING_REQUIRED idle_time : Fri Aug 2 09:33:00 AM 2019 EDT nonce_high_random : 0x0000000000000000 (0) nonce_high_max : 0x0000000000000000 (0) nonce_high : 0x0000000000000000 (0) nonce_low : 0x0000000000000000 (0) compat : NULL tcon_table : * pending_auth : * pending_auth: struct smbXsrv_session_auth0 prev : * next : NULL session : * connection : * gensec : * preauth : * in_flags : 0x00 (0) in_security_mode : 0x01 (1) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT idle_time : Fri Aug 2 09:33:00 AM 2019 EDT [2019/08/02 09:33:00.352052, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.352063, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:558(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2019/08/02 09:33:00.352073, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.352082, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.352090, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.352170, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) authenticate: struct AUTHENTICATE_MESSAGE Signature : 'NTLMSSP' MessageType : NtLmAuthenticate (3) LmChallengeResponseLen : 0x0001 (1) LmChallengeResponseMaxLen: 0x0001 (1) LmChallengeResponse : * LmChallengeResponse : union ntlmssp_LM_RESPONSE_with_len(case 1) NtChallengeResponseLen : 0x0000 (0) NtChallengeResponseMaxLen: 0x0000 (0) NtChallengeResponse : * NtChallengeResponse : union ntlmssp_NTLM_RESPONSE_with_len(case 0) DomainNameLen : 0x0000 (0) DomainNameMaxLen : 0x0000 (0) DomainName : * DomainName : '' UserNameLen : 0x0000 (0) UserNameMaxLen : 0x0000 (0) UserName : * UserName : '' WorkstationLen : 0x001c (28) WorkstationMaxLen : 0x001c (28) Workstation : * Workstation : 'W2K19-ZELT-PDC' EncryptedRandomSessionKeyLen: 0x0010 (16) EncryptedRandomSessionKeyMaxLen: 0x0010 (16) EncryptedRandomSessionKey: * EncryptedRandomSessionKey: DATA_BLOB length=16 [0000] 7E 4D C5 F5 4D 47 69 48 62 FD E6 01 DC 63 FE 11 ~M..MGiH b....c.. NegotiateFlags : 0xe2888a15 (3800599061) 1: NTLMSSP_NEGOTIATE_UNICODE 0: NTLMSSP_NEGOTIATE_OEM 1: NTLMSSP_REQUEST_TARGET 1: NTLMSSP_NEGOTIATE_SIGN 0: NTLMSSP_NEGOTIATE_SEAL 0: NTLMSSP_NEGOTIATE_DATAGRAM 0: NTLMSSP_NEGOTIATE_LM_KEY 0: NTLMSSP_NEGOTIATE_NETWARE 1: NTLMSSP_NEGOTIATE_NTLM 0: NTLMSSP_NEGOTIATE_NT_ONLY 1: NTLMSSP_ANONYMOUS 0: NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED 0: NTLMSSP_NEGOTIATE_OEM_WORKSTATION_SUPPLIED 0: NTLMSSP_NEGOTIATE_THIS_IS_LOCAL_CALL 1: NTLMSSP_NEGOTIATE_ALWAYS_SIGN 0: NTLMSSP_TARGET_TYPE_DOMAIN 0: NTLMSSP_TARGET_TYPE_SERVER 0: NTLMSSP_TARGET_TYPE_SHARE 1: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY 0: NTLMSSP_NEGOTIATE_IDENTIFY 0: NTLMSSP_REQUEST_NON_NT_SESSION_KEY 1: NTLMSSP_NEGOTIATE_TARGET_INFO 1: NTLMSSP_NEGOTIATE_VERSION 1: NTLMSSP_NEGOTIATE_128 1: NTLMSSP_NEGOTIATE_KEY_EXCH 1: NTLMSSP_NEGOTIATE_56 Version: struct ntlmssp_VERSION ProductMajorVersion : NTLMSSP_WINDOWS_MAJOR_VERSION_10 (10) ProductMinorVersion : NTLMSSP_WINDOWS_MINOR_VERSION_0 (0) ProductBuild : 0x4563 (17763) Reserved: ARRAY(3) [0] : 0x00 (0) [1] : 0x00 (0) [2] : 0x00 (0) NTLMRevisionCurrent : NTLMSSP_REVISION_W2K3 (15) [2019/08/02 09:33:00.352382, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/ntlmssp/ntlmssp_server.c:552(ntlmssp_server_preauth) Got user=[] domain=[] workstation=[W2K19-ZELT-PDC] len1=1 len2=0 [2019/08/02 09:33:00.352403, 3, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3872(lp_load_ex) lp_load_ex: refreshing parameters [2019/08/02 09:33:00.352415, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1346(free_param_opts) Freeing parametrics: [2019/08/02 09:33:00.352465, 3, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:548(init_globals) Initialising global parameters [2019/08/02 09:33:00.352554, 3, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2786(lp_do_section) Processing section "[global]" doing parameter workgroup = MYGROUP doing parameter server string = Samba Server Version %v doing parameter security = user doing parameter map to guest = Bad User doing parameter guest account = nobody doing parameter client min protocol = SMB2 doing parameter idmap config * : backend = tdb doing parameter log level = 10 [2019/08/02 09:33:00.352636, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/util/debug.c:754(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 [2019/08/02 09:33:00.352726, 2, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2803(lp_do_section) Processing section "[homes]" doing parameter comment = Home Directories doing parameter read only = No [2019/08/02 09:33:00.352754, 2, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2803(lp_do_section) Processing section "[data]" doing parameter comment = Public share doing parameter path = /data doing parameter read only = No doing parameter guest ok = Yes [2019/08/02 09:33:00.352801, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3914(lp_load_ex) pm_process() returned Yes [2019/08/02 09:33:00.352821, 3, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1621(lp_add_ipc) adding IPC service [2019/08/02 09:33:00.352861, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:122(make_user_info_map) Mapping user []\[] from workstation [W2K19-ZELT-PDC] [2019/08/02 09:33:00.352876, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:64(make_user_info) attempting to make a user_info for () [2019/08/02 09:33:00.352886, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:72(make_user_info) making strings for 's user_info struct [2019/08/02 09:33:00.352897, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:125(make_user_info) making blobs for 's user_info struct [2019/08/02 09:33:00.352906, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:176(make_user_info) made a user_info for () [2019/08/02 09:33:00.352914, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:189(auth_check_ntlm_password) check_ntlm_password: Checking password for unmapped user []\[]@[W2K19-ZELT-PDC] with the new password interface [2019/08/02 09:33:00.352924, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:192(auth_check_ntlm_password) check_ntlm_password: mapped user is: []\[]@[W2K19-ZELT-PDC] [2019/08/02 09:33:00.352932, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:202(auth_check_ntlm_password) check_ntlm_password: auth_context challenge created by random [2019/08/02 09:33:00.352941, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:204(auth_check_ntlm_password) challenge is: [2019/08/02 09:33:00.352949, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/util/util.c:514(dump_data) [0000] A9 F7 FB DD 54 2F 22 4B ....T/"K [2019/08/02 09:33:00.352963, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_builtin.c:41(check_anonymous_security) Check auth for: [] [2019/08/02 09:33:00.352983, 3, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:256(auth_check_ntlm_password) auth_check_ntlm_password: anonymous authentication for user [] succeeded [2019/08/02 09:33:00.353013, 3, pid=28084, effective(0, 0), real(0, 0)] ../auth/auth_log.c:476(log_authentication_event_human_readable) Auth: [SMB2,(null)] user []\[] at [Fri, 02 Aug 2019 09:33:00.353000 EDT] with [(null)] status [NT_STATUS_OK] workstation [W2K19-ZELT-PDC] remote host [ipv4:10.37.158.97:57383] became [CI-VM-10-0-138-64]\[nobody] [S-1-5-21-2194914832-1122228929-518983330-501]. local host [ipv4:10.0.138.64:445] [2019/08/02 09:33:00.353145, 3, pid=28084, effective(0, 0), real(0, 0)] ../lib/audit_logging/audit_logging.c:141(audit_log_json) JSON Authentication: {"timestamp": "2019-08-02T09:33:00.353064-0400", "type": "Authentication", "Authentication": {"version": {"major": 1, "minor": 0}, "status": "NT_STATUS_OK", "localAddress": "ipv4:10.0.138.64:445", "remoteAddress": "ipv4:10.37.158.97:57383", "serviceDescription": "SMB2", "authDescription": null, "clientDomain": "", "clientAccount": "", "workstation": "W2K19-ZELT-PDC", "becameAccount": "nobody", "becameDomain": "CI-VM-10-0-138-64", "becameSid": "S-1-5-21-2194914832-1122228929-518983330-501", "mappedAccount": "", "mappedDomain": "", "netlogonComputer": null, "netlogonTrustAccount": null, "netlogonNegotiateFlags": "0x00000000", "netlogonSecureChannelType": 0, "netlogonTrustAccountSid": null, "passwordType": null, "duration": 128312}} [2019/08/02 09:33:00.353171, 5, pid=28084, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:316(auth_check_ntlm_password) check_ntlm_password: guest authentication for user [] -> [] -> [nobody] succeeded [2019/08/02 09:33:00.353182, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/auth_ntlmssp.c:224(auth3_check_password) Got NT session key of length 16 [2019/08/02 09:33:00.353191, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/auth_ntlmssp.c:231(auth3_check_password) Got LM session key of length 16 [2019/08/02 09:33:00.353239, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/ntlmssp/ntlmssp_server.c:978(ntlmssp_server_postauth) ntlmssp_server_auth: Using unmodified nt session key. [2019/08/02 09:33:00.353255, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:440(gensec_update_send) gensec_update_send: ntlmssp[0x55c3af3d9820]: subreq: 0x55c3af3d6a90 [2019/08/02 09:33:00.353265, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:440(gensec_update_send) gensec_update_send: spnego[0x55c3af3d74e0]: subreq: 0x55c3af3e2a40 [2019/08/02 09:33:00.353281, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 smbd_smb2_request_pending_queue: req->current_idx = 1 req->in.vector[0].iov_len = 0 req->in.vector[1].iov_len = 0 req->in.vector[2].iov_len = 64 req->in.vector[3].iov_len = 24 req->in.vector[4].iov_len = 170 req->out.vector[0].iov_len = 4 req->out.vector[1].iov_len = 0 req->out.vector[2].iov_len = 64 req->out.vector[3].iov_len = 8 req->out.vector[4].iov_len = 0 [2019/08/02 09:33:00.353328, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:498(gensec_update_done) gensec_update_done: ntlmssp[0x55c3af3d9820]: NT_STATUS_OK tevent_req[0x55c3af3d6a90/../auth/ntlmssp/ntlmssp.c:181]: state[2] error[0 (0x0)] state[struct gensec_ntlmssp_update_state (0x55c3af3d6c40)] timer[(nil)] finish[../auth/ntlmssp/ntlmssp.c:244] [2019/08/02 09:33:00.353346, 10, pid=28084, effective(0, 0), real(0, 0), class=auth] ../auth/gensec/gensec.c:498(gensec_update_done) gensec_update_done: spnego[0x55c3af3d74e0]: NT_STATUS_OK tevent_req[0x55c3af3e2a40/../auth/gensec/spnego.c:1601]: state[2] error[0 (0x0)] state[struct gensec_spnego_update_state (0x55c3af3e2bf0)] timer[(nil)] finish[../auth/gensec/spnego.c:2070] [2019/08/02 09:33:00.353359, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.353368, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:558(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2019/08/02 09:33:00.353377, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2019/08/02 09:33:00.353387, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.353396, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.353415, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.353443, 5, pid=28084, effective(0, 0), real(0, 0)] ../auth/auth_log.c:580(log_successful_authz_event_human_readable) Successful AuthZ: [SMB2,NTLMSSP] user [NT AUTHORITY]\[ANONYMOUS LOGON] [S-1-5-7] at [Fri, 02 Aug 2019 09:33:00.353437 EDT] Remote host [ipv4:10.37.158.97:57383] local host [ipv4:10.0.138.64:445] [2019/08/02 09:33:00.353473, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/audit_logging/audit_logging.c:141(audit_log_json) JSON Authorization: {"timestamp": "2019-08-02T09:33:00.353454-0400", "type": "Authorization", "Authorization": {"version": {"major": 1, "minor": 1}, "localAddress": "ipv4:10.0.138.64:445", "remoteAddress": "ipv4:10.37.158.97:57383", "serviceDescription": "SMB2", "authType": "NTLMSSP", "domain": "NT AUTHORITY", "account": "ANONYMOUS LOGON", "sid": "S-1-5-7", "sessionId": "fa518a2d-0cab-4b48-a76c-08b76d0d6c09", "logonServer": "CI-VM-10-0-138-64", "transportProtection": "SMB", "accountFlags": "0x00000010"}} [2019/08/02 09:33:00.353529, 6, pid=28084, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2336(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Fri Aug 2 09:31:54 2019 [2019/08/02 09:33:00.353555, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.353565, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_session_global.tdb 2: 3: [2019/08/02 09:33:00.353576, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key AAD2647B [2019/08/02 09:33:00.353587, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3d7740 [2019/08/02 09:33:00.353614, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:948(smbXsrv_session_global_store) [2019/08/02 09:33:00.353621, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:950(smbXsrv_session_global_store) smbXsrv_session_global_store: key 'AAD2647B' stored [2019/08/02 09:33:00.353631, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &global_blob: struct smbXsrv_session_globalB version : SMBXSRV_VERSION_0 (0) seqnum : 0x00000005 (5) info : union smbXsrv_session_globalU(case 0) info0 : * info0: struct smbXsrv_session_global0 db_rec : * session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : Fri Aug 2 09:33:00 AM 2019 EDT auth_session_info_seqnum : 0x00000001 (1) auth_session_info : * auth_session_info: struct auth_session_info security_token : * security_token: struct security_token num_sids : 0x00000005 (5) sids: ARRAY(5) sids : S-1-5-7 sids : S-1-1-0 sids : S-1-5-2 sids : S-1-22-1-99 sids : S-1-22-2-99 privilege_mask : 0x0000000000000000 (0) 0: SEC_PRIV_MACHINE_ACCOUNT_BIT 0: SEC_PRIV_PRINT_OPERATOR_BIT 0: SEC_PRIV_ADD_USERS_BIT 0: SEC_PRIV_DISK_OPERATOR_BIT 0: SEC_PRIV_REMOTE_SHUTDOWN_BIT 0: SEC_PRIV_BACKUP_BIT 0: SEC_PRIV_RESTORE_BIT 0: SEC_PRIV_TAKE_OWNERSHIP_BIT 0: SEC_PRIV_INCREASE_QUOTA_BIT 0: SEC_PRIV_SECURITY_BIT 0: SEC_PRIV_LOAD_DRIVER_BIT 0: SEC_PRIV_SYSTEM_PROFILE_BIT 0: SEC_PRIV_SYSTEMTIME_BIT 0: SEC_PRIV_PROFILE_SINGLE_PROCESS_BIT 0: SEC_PRIV_INCREASE_BASE_PRIORITY_BIT 0: SEC_PRIV_CREATE_PAGEFILE_BIT 0: SEC_PRIV_SHUTDOWN_BIT 0: SEC_PRIV_DEBUG_BIT 0: SEC_PRIV_SYSTEM_ENVIRONMENT_BIT 0: SEC_PRIV_CHANGE_NOTIFY_BIT 0: SEC_PRIV_UNDOCK_BIT 0: SEC_PRIV_ENABLE_DELEGATION_BIT 0: SEC_PRIV_MANAGE_VOLUME_BIT 0: SEC_PRIV_IMPERSONATE_BIT 0: SEC_PRIV_CREATE_GLOBAL_BIT rights_mask : 0x00000000 (0) 0: LSA_POLICY_MODE_INTERACTIVE 0: LSA_POLICY_MODE_NETWORK 0: LSA_POLICY_MODE_BATCH 0: LSA_POLICY_MODE_SERVICE 0: LSA_POLICY_MODE_PROXY 0: LSA_POLICY_MODE_DENY_INTERACTIVE 0: LSA_POLICY_MODE_DENY_NETWORK 0: LSA_POLICY_MODE_DENY_BATCH 0: LSA_POLICY_MODE_DENY_SERVICE 0: LSA_POLICY_MODE_REMOTE_INTERACTIVE 0: LSA_POLICY_MODE_DENY_REMOTE_INTERACTIVE 0x00: LSA_POLICY_MODE_ALL (0) 0x00: LSA_POLICY_MODE_ALL_NT4 (0) unix_token : * unix_token: struct security_unix_token uid : 0x0000000000000063 (99) gid : 0x0000000000000063 (99) ngroups : 0x00000001 (1) groups: ARRAY(1) groups : 0x0000000000000063 (99) info : * info: struct auth_user_info account_name : * account_name : 'ANONYMOUS LOGON' user_principal_name : NULL user_principal_constructed: 0x00 (0) domain_name : * domain_name : 'NT AUTHORITY' dns_domain_name : NULL full_name : * full_name : 'Anonymous Logon' logon_script : * logon_script : '' profile_path : * profile_path : '' home_directory : * home_directory : '' home_drive : * home_drive : '' logon_server : * logon_server : 'CI-VM-10-0-138-64' last_logon : NTTIME(0) last_logoff : NTTIME(0) acct_expiry : NTTIME(0) last_password_change : NTTIME(0) allow_password_change : NTTIME(0) force_password_change : NTTIME(0) logon_count : 0x0000 (0) bad_password_count : 0x0000 (0) acct_flags : 0x00000010 (16) authenticated : 0x00 (0) unix_info : * unix_info: struct auth_user_info_unix unix_name : * unix_name : 'nobody' sanitized_username : * sanitized_username : '' torture : NULL credentials : NULL unique_session_token : fa518a2d-0cab-4b48-a76c-08b76d0d6c09 connection_dialect : 0x0311 (785) signing_flags : 0x04 (4) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 1: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x08 (8) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 1: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000001 (1) connection : * encryption_cipher : 0x0001 (1) [2019/08/02 09:33:00.354082, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_session_global.tdb [2019/08/02 09:33:00.354093, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key AAD2647B [2019/08/02 09:33:00.354116, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1418(smbXsrv_session_update) [2019/08/02 09:33:00.354123, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1426(smbXsrv_session_update) smbXsrv_session_update: global_id (0xaad2647b) stored [2019/08/02 09:33:00.354131, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &session_blob: struct smbXsrv_sessionB version : SMBXSRV_VERSION_0 (0) reserved : 0x00000000 (0) info : union smbXsrv_sessionU(case 0) info0 : * info0: struct smbXsrv_session table : * db_rec : NULL client : * local_id : 0xaad2647b (2865915003) global : * global: struct smbXsrv_session_global0 db_rec : NULL session_global_id : 0xaad2647b (2865915003) session_wire_id : 0x00000000aad2647b (2865915003) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT expiration_time : Wed Dec 31 07:00:00 PM 1969 EST auth_time : Fri Aug 2 09:33:00 AM 2019 EDT auth_session_info_seqnum : 0x00000001 (1) auth_session_info : * auth_session_info: struct auth_session_info security_token : * security_token: struct security_token num_sids : 0x00000005 (5) sids: ARRAY(5) sids : S-1-5-7 sids : S-1-1-0 sids : S-1-5-2 sids : S-1-22-1-99 sids : S-1-22-2-99 privilege_mask : 0x0000000000000000 (0) 0: SEC_PRIV_MACHINE_ACCOUNT_BIT 0: SEC_PRIV_PRINT_OPERATOR_BIT 0: SEC_PRIV_ADD_USERS_BIT 0: SEC_PRIV_DISK_OPERATOR_BIT 0: SEC_PRIV_REMOTE_SHUTDOWN_BIT 0: SEC_PRIV_BACKUP_BIT 0: SEC_PRIV_RESTORE_BIT 0: SEC_PRIV_TAKE_OWNERSHIP_BIT 0: SEC_PRIV_INCREASE_QUOTA_BIT 0: SEC_PRIV_SECURITY_BIT 0: SEC_PRIV_LOAD_DRIVER_BIT 0: SEC_PRIV_SYSTEM_PROFILE_BIT 0: SEC_PRIV_SYSTEMTIME_BIT 0: SEC_PRIV_PROFILE_SINGLE_PROCESS_BIT 0: SEC_PRIV_INCREASE_BASE_PRIORITY_BIT 0: SEC_PRIV_CREATE_PAGEFILE_BIT 0: SEC_PRIV_SHUTDOWN_BIT 0: SEC_PRIV_DEBUG_BIT 0: SEC_PRIV_SYSTEM_ENVIRONMENT_BIT 0: SEC_PRIV_CHANGE_NOTIFY_BIT 0: SEC_PRIV_UNDOCK_BIT 0: SEC_PRIV_ENABLE_DELEGATION_BIT 0: SEC_PRIV_MANAGE_VOLUME_BIT 0: SEC_PRIV_IMPERSONATE_BIT 0: SEC_PRIV_CREATE_GLOBAL_BIT rights_mask : 0x00000000 (0) 0: LSA_POLICY_MODE_INTERACTIVE 0: LSA_POLICY_MODE_NETWORK 0: LSA_POLICY_MODE_BATCH 0: LSA_POLICY_MODE_SERVICE 0: LSA_POLICY_MODE_PROXY 0: LSA_POLICY_MODE_DENY_INTERACTIVE 0: LSA_POLICY_MODE_DENY_NETWORK 0: LSA_POLICY_MODE_DENY_BATCH 0: LSA_POLICY_MODE_DENY_SERVICE 0: LSA_POLICY_MODE_REMOTE_INTERACTIVE 0: LSA_POLICY_MODE_DENY_REMOTE_INTERACTIVE 0x00: LSA_POLICY_MODE_ALL (0) 0x00: LSA_POLICY_MODE_ALL_NT4 (0) unix_token : * unix_token: struct security_unix_token uid : 0x0000000000000063 (99) gid : 0x0000000000000063 (99) ngroups : 0x00000001 (1) groups: ARRAY(1) groups : 0x0000000000000063 (99) info : * info: struct auth_user_info account_name : * account_name : 'ANONYMOUS LOGON' user_principal_name : NULL user_principal_constructed: 0x00 (0) domain_name : * domain_name : 'NT AUTHORITY' dns_domain_name : NULL full_name : * full_name : 'Anonymous Logon' logon_script : * logon_script : '' profile_path : * profile_path : '' home_directory : * home_directory : '' home_drive : * home_drive : '' logon_server : * logon_server : 'CI-VM-10-0-138-64' last_logon : NTTIME(0) last_logoff : NTTIME(0) acct_expiry : NTTIME(0) last_password_change : NTTIME(0) allow_password_change : NTTIME(0) force_password_change : NTTIME(0) logon_count : 0x0000 (0) bad_password_count : 0x0000 (0) acct_flags : 0x00000010 (16) authenticated : 0x00 (0) unix_info : * unix_info: struct auth_user_info_unix unix_name : * unix_name : 'nobody' sanitized_username : * sanitized_username : '' torture : NULL credentials : NULL unique_session_token : fa518a2d-0cab-4b48-a76c-08b76d0d6c09 connection_dialect : 0x0311 (785) signing_flags : 0x04 (4) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 1: SMBXSRV_PROCESSED_UNSIGNED_PACKET encryption_flags : 0x08 (8) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 1: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) local_address : 'ipv4:10.0.138.64:445' remote_address : 'ipv4:10.37.158.97:57383' remote_name : '10.37.158.97' auth_session_info_seqnum : 0x00000001 (1) connection : * encryption_cipher : 0x0001 (1) status : NT_STATUS_OK idle_time : Fri Aug 2 09:33:00 AM 2019 EDT nonce_high_random : 0x4d199c593e173b05 (5555643522445949701) nonce_high_max : 0x0000000000ffffff (16777215) nonce_high : 0x0000000000000000 (0) nonce_low : 0x0000000000000000 (0) compat : * tcon_table : * pending_auth : NULL [2019/08/02 09:33:00.354624, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:3081(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[8] dyn[yes:9] at ../source3/smbd/smb2_sesssetup.c:174 [2019/08/02 09:33:00.354637, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:937(smb2_set_operation_credit) smb2_set_operation_credit: smb2_set_operation_credit: requested 33, charge 1, granted 33, current possible/max 512/512, total granted/max/low/range 33/8192/3/33 [2019/08/02 09:33:00.478666, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:3953(smbd_smb2_io_handler) smbd_smb2_request idx[1] of 5 vectors [2019/08/02 09:33:00.478724, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:679(smb2_validate_sequence_number) smb2_validate_sequence_number: smb2_validate_sequence_number: clearing id 3 (position 3) from bitmap [2019/08/02 09:33:00.478741, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:2323(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_TCON] mid = 3 [2019/08/02 09:33:00.478757, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.478768, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.478779, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.478802, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:486(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2019/08/02 09:33:00.478852, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_tcon.c:214(smbd_smb2_tree_connect) smbd_smb2_tree_connect: path[\\10.0.138.64\data] share[data] [2019/08/02 09:33:00.478894, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_tcon_global.tdb [2019/08/02 09:33:00.478905, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_tcon_global.tdb 2: 3: [2019/08/02 09:33:00.478917, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key D2EF9D79 [2019/08/02 09:33:00.478939, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3cd0e0 [2019/08/02 09:33:00.478997, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:710(smbXsrv_tcon_global_store) [2019/08/02 09:33:00.479008, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:712(smbXsrv_tcon_global_store) smbXsrv_tcon_global_store: key 'D2EF9D79' stored [2019/08/02 09:33:00.479019, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &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 : 0xd2ef9d79 (3538918777) tcon_wire_id : 0xd2ef9d79 (3538918777) server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT share_name : NULL 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 : 0x00000000 (0) signing_flags : 0x00 (0) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 0: SMBXSRV_PROCESSED_UNSIGNED_PACKET [2019/08/02 09:33:00.479148, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key D2EF9D79 [2019/08/02 09:33:00.479159, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_tcon_global.tdb [2019/08/02 09:33:00.479170, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:832(smbXsrv_tcon_create) [2019/08/02 09:33:00.479177, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:840(smbXsrv_tcon_create) smbXsrv_tcon_create: global_id (0xd2ef9d79) stored [2019/08/02 09:33:00.479186, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &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 : 0xd2ef9d79 (3538918777) global : * global: struct smbXsrv_tcon_global0 db_rec : NULL tcon_global_id : 0xd2ef9d79 (3538918777) tcon_wire_id : 0xd2ef9d79 (3538918777) server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT share_name : NULL 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 : 0x00000000 (0) 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 : Fri Aug 2 09:33:00 AM 2019 EDT compat : NULL [2019/08/02 09:33:00.479334, 3, pid=28084, effective(0, 0), real(0, 0)] ../lib/util/access.c:365(allow_access) Allowed connection from 10.37.158.97 (10.37.158.97) [2019/08/02 09:33:00.479385, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:69(set_conn_connectpath) set_conn_connectpath: service data, connectpath = /data [2019/08/02 09:33:00.479403, 3, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:603(make_connection_snum) make_connection_snum: Connect path is '/data' for service [data] [2019/08/02 09:33:00.479423, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:219(user_ok_token) user_ok_token: share data is ok for unix user nobody [2019/08/02 09:33:00.479441, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:266(is_share_read_only_for_token) is_share_read_only_for_user: share data is read-write for unix user nobody [2019/08/02 09:33:00.479475, 10, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/access_check.c:337(se_file_access_check) se_file_access_check: MAX desired = 0x2000000 mapped to 0x1f01ff [2019/08/02 09:33:00.479493, 3, pid=28084, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:113(vfs_init_default) Initialising default vfs hooks [2019/08/02 09:33:00.479507, 10, pid=28084, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:64(vfs_find_backend_entry) vfs_find_backend_entry called for /[Default VFS]/ [2019/08/02 09:33:00.479517, 5, pid=28084, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:103(smb_register_vfs) Successfully added vfs backend '/[Default VFS]/' [2019/08/02 09:33:00.479527, 10, pid=28084, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:64(vfs_find_backend_entry) vfs_find_backend_entry called for posixacl [2019/08/02 09:33:00.479537, 5, pid=28084, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:103(smb_register_vfs) Successfully added vfs backend 'posixacl' [2019/08/02 09:33:00.479546, 3, pid=28084, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:139(vfs_init_custom) Initialising custom vfs hooks from [/[Default VFS]/] [2019/08/02 09:33:00.479556, 10, pid=28084, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:64(vfs_find_backend_entry) vfs_find_backend_entry called for /[Default VFS]/ Successfully loaded vfs module [/[Default VFS]/] with the new modules system [2019/08/02 09:33:00.479606, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/notify_msg.c:80(notify_init) notify_init: notifyd=27923 [2019/08/02 09:33:00.479621, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 784 - private_data=0x55c3af3e2ce0 [2019/08/02 09:33:00.479633, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 793 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.479643, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:709(messaging_register) Registering messaging pointer for type 799 - private_data=0x55c3af3d0a20 [2019/08/02 09:33:00.479661, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:69(set_conn_connectpath) set_conn_connectpath: service data, connectpath = /data [2019/08/02 09:33:00.479674, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:219(user_ok_token) user_ok_token: share data is ok for unix user nobody [2019/08/02 09:33:00.479684, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:266(is_share_read_only_for_token) is_share_read_only_for_user: share data is read-write for unix user nobody [2019/08/02 09:33:00.479698, 10, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/access_check.c:337(se_file_access_check) se_file_access_check: MAX desired = 0x2000000 mapped to 0x1f01ff [2019/08/02 09:33:00.479723, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (99, 99) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.479733, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:63(security_token_debug) Security token SIDs (5): SID[ 0]: S-1-5-7 SID[ 1]: S-1-1-0 SID[ 2]: S-1-5-2 SID[ 3]: S-1-22-1-99 SID[ 4]: S-1-22-2-99 Privileges (0x 0): Rights (0x 0): [2019/08/02 09:33:00.479762, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 99 Primary group is 99 and contains 1 supplementary groups Group[ 0]: 99 [2019/08/02 09:33:00.479802, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/uid.c:433(change_to_user_internal) change_to_user_internal: Impersonated user: uid=(99,99), gid=(0,99), cwd=[/] [2019/08/02 09:33:00.479825, 4, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.479835, 5, pid=28084, effective(99, 99), real(99, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2019/08/02 09:33:00.479844, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2019/08/02 09:33:00.479864, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:486(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2019/08/02 09:33:00.479878, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:69(set_conn_connectpath) set_conn_connectpath: service data, connectpath = /data [2019/08/02 09:33:00.479896, 10, pid=28084, effective(0, 0), real(0, 0), class=vfs] ../source3/modules/vfs_default.c:178(vfswrap_fs_capabilities) vfswrap_fs_capabilities: timestamp resolution of sec available on share data, directory /data [2019/08/02 09:33:00.479906, 2, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:849(make_connection_snum) w2k19-zelt-pdc (ipv4:10.37.158.97:57383) connect to service data initially as user nobody (uid=99, gid=99) (pid 28084) [2019/08/02 09:33:00.479925, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_tcon_global.tdb [2019/08/02 09:33:00.479935, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_tcon_global.tdb 2: 3: [2019/08/02 09:33:00.479947, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key D2EF9D79 [2019/08/02 09:33:00.479958, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3d8ef0 [2019/08/02 09:33:00.479972, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:710(smbXsrv_tcon_global_store) [2019/08/02 09:33:00.479979, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:712(smbXsrv_tcon_global_store) smbXsrv_tcon_global_store: key 'D2EF9D79' stored [2019/08/02 09:33:00.479989, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &global_blob: struct smbXsrv_tcon_globalB version : SMBXSRV_VERSION_0 (0) seqnum : 0x00000002 (2) info : union smbXsrv_tcon_globalU(case 0) info0 : * info0: struct smbXsrv_tcon_global0 db_rec : * tcon_global_id : 0xd2ef9d79 (3538918777) tcon_wire_id : 0xd2ef9d79 (3538918777) server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT share_name : 'data' 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 : 0xaad2647b (2865915003) signing_flags : 0x00 (0) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 0: SMBXSRV_PROCESSED_UNSIGNED_PACKET [2019/08/02 09:33:00.480086, 10, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key D2EF9D79 [2019/08/02 09:33:00.480096, 5, pid=28084, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_tcon_global.tdb [2019/08/02 09:33:00.480120, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:877(smbXsrv_tcon_update) [2019/08/02 09:33:00.480128, 10, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:885(smbXsrv_tcon_update) smbXsrv_tcon_update: global_id (0xd2ef9d79) stored [2019/08/02 09:33:00.480137, 1, pid=28084, effective(0, 0), real(0, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &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 : 0xd2ef9d79 (3538918777) global : * global: struct smbXsrv_tcon_global0 db_rec : NULL tcon_global_id : 0xd2ef9d79 (3538918777) tcon_wire_id : 0xd2ef9d79 (3538918777) server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT share_name : 'data' 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 : 0xaad2647b (2865915003) signing_flags : 0x00 (0) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 0: SMBXSRV_PROCESSED_UNSIGNED_PACKET status : NT_STATUS_OK idle_time : Fri Aug 2 09:33:00 AM 2019 EDT compat : * [2019/08/02 09:33:00.480272, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:3081(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[16] dyn[no:0] at ../source3/smbd/smb2_tcon.c:173 [2019/08/02 09:33:00.480284, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:937(smb2_set_operation_credit) smb2_set_operation_credit: smb2_set_operation_credit: requested 1, charge 1, granted 1, current possible/max 480/512, total granted/max/low/range 33/8192/4/33 [2019/08/02 09:33:00.604137, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:3953(smbd_smb2_io_handler) smbd_smb2_request idx[1] of 5 vectors [2019/08/02 09:33:00.604200, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:679(smb2_validate_sequence_number) smb2_validate_sequence_number: smb2_validate_sequence_number: clearing id 4 (position 4) from bitmap [2019/08/02 09:33:00.604214, 10, pid=28084, effective(0, 0), real(0, 0), class=smb2] ../source3/smbd/smb2_server.c:2323(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 4 [2019/08/02 09:33:00.604239, 4, pid=28084, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (99, 99) - sec_ctx_stack_ndx = 0 [2019/08/02 09:33:00.604251, 5, pid=28084, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:63(security_token_debug) Security token SIDs (5): SID[ 0]: S-1-5-7 SID[ 1]: S-1-1-0 SID[ 2]: S-1-5-2 SID[ 3]: S-1-22-1-99 SID[ 4]: S-1-22-2-99 Privileges (0x 0): Rights (0x 0): [2019/08/02 09:33:00.604282, 5, pid=28084, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token) UNIX token of user 99 Primary group is 99 and contains 1 supplementary groups Group[ 0]: 99 [2019/08/02 09:33:00.604312, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:805(vfs_ChDir) vfs_ChDir to /data [2019/08/02 09:33:00.604348, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:859(vfs_ChDir) vfs_ChDir got /data [2019/08/02 09:33:00.604361, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/uid.c:433(change_to_user_internal) change_to_user_internal: Impersonated user: uid=(99,99), gid=(0,99), cwd=[/data] [2019/08/02 09:33:00.604376, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_tcon_global.tdb [2019/08/02 09:33:00.604386, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_tcon_global.tdb 2: 3: [2019/08/02 09:33:00.604399, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key D2EF9D79 [2019/08/02 09:33:00.604410, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3d8ef0 [2019/08/02 09:33:00.604433, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/smbXsrv_tcon.c:710(smbXsrv_tcon_global_store) [2019/08/02 09:33:00.604441, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/smbXsrv_tcon.c:712(smbXsrv_tcon_global_store) smbXsrv_tcon_global_store: key 'D2EF9D79' stored [2019/08/02 09:33:00.604451, 1, pid=28084, effective(99, 99), real(99, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &global_blob: struct smbXsrv_tcon_globalB version : SMBXSRV_VERSION_0 (0) seqnum : 0x00000003 (3) info : union smbXsrv_tcon_globalU(case 0) info0 : * info0: struct smbXsrv_tcon_global0 db_rec : * tcon_global_id : 0xd2ef9d79 (3538918777) tcon_wire_id : 0xd2ef9d79 (3538918777) server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT share_name : 'data' encryption_flags : 0x08 (8) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 1: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET session_global_id : 0xaad2647b (2865915003) signing_flags : 0x04 (4) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 1: SMBXSRV_PROCESSED_UNSIGNED_PACKET [2019/08/02 09:33:00.604555, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key D2EF9D79 [2019/08/02 09:33:00.604565, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_tcon_global.tdb [2019/08/02 09:33:00.604575, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/smbXsrv_tcon.c:877(smbXsrv_tcon_update) [2019/08/02 09:33:00.604582, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/smbXsrv_tcon.c:885(smbXsrv_tcon_update) smbXsrv_tcon_update: global_id (0xd2ef9d79) stored [2019/08/02 09:33:00.604591, 1, pid=28084, effective(99, 99), real(99, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &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 : 0xd2ef9d79 (3538918777) global : * global: struct smbXsrv_tcon_global0 db_rec : NULL tcon_global_id : 0xd2ef9d79 (3538918777) tcon_wire_id : 0xd2ef9d79 (3538918777) server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) creation_time : Fri Aug 2 09:33:00 AM 2019 EDT share_name : 'data' encryption_flags : 0x08 (8) 0: SMBXSRV_ENCRYPTION_REQUIRED 0: SMBXSRV_ENCRYPTION_DESIRED 0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET 1: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET session_global_id : 0xaad2647b (2865915003) signing_flags : 0x04 (4) 0: SMBXSRV_SIGNING_REQUIRED 0: SMBXSRV_PROCESSED_SIGNED_PACKET 1: SMBXSRV_PROCESSED_UNSIGNED_PACKET status : NT_STATUS_OK idle_time : Fri Aug 2 09:33:01 AM 2019 EDT compat : * [2019/08/02 09:33:00.604722, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_create.c:666(smbd_smb2_create_send) smbd_smb2_create_send: name [testdir] [2019/08/02 09:33:00.604744, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_create.c:764(smbd_smb2_create_send) smbd_smb2_create_send: open execution phase [2019/08/02 09:33:00.604765, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/filename.c:461(unix_convert) unix_convert called on file "testdir" [2019/08/02 09:33:00.604794, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/statcache.c:245(stat_cache_lookup) stat_cache_lookup: lookup failed for name [TESTDIR] [2019/08/02 09:33:00.604809, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/filename.c:662(unix_convert) unix_convert begin: name = testdir, dirpath = , start = testdir [2019/08/02 09:33:00.604841, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/filename.c:685(unix_convert) conversion of base_name finished testdir -> testdir [2019/08/02 09:33:00.604854, 10, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1196(check_reduced_name) check_reduced_name: check_reduced_name [testdir] [/data] [2019/08/02 09:33:00.604869, 10, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1260(check_reduced_name) check_reduced_name realpath [testdir] -> [/data/testdir] [2019/08/02 09:33:00.604880, 5, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1371(check_reduced_name) check_reduced_name: testdir reduced to /data/testdir [2019/08/02 09:33:00.604892, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:5612(create_file_default) create_file_default: create_file: access_mask = 0x1000a0 file_attributes = 0x0, share_access = 0x3, create_disposition = 0x1 create_options = 0x1 oplock_request = 0x0 private_flags = 0x0 root_dir_fid = 0x0, ea_list = (nil), sd = (nil), fname = testdir [2019/08/02 09:33:00.604910, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:5063(create_file_unixpath) create_file_unixpath: create_file_unixpath: access_mask = 0x1000a0 file_attributes = 0x0, share_access = 0x3, create_disposition = 0x1 create_options = 0x1 oplock_request = 0x0 private_flags = 0x0 ea_list = (nil), sd = (nil), fname = testdir [2019/08/02 09:33:00.604924, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:3991(open_directory) open_directory: opening directory testdir, access_mask = 0x1000a0, share_access = 0x3 create_options = 0x1, create_disposition = 0x1, file_attributes = 0x10 [2019/08/02 09:33:00.604941, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:3509(posix_get_nt_acl) posix_get_nt_acl: called for file testdir [2019/08/02 09:33:00.605093, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/passdb/lookup_sid.c:1286(uid_to_sid) uid 99 -> sid S-1-5-21-2961102297-628415903-657217176-501 [2019/08/02 09:33:00.605142, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/passdb/lookup_sid.c:1335(gid_to_sid) gid 99 -> sid S-1-22-2-99 [2019/08/02 09:33:00.605158, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2752(canonicalise_acl) canonicalise_acl: Access ace entries before arrange : [2019/08/02 09:33:00.605169, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x [2019/08/02 09:33:00.605182, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 1. Type = allow SID = S-1-22-2-99 gid 99 SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x [2019/08/02 09:33:00.605193, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 2. Type = allow SID = S-1-5-21-2961102297-628415903-657217176-501 uid 99 SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2019/08/02 09:33:00.605206, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:847(print_canon_ace_list) print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-2961102297-628415903-657217176-501 uid 99 SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-22-2-99 gid 99 SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x [2019/08/02 09:33:00.605232, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff [2019/08/02 09:33:00.605242, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2019/08/02 09:33:00.605251, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2019/08/02 09:33:00.605265, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:183(smbd_check_access_rights) smbd_check_access_rights: file testdir requesting 0x1000a0 returning 0x100020 (NT_STATUS_OK) [2019/08/02 09:33:00.605286, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_open_global.tdb [2019/08/02 09:33:00.605296, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_open_global.tdb 2: 3: [2019/08/02 09:33:00.605307, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key A62676C9 [2019/08/02 09:33:00.605325, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3ddd60 [2019/08/02 09:33:00.605335, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/smbXsrv_open.c:625(smbXsrv_open_global_verify_record) smbXsrv_open_global_verify_record: empty value [2019/08/02 09:33:00.605386, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/smbXsrv_open.c:744(smbXsrv_open_global_store) smbXsrv_open_global_store: key 'A62676C9' stored [2019/08/02 09:33:00.605399, 1, pid=28084, effective(99, 99), real(99, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &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 db_rec : * server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) open_global_id : 0xa62676c9 (2787538633) open_persistent_id : 0x00000000a62676c9 (2787538633) open_volatile_id : 0x000000009931c432 (2570175538) open_owner : S-1-5-7 open_time : Fri Aug 2 09:33:01 AM 2019 EDT create_guid : 00000000-0000-0000-0000-000000000000 client_guid : 5a4d131b-b358-11e9-80fe-525400d13910 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) [2019/08/02 09:33:00.605497, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key A62676C9 [2019/08/02 09:33:00.605508, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_open_global.tdb [2019/08/02 09:33:00.605520, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/smbXsrv_open.c:911(smbXsrv_open_create) smbXsrv_open_create: global_id (0xa62676c9) stored [2019/08/02 09:33:00.605529, 1, pid=28084, effective(99, 99), real(99, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) &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 : * db_rec : NULL local_id : 0x9931c432 (2570175538) global : * global: struct smbXsrv_open_global0 db_rec : NULL server_id: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) open_global_id : 0xa62676c9 (2787538633) open_persistent_id : 0x00000000a62676c9 (2787538633) open_volatile_id : 0x000000009931c432 (2570175538) open_owner : S-1-5-7 open_time : Fri Aug 2 09:33:01 AM 2019 EDT create_guid : 00000000-0000-0000-0000-000000000000 client_guid : 5a4d131b-b358-11e9-80fe-525400d13910 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) status : NT_STATUS_OK idle_time : Fri Aug 2 09:33:01 AM 2019 EDT 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) [2019/08/02 09:33:00.605670, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/files.c:128(file_new) allocated file structure fnum 2570175538 (1 used) [2019/08/02 09:33:00.605687, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/files.c:754(file_name_hash) file_name_hash: /data/testdir hash 0x3170a1cb [2019/08/02 09:33:00.605704, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:805(vfs_ChDir) vfs_ChDir to testdir [2019/08/02 09:33:00.605721, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:859(vfs_ChDir) vfs_ChDir got /data/testdir [2019/08/02 09:33:00.605731, 10, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1196(check_reduced_name) check_reduced_name: check_reduced_name [.] [/data] [2019/08/02 09:33:00.605742, 10, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1260(check_reduced_name) check_reduced_name realpath [.] -> [/data/testdir] [2019/08/02 09:33:00.605752, 5, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1371(check_reduced_name) check_reduced_name: . reduced to /data/testdir [2019/08/02 09:33:00.605768, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:805(vfs_ChDir) vfs_ChDir to /data [2019/08/02 09:33:00.605781, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:859(vfs_ChDir) vfs_ChDir got /data [2019/08/02 09:33:00.605790, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:810(fd_open) fd_open: name testdir, flags = 0200000 mode = 00, fd = 9. [2019/08/02 09:33:00.605803, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/locking.tdb [2019/08/02 09:33:00.605822, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/locking.tdb 2: 3: [2019/08/02 09:33:00.605834, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key 01FD0000000000004620 [2019/08/02 09:33:00.605867, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3dd6c0 [2019/08/02 09:33:00.605888, 10, pid=28084, effective(99, 99), real(99, 0), class=locking] ../source3/locking/share_mode_lock.c:368(unparse_share_modes) unparse_share_modes: [2019/08/02 09:33:00.605901, 1, pid=28084, effective(99, 99), real(99, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) d: struct share_mode_data sequence_number : 0x67b91511176c89a9 (7474028219749665193) servicepath : * servicepath : '/data' base_name : * base_name : 'testdir' stream_name : NULL num_share_modes : 0x00000001 (1) share_modes: ARRAY(1) share_modes: struct share_mode_entry pid: struct server_id pid : 0x0000000000006db4 (28084) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0x7b08e61279bc2c26 (8865588833504996390) op_mid : 0x0000000000000004 (4) op_type : 0x0000 (0) lease_idx : 0xffffffff (4294967295) access_mask : 0x001000a0 (1048736) share_access : 0x00000003 (3) private_options : 0x00000000 (0) time : Fri Aug 2 09:33:00 AM 2019 EDT.605278 share_file_id : 0x00000000981a0535 (2551842101) uid : 0x00000063 (99) flags : 0x0000 (0) name_hash : 0x3170a1cb (829465035) stale : 0x00 (0) lease : NULL num_leases : 0x00000000 (0) leases: ARRAY(0) num_delete_tokens : 0x00000000 (0) delete_tokens: ARRAY(0) old_write_time : Wed Dec 31 07:00:00 PM 1969 EST.0 changed_write_time : Wed Dec 31 07:00:00 PM 1969 EST.0 fresh : 0x01 (1) modified : 0x01 (1) record : * id: struct file_id devid : 0x000000000000fd01 (64769) inode : 0x0000000000212046 (2170950) extid : 0x0000000000000000 (0) [2019/08/02 09:33:00.606049, 10, pid=28084, effective(99, 99), real(99, 0), class=locking] ../source3/locking/share_mode_lock.c:157(share_mode_memcache_delete) deleting entry for file testdir seq 0x7474028219749665193 key fd01:212046:0 [2019/08/02 09:33:00.606089, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/locking.tdb [2019/08/02 09:33:00.606112, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key 01FD0000000000004620 [2019/08/02 09:33:00.606124, 10, pid=28084, effective(99, 99), real(99, 0), class=locking] ../source3/locking/share_mode_lock.c:171(share_mode_memcache_store) stored entry for file testdir seq 0x7474028219749665194 key fd01:212046:0 [2019/08/02 09:33:00.606136, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:5421(create_file_unixpath) create_file_unixpath: info=1 [2019/08/02 09:33:00.606145, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:5700(create_file_default) create_file: info=1 [2019/08/02 09:33:00.606155, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_create.c:1295(smbd_smb2_create_after_exec) smbd_smb2_create_send: response construction phase [2019/08/02 09:33:00.606166, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:3509(posix_get_nt_acl) posix_get_nt_acl: called for file testdir [2019/08/02 09:33:00.606188, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/passdb/lookup_sid.c:1286(uid_to_sid) uid 99 -> sid S-1-5-21-2961102297-628415903-657217176-501 [2019/08/02 09:33:00.606200, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/passdb/lookup_sid.c:1335(gid_to_sid) gid 99 -> sid S-1-22-2-99 [2019/08/02 09:33:00.606211, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2752(canonicalise_acl) canonicalise_acl: Access ace entries before arrange : [2019/08/02 09:33:00.606220, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x [2019/08/02 09:33:00.606231, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 1. Type = allow SID = S-1-22-2-99 gid 99 SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x [2019/08/02 09:33:00.606243, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 2. Type = allow SID = S-1-5-21-2961102297-628415903-657217176-501 uid 99 SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2019/08/02 09:33:00.606254, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:847(print_canon_ace_list) print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-2961102297-628415903-657217176-501 uid 99 SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-22-2-99 gid 99 SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x [2019/08/02 09:33:00.606275, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff [2019/08/02 09:33:00.606284, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2019/08/02 09:33:00.606293, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2019/08/02 09:33:00.606305, 10, pid=28084, effective(99, 99), real(99, 0)] ../libcli/security/access_check.c:188(se_access_check) se_access_check: MAX desired = 0x2000000, granted = 0x1200a9, remaining = 0x1200a9 [2019/08/02 09:33:00.606322, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:3509(posix_get_nt_acl) posix_get_nt_acl: called for file . [2019/08/02 09:33:00.606339, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/passdb/lookup_sid.c:1286(uid_to_sid) uid 99 -> sid S-1-5-21-2961102297-628415903-657217176-501 [2019/08/02 09:33:00.606350, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/passdb/lookup_sid.c:1335(gid_to_sid) gid 99 -> sid S-1-22-2-99 [2019/08/02 09:33:00.606360, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2752(canonicalise_acl) canonicalise_acl: Access ace entries before arrange : [2019/08/02 09:33:00.606369, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms rwx [2019/08/02 09:33:00.606380, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 1. Type = allow SID = S-1-22-2-99 gid 99 SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx [2019/08/02 09:33:00.606391, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 2. Type = allow SID = S-1-5-21-2961102297-628415903-657217176-501 uid 99 SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2019/08/02 09:33:00.606402, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:847(print_canon_ace_list) print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-2961102297-628415903-657217176-501 uid 99 SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-22-2-99 gid 99 SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms rwx [2019/08/02 09:33:00.606423, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff [2019/08/02 09:33:00.606432, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff [2019/08/02 09:33:00.606440, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff [2019/08/02 09:33:00.606451, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:183(smbd_check_access_rights) smbd_check_access_rights: file . requesting 0x40 returning 0x40 (NT_STATUS_OK) [2019/08/02 09:33:00.606469, 8, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/dosmode.c:667(dos_mode) dos_mode: testdir [2019/08/02 09:33:00.606487, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/dosmode.c:323(get_ea_dos_attribute) get_ea_dos_attribute: Cannot get attribute from EA on file testdir: Error = No data available [2019/08/02 09:33:00.606506, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print) dos_mode_debug_print: dos_mode returning (0x10): "d" [2019/08/02 09:33:00.606516, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_create.c:1521(smbd_smb2_create_finish) smbd_smb2_create_finish: testdir - fnum 2570175538 [2019/08/02 09:33:00.606535, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_server.c:3081(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[88] dyn[yes:88] at ../source3/smbd/smb2_create.c:367 [2019/08/02 09:33:00.606547, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:937(smb2_set_operation_credit) smb2_set_operation_credit: smb2_set_operation_credit: requested 1, charge 1, granted 1, current possible/max 480/512, total granted/max/low/range 33/8192/5/33 [2019/08/02 09:33:00.730583, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_server.c:3953(smbd_smb2_io_handler) smbd_smb2_request idx[1] of 5 vectors [2019/08/02 09:33:00.730639, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:679(smb2_validate_sequence_number) smb2_validate_sequence_number: smb2_validate_sequence_number: clearing id 5 (position 5) from bitmap [2019/08/02 09:33:00.730654, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_server.c:2323(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 5 [2019/08/02 09:33:00.730671, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/uid.c:310(change_to_user_internal) change_to_user_internal: Skipping user change - already user [2019/08/02 09:33:00.730696, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_create.c:666(smbd_smb2_create_send) smbd_smb2_create_send: name [testdir\test1] [2019/08/02 09:33:00.730723, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_create.c:764(smbd_smb2_create_send) smbd_smb2_create_send: open execution phase [2019/08/02 09:33:00.730736, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/filename.c:461(unix_convert) unix_convert called on file "testdir/test1" [2019/08/02 09:33:00.730752, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/statcache.c:245(stat_cache_lookup) stat_cache_lookup: lookup failed for name [TESTDIR/TEST1] [2019/08/02 09:33:00.730763, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/statcache.c:245(stat_cache_lookup) stat_cache_lookup: lookup failed for name [TESTDIR] [2019/08/02 09:33:00.730774, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/filename.c:662(unix_convert) unix_convert begin: name = testdir/test1, dirpath = , start = testdir/test1 [2019/08/02 09:33:00.730792, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/filename.c:235(check_parent_exists) check_parent_exists: name = testdir/test1, dirpath = testdir, start = test1 [2019/08/02 09:33:00.730805, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled) is_mangled test1 ? [2019/08/02 09:33:00.730827, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component) is_mangled_component test1 (len 5) ? [2019/08/02 09:33:00.730838, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled) is_mangled test1 ? [2019/08/02 09:33:00.730848, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component) is_mangled_component test1 (len 5) ? [2019/08/02 09:33:00.730866, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:805(vfs_ChDir) vfs_ChDir to testdir [2019/08/02 09:33:00.730882, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:859(vfs_ChDir) vfs_ChDir got /data/testdir [2019/08/02 09:33:00.730894, 10, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1196(check_reduced_name) check_reduced_name: check_reduced_name [.] [/data] [2019/08/02 09:33:00.730910, 10, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1260(check_reduced_name) check_reduced_name realpath [.] -> [/data/testdir] [2019/08/02 09:33:00.730920, 5, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1371(check_reduced_name) check_reduced_name: . reduced to /data/testdir [2019/08/02 09:33:00.730943, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:805(vfs_ChDir) vfs_ChDir to /data [2019/08/02 09:33:00.730956, 4, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:859(vfs_ChDir) vfs_ChDir got /data [2019/08/02 09:33:00.730982, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled) is_mangled test1 ? [2019/08/02 09:33:00.730996, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component) is_mangled_component test1 (len 5) ? [2019/08/02 09:33:00.731005, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/filename.c:1060(unix_convert) New file test1 [2019/08/02 09:33:00.731015, 10, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1196(check_reduced_name) check_reduced_name: check_reduced_name [testdir/test1] [/data] [2019/08/02 09:33:00.731031, 10, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1260(check_reduced_name) check_reduced_name realpath [testdir/test1] -> [/data/testdir/test1] [2019/08/02 09:33:00.731041, 5, pid=28084, effective(99, 99), real(99, 0), class=vfs] ../source3/smbd/vfs.c:1371(check_reduced_name) check_reduced_name: testdir/test1 reduced to /data/testdir/test1 [2019/08/02 09:33:00.731052, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:5612(create_file_default) create_file_default: create_file: access_mask = 0x100081 file_attributes = 0x80, share_access = 0x3, create_disposition = 0x2 create_options = 0x204001 oplock_request = 0x0 private_flags = 0x0 root_dir_fid = 0x0, ea_list = (nil), sd = (nil), fname = testdir/test1 [2019/08/02 09:33:00.731065, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:5063(create_file_unixpath) create_file_unixpath: create_file_unixpath: access_mask = 0x100081 file_attributes = 0x80, share_access = 0x3, create_disposition = 0x2 create_options = 0x204001 oplock_request = 0x0 private_flags = 0x0 ea_list = (nil), sd = (nil), fname = testdir/test1 [2019/08/02 09:33:00.731077, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:3991(open_directory) open_directory: opening directory testdir/test1, access_mask = 0x100081, share_access = 0x3 create_options = 0x204001, create_disposition = 0x2, file_attributes = 0x90 [2019/08/02 09:33:00.731090, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/dosmode.c:206(unix_mode) unix_mode: unix_mode(testdir/test1) returning 0755 [2019/08/02 09:33:00.731117, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:3509(posix_get_nt_acl) posix_get_nt_acl: called for file testdir [2019/08/02 09:33:00.731153, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/passdb/lookup_sid.c:1286(uid_to_sid) uid 99 -> sid S-1-5-21-2961102297-628415903-657217176-501 [2019/08/02 09:33:00.731169, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/passdb/lookup_sid.c:1335(gid_to_sid) gid 99 -> sid S-1-22-2-99 [2019/08/02 09:33:00.731180, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2752(canonicalise_acl) canonicalise_acl: Access ace entries before arrange : [2019/08/02 09:33:00.731190, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x [2019/08/02 09:33:00.731203, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 1. Type = allow SID = S-1-22-2-99 gid 99 SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x [2019/08/02 09:33:00.731215, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:2765(canonicalise_acl) canon_ace index 2. Type = allow SID = S-1-5-21-2961102297-628415903-657217176-501 uid 99 SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2019/08/02 09:33:00.731227, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:847(print_canon_ace_list) print_canon_ace_list: canonicalise_acl: ace entries after arrange canon_ace index 0. Type = allow SID = S-1-5-21-2961102297-628415903-657217176-501 uid 99 SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-22-2-99 gid 99 SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r-x canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x [2019/08/02 09:33:00.731252, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff [2019/08/02 09:33:00.731262, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2019/08/02 09:33:00.731272, 10, pid=28084, effective(99, 99), real(99, 0), class=acls] ../source3/smbd/posix_acls.c:1111(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9 [2019/08/02 09:33:00.731313, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:324(check_parent_access) check_parent_access: access check on directory testdir for path testdir/test1 for mask 0x4 returned (0x4) NT_STATUS_ACCESS_DENIED [2019/08/02 09:33:00.731329, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:3874(mkdir_internal) mkdir_internal: check_parent_access on directory testdir for path testdir/test1 returned NT_STATUS_ACCESS_DENIED [2019/08/02 09:33:00.731339, 2, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:4043(open_directory) open_directory: unable to create testdir/test1. Error was NT_STATUS_ACCESS_DENIED [2019/08/02 09:33:00.731349, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:5433(create_file_unixpath) create_file_unixpath: NT_STATUS_ACCESS_DENIED [2019/08/02 09:33:00.731358, 10, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/open.c:5709(create_file_default) create_file: NT_STATUS_ACCESS_DENIED [2019/08/02 09:33:00.731372, 3, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_server.c:3190(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at ../source3/smbd/smb2_create.c:296 [2019/08/02 09:33:00.731383, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_server.c:3081(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] body[8] dyn[yes:1] at ../source3/smbd/smb2_server.c:3238 [2019/08/02 09:33:00.731394, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:937(smb2_set_operation_credit) smb2_set_operation_credit: smb2_set_operation_credit: requested 1, charge 1, granted 1, current possible/max 480/512, total granted/max/low/range 33/8192/6/33 [2019/08/02 09:33:00.861411, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_server.c:3953(smbd_smb2_io_handler) smbd_smb2_request idx[1] of 5 vectors [2019/08/02 09:33:00.861462, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:679(smb2_validate_sequence_number) smb2_validate_sequence_number: smb2_validate_sequence_number: clearing id 6 (position 6) from bitmap [2019/08/02 09:33:00.861477, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_server.c:2323(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_CLOSE] mid = 6 [2019/08/02 09:33:00.861493, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/uid.c:310(change_to_user_internal) change_to_user_internal: Skipping user change - already user [2019/08/02 09:33:00.861518, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_close.c:230(smbd_smb2_close) smbd_smb2_close: testdir - fnum 2570175538 [2019/08/02 09:33:00.861537, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/locking.tdb [2019/08/02 09:33:00.861548, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/locking.tdb 2: 3: [2019/08/02 09:33:00.861562, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key 01FD0000000000004620 [2019/08/02 09:33:00.861585, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3dae90 [2019/08/02 09:33:00.861601, 10, pid=28084, effective(99, 99), real(99, 0), class=locking] ../source3/locking/share_mode_lock.c:285(share_mode_memcache_fetch) fetched entry for file testdir seq 0x7474028219749665194 key fd01:212046:0 [2019/08/02 09:33:00.861614, 10, pid=28084, effective(99, 99), real(99, 0), class=locking] ../source3/locking/locking.c:1224(find_delete_on_close_token) find_delete_on_close_token: name_hash = 0x3170a1cb [2019/08/02 09:33:00.861627, 10, pid=28084, effective(99, 99), real(99, 0), class=locking] ../source3/locking/share_mode_lock.c:368(unparse_share_modes) unparse_share_modes: [2019/08/02 09:33:00.861636, 1, pid=28084, effective(99, 99), real(99, 0), class=rpc_parse] ../librpc/ndr/ndr.c:422(ndr_print_debug) d: struct share_mode_data sequence_number : 0x67b91511176c89aa (7474028219749665194) servicepath : * servicepath : '/data' base_name : * base_name : 'testdir' stream_name : NULL num_share_modes : 0x00000000 (0) share_modes: ARRAY(0) num_leases : 0x00000000 (0) leases: ARRAY(0) num_delete_tokens : 0x00000000 (0) delete_tokens: ARRAY(0) old_write_time : Wed Dec 31 07:00:00 PM 1969 EST.0 changed_write_time : Wed Dec 31 07:00:00 PM 1969 EST.0 fresh : 0x00 (0) modified : 0x01 (1) record : * id: struct file_id devid : 0x000000000000fd01 (64769) inode : 0x0000000000212046 (2170950) extid : 0x0000000000000000 (0) [2019/08/02 09:33:00.861716, 10, pid=28084, effective(99, 99), real(99, 0), class=locking] ../source3/locking/share_mode_lock.c:157(share_mode_memcache_delete) deleting entry for file testdir seq 0x7474028219749665194 key fd01:212046:0 [2019/08/02 09:33:00.861726, 10, pid=28084, effective(99, 99), real(99, 0), class=locking] ../source3/locking/share_mode_lock.c:380(unparse_share_modes) No used share mode found [2019/08/02 09:33:00.861737, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/locking.tdb [2019/08/02 09:33:00.861747, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key 01FD0000000000004620 [2019/08/02 09:33:00.861765, 10, pid=28084, effective(99, 99), real(99, 0), class=locking] ../source3/locking/posix.c:500(delete_lock_ref_count) delete_lock_ref_count for file testdir [2019/08/02 09:33:00.861780, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:130(dbwrap_lock_order_lock) dbwrap_lock_order_lock: check lock order 1 for /var/lib/samba/lock/smbXsrv_open_global.tdb [2019/08/02 09:33:00.861790, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:116(debug_lock_order) lock order: 1:/var/lib/samba/lock/smbXsrv_open_global.tdb 2: 3: [2019/08/02 09:33:00.861800, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Locking key A62676C9 [2019/08/02 09:33:00.861821, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:145(db_tdb_fetch_locked_internal) db_tdb_fetch_locked_internal: Allocated locked data 0x55c3af3d80d0 [2019/08/02 09:33:00.861837, 10, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap_tdb.c:61(db_tdb_log_key) db_tdb_log_key: Unlocking key A62676C9 [2019/08/02 09:33:00.861848, 5, pid=28084, effective(99, 99), real(99, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_lock_order_unlock) dbwrap_lock_order_unlock: release lock order 1 for /var/lib/samba/lock/smbXsrv_open_global.tdb [2019/08/02 09:33:00.861860, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/files.c:563(file_free) freed files structure 2570175538 (0 used) [2019/08/02 09:33:00.861873, 8, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/dosmode.c:667(dos_mode) dos_mode: testdir [2019/08/02 09:33:00.861889, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/dosmode.c:323(get_ea_dos_attribute) get_ea_dos_attribute: Cannot get attribute from EA on file testdir: Error = No data available [2019/08/02 09:33:00.861905, 5, pid=28084, effective(99, 99), real(99, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print) dos_mode_debug_print: dos_mode returning (0x10): "d" [2019/08/02 09:33:00.861920, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2] ../source3/smbd/smb2_server.c:3081(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[60] dyn[no:0] at ../source3/smbd/smb2_close.c:147 [2019/08/02 09:33:00.861932, 10, pid=28084, effective(99, 99), real(99, 0), class=smb2_credits] ../source3/smbd/smb2_server.c:937(smb2_set_operation_credit) smb2_set_operation_credit: smb2_set_operation_credit: requested 1, charge 1, granted 1, current possible/max 480/512, total granted/max/low/range 33/8192/7/33