Attachment 13296 Details for Bug 12853 – Log file

Log file

win-1sfc6cv4q52.log (text/plain), 23.06 KB, created by Lev on 2017-06-20 14:13:26 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Lev

Created: 2017-06-20 14:13:26 UTC

Size: 23.06 KB

patch

obsolete

>[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:<none> 3:<none>
>[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:<none> 2:<none> 3:<none>
>[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:<none> 3:<none>
>[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:<none> 2:<none> 3:<none>
>[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:<none> 3:<none>
>[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:<none> 2:<none> 3:<none>
>[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:<none> 3:<none>
>[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:<none> 2:<none> 3:<none>
>[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:<none> 3:<none>
>[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:<none> 2:<none> 3:<none>
>[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

Actions: View

Attachments on bug 12853: 13296 | 13564 | 13743