[2017/06/20 16:56:18.395372, 5, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:128(file_new) allocated file structure fnum 429999517 (2 used) [2017/06/20 16:56:18.395428, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:756(file_name_hash) file_name_hash: /export/vol1/file4.txt hash 0xe940043f [2017/06/20 16:56:18.395582, 5, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:206(unix_mode) unix_mode: unix_mode(file4.txt) returning 0744 [2017/06/20 16:56:18.395620, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2972(open_file_ntcreate) open_file_ntcreate: fname=file4.txt, dos_attrs=0x80 access_mask=0x120089 share_access=0x3 create_disposition = 0x1 create_options=0x40 unix mode=0744 oplock_request=2 private_flags = 0x0 [2017/06/20 16:56:18.395758, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:3142(open_file_ntcreate) open_file_ntcreate: fname=file4.txt, after mapping access_mask=0x120089 [2017/06/20 16:56:18.395798, 4, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:3233(open_file_ntcreate) calling open_file with flags=0x0 flags2=0x800 mode=0744, access_mask = 0x120089, open_access_mask = 0x120089 [2017/06/20 16:56:18.395845, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:3560(posix_get_nt_acl) posix_get_nt_acl: called for file file4.txt [2017/06/20 16:56:18.395970, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1251(uid_to_sid) uid 65534 -> sid S-1-5-21-1893543895-1847372660-4172524467-501 [2017/06/20 16:56:18.396083, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1300(gid_to_sid) gid 65534 -> sid S-1-22-2-65534 [2017/06/20 16:56:18.396242, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2724(canonicalise_acl) canonicalise_acl: Access ace entries before arrange : [2017/06/20 16:56:18.396276, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl) canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms rwx [2017/06/20 16:56:18.396326, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl) canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nogroup) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx [2017/06/20 16:56:18.396549, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl) canon_ace index 2. Type = allow SID = S-1-5-21-1893543895-1847372660-4172524467-501 uid 65534 (nobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx [2017/06/20 16:56:18.396770, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:848(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-1893543895-1847372660-4172524467-501 uid 65534 (nobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nogroup) 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 [2017/06/20 16:56:18.397153, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1e01ff [2017/06/20 16:56:18.397188, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1e01ff [2017/06/20 16:56:18.397235, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms) map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1e01ff [2017/06/20 16:56:18.397397, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:181(smbd_check_access_rights) smbd_check_access_rights: file file4.txt requesting 0x120089 returning 0x120009 (NT_STATUS_OK) [2017/06/20 16:56:18.397519, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1199(check_reduced_name) check_reduced_name: check_reduced_name [file4.txt] [/export/vol1] [2017/06/20 16:56:18.397619, 10, pid=28186, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1259(check_reduced_name) check_reduced_name realpath [file4.txt] -> [/export/vol1/file4.txt] [2017/06/20 16:56:18.397791, 5, pid=28186, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1370(check_reduced_name) check_reduced_name: file4.txt reduced to /export/vol1/file4.txt [2017/06/20 16:56:35.176280, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:689(fd_open) fd_open: name file4.txt, flags = 04000 mode = 0744, fd = -1. Interrupted system call [2017/06/20 16:56:35.176445, 3, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1179(open_file) Error opening file file4.txt (NT_STATUS_RETRY) (local_flags=2048) (flags=2048) [2017/06/20 16:56:35.176495, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1726(push_deferred_open_message_smb2) push_deferred_open_message_smb2: timeout at 2017/06/20 16:56:38.392634 [2017/06/20 16:56:35.176560, 5, pid=28186, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order) check lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb [2017/06/20 16:56:35.176602, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1:/var/lock/samba/smbXsrv_open_global.tdb 2: 3: [2017/06/20 16:56:35.176652, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Locking key 78A35EFB [2017/06/20 16:56:35.176738, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal) Allocated locked data 0x0x7f600f7b2540 [2017/06/20 16:56:35.176807, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Unlocking key 78A35EFB [2017/06/20 16:56:35.176839, 5, pid=28186, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor) release lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb [2017/06/20 16:56:35.176864, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1: 2: 3: [2017/06/20 16:56:35.176902, 5, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:565(file_free) freed files structure 429999517 (1 used) [2017/06/20 16:56:35.176927, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5334(create_file_unixpath) create_file_unixpath: NT_STATUS_RETRY [2017/06/20 16:56:35.176954, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5612(create_file_default) create_file: NT_STATUS_RETRY [2017/06/20 16:56:35.176983, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1535(open_was_deferred_smb2) open_was_deferred_smb2: mid = 32 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 = 56 req->in.vector[4].iov_len = 128 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 [2017/06/20 16:56:35.178262, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1571(smbd_smb2_request_pending_timer) smbd_smb2_request_pending_queue: opcode[SMB2_OP_CREATE] mid 32 going async [2017/06/20 16:56:35.178337, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:925(smb2_set_operation_credit) smb2_set_operation_credit: requested 1, charge 1, granted 1, current possible/max 482/512, total granted/max/low/range 31/8192/33/31 [2017/06/20 16:56:35.178453, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1669(smbd_smb2_request_pending_timer) state->vector[0/5].iov_len = 4 state->vector[1/5].iov_len = 0 state->vector[2/5].iov_len = 64 state->vector[3/5].iov_len = 8 state->vector[4/5].iov_len = 1 [2017/06/20 16:56:39.645162, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/lib/util_event.c:42(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) called [2017/06/20 16:56:39.645253, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/lib/util_event.c:53(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled [2017/06/20 16:56:39.645319, 10, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/lib/util_event.c:42(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) called [2017/06/20 16:56:39.645353, 5, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/process.c:2895(housekeeping_fn) housekeeping [2017/06/20 16:56:39.645390, 4, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2017/06/20 16:56:39.645417, 5, pid=28186, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2017/06/20 16:56:39.645441, 5, pid=28186, effective(65534, 65534), real(65534, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2017/06/20 16:56:39.645502, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2017/06/20 16:56:39.645544, 10, pid=28186, effective(0, 0), real(0, 0)] ../source3/lib/util_event.c:53(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled [2017/06/20 16:56:55.192317, 4, pid=28186, 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 [2017/06/20 16:56:55.192394, 5, pid=28186, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2017/06/20 16:56:55.192414, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2017/06/20 16:56:55.192467, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2017/06/20 16:56:55.192501, 4, pid=28186, 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 [2017/06/20 16:56:55.192529, 5, pid=28186, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2017/06/20 16:56:55.192552, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2017/06/20 16:56:55.192582, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2017/06/20 16:56:55.192602, 4, pid=28186, 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 [2017/06/20 16:56:55.192619, 5, pid=28186, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2017/06/20 16:56:55.192651, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2017/06/20 16:56:55.192718, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2017/06/20 16:56:55.192763, 5, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order) check lock order 1 for /var/lock/samba/smbXsrv_session_global.tdb [2017/06/20 16:56:55.192793, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1:/var/lock/samba/smbXsrv_session_global.tdb 2: 3: [2017/06/20 16:56:55.192831, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Locking key 08B53AB2 [2017/06/20 16:56:55.192888, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal) Allocated locked data 0x0x7f600f7b2540 [2017/06/20 16:56:55.192952, 5, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor) release lock order 1 for /var/lock/samba/smbXsrv_session_global.tdb [2017/06/20 16:56:55.193071, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1: 2: 3: [2017/06/20 16:56:55.193106, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Unlocking key 08B53AB2 [2017/06/20 16:56:55.193148, 5, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order) check lock order 1 for /var/lock/samba/locking.tdb [2017/06/20 16:56:55.193188, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1:/var/lock/samba/locking.tdb 2: 3: [2017/06/20 16:56:55.193236, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Locking key 1CFD0000000000008000 [2017/06/20 16:56:55.193275, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal) Allocated locked data 0x0x7f600f7ae2e0 [2017/06/20 16:56:55.193319, 10, pid=28186, effective(0, 0), real(0, 0), class=locking] ../source3/locking/share_mode_lock.c:283(share_mode_memcache_fetch) fetched entry for file . seq 0x17790869942674980493 key fd1c:80:0 [2017/06/20 16:56:55.193371, 10, pid=28186, effective(0, 0), real(0, 0), class=locking] ../source3/locking/locking.c:1229(find_delete_on_close_token) find_delete_on_close_token: name_hash = 0xd7088907 [2017/06/20 16:56:55.193416, 10, pid=28186, effective(0, 0), real(0, 0), class=locking] ../source3/locking/share_mode_lock.c:366(unparse_share_modes) unparse_share_modes: [2017/06/20 16:56:55.193454, 1, pid=28186, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:413(ndr_print_debug) d: struct share_mode_data sequence_number : 0xf6e5ddf3ea50fe8d (-655874131034571123) servicepath : * servicepath : '/export/vol1' base_name : * base_name : '.' 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 : Thu Jan 1 02:00:00 1970 IST.0 changed_write_time : Thu Jan 1 02:00:00 1970 IST.0 fresh : 0x00 (0) modified : 0x01 (1) record : * id: struct file_id devid : 0x000000000000fd1c (64796) inode : 0x0000000000000080 (128) extid : 0x0000000000000000 (0) [2017/06/20 16:56:55.193876, 10, pid=28186, effective(0, 0), real(0, 0), class=locking] ../source3/locking/share_mode_lock.c:155(share_mode_memcache_delete) deleting entry for file . seq 0x17790869942674980493 key fd1c:80:0 [2017/06/20 16:56:55.193908, 10, pid=28186, effective(0, 0), real(0, 0), class=locking] ../source3/locking/share_mode_lock.c:378(unparse_share_modes) No used share mode found [2017/06/20 16:56:55.193937, 5, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor) release lock order 1 for /var/lock/samba/locking.tdb [2017/06/20 16:56:55.193960, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1: 2: 3: [2017/06/20 16:56:55.194011, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Unlocking key 1CFD0000000000008000 [2017/06/20 16:56:55.194044, 4, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/dir.c:233(dptr_close_internal) closing dptr key 0 [2017/06/20 16:56:55.194094, 5, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order) check lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb [2017/06/20 16:56:55.194125, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1:/var/lock/samba/smbXsrv_open_global.tdb 2: 3: [2017/06/20 16:56:55.194157, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Locking key 39E0ADD8 [2017/06/20 16:56:55.194208, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal) Allocated locked data 0x0x7f600f7add60 [2017/06/20 16:56:55.194271, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Unlocking key 39E0ADD8 [2017/06/20 16:56:55.194345, 5, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor) release lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb [2017/06/20 16:56:55.194395, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1: 2: 3: [2017/06/20 16:56:55.194439, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/files.c:565(file_free) freed files structure 2436840126 (0 used) [2017/06/20 16:56:55.194468, 5, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order) check lock order 1 for /var/lock/samba/smbXsrv_tcon_global.tdb [2017/06/20 16:56:55.194492, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1:/var/lock/samba/smbXsrv_tcon_global.tdb 2: 3: [2017/06/20 16:56:55.194527, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Locking key D2AFC732 [2017/06/20 16:56:55.194563, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal) Allocated locked data 0x0x7f600f7a5e60 [2017/06/20 16:56:55.194624, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key) Unlocking key D2AFC732 [2017/06/20 16:56:55.194661, 5, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor) release lock order 1 for /var/lock/samba/smbXsrv_tcon_global.tdb [2017/06/20 16:56:55.194811, 10, pid=28186, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order) lock order: 1: 2: 3: [2017/06/20 16:56:55.194862, 4, pid=28186, 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 [2017/06/20 16:56:55.194894, 5, pid=28186, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2017/06/20 16:56:55.194930, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2017/06/20 16:56:55.195011, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2017/06/20 16:56:55.195056, 2, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:1144(close_cnum) win-1sfc6cv4q52 (ipv4:170.70.2.57:53183) closed connection to service vol1 [2017/06/20 16:56:55.195122, 4, pid=28186, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:874(vfs_ChDir) vfs_ChDir to / [2017/06/20 16:56:55.195186, 4, pid=28186, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:885(vfs_ChDir) vfs_ChDir got / [2017/06/20 16:56:55.195237, 4, pid=28186, 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 [2017/06/20 16:56:55.195279, 5, pid=28186, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2017/06/20 16:56:55.195307, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2017/06/20 16:56:55.195352, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2017/06/20 16:56:55.291777, 4, pid=28186, 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 [2017/06/20 16:56:55.291838, 5, pid=28186, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2017/06/20 16:56:55.291867, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2017/06/20 16:56:55.291917, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2017/06/20 16:56:55.291986, 3, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:271(smbd_smb2_request_destructor) ZSTATS: Request 0x7f600f7c6510: not started, start_time_usec=0 [2017/06/20 16:56:55.292052, 3, pid=28186, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:275(smbd_smb2_request_destructor) ZSTATS: Request 0x7f600f7ab610: dangling request, start_time_usec=1497966978391737 [2017/06/20 16:56:55.292146, 5, pid=28186, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:403(messaging_deregister) Deregistering messaging pointer for type 784 - private_data=0x7f600f7ac8b0 [2017/06/20 16:56:55.292296, 10, pid=28186, effective(0, 0), real(0, 0)] ../source3/lib/messages_dgm_ref.c:142(msg_dgm_ref_destructor) msg_dgm_ref_destructor: refs=(nil) [2017/06/20 16:56:55.292560, 0, pid=28186, effective(0, 0), real(0, 0)] ../source3/lib/util.c:791(smb_panic_s3) PANIC (pid 28186): async open timeout