Attachment 13252 Details for Bug 12818 – Full logs

Full logs

vm21-win2012se.log (text/plain), 216.05 KB, created by Lev on 2017-06-05 14:42:12 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Lev

Created: 2017-06-05 14:42:12 UTC

Size: 216.05 KB

patch

obsolete

>[2017/06/05 16:22:32.278698,  6, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2229(lp_file_list_changed)
>  lp_file_list_changed()
>  file /etc/samba/smb.conf -> /etc/samba/smb.conf  last mod_time: Mon Jun  5 14:14:33 2017
>  
>[2017/06/05 16:22:32.279394,  5, pid=2877, 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/05 16:22:32.279802, 10, pid=2877, 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/05 16:22:32.280148, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 5A21384A
>[2017/06/05 16:22:32.280442, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3b0860
>[2017/06/05 16:22:32.280858, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:943(smbXsrv_session_global_store)
>[2017/06/05 16:22:32.281041, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:945(smbXsrv_session_global_store)
>  smbXsrv_session_global_store: key '5A21384A' stored
>[2017/06/05 16:22:32.281344,  1, pid=2877, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:413(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        : 0x5a21384a (1512126538)
>                  session_wire_id          : 0x000000005a21384a (1512126538)
>                  creation_time            : Mon Jun  5 16:22:32 2017 IDT
>                  expiration_time          : Thu Jan  1 02:00:00 1970 IST
>                  auth_time                : Mon Jun  5 16:22:32 2017 IDT
>                  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                 : 0x00000009 (9)
>                                  sids: ARRAY(9)
>                                      sids                     : S-1-5-21-1893543895-1847372660-4172524467-501
>                                      sids                     : S-1-5-21-1893543895-1847372660-4172524467-514
>                                      sids                     : S-1-22-2-65534
>                                      sids                     : S-1-1-0
>                                      sids                     : S-1-5-2
>                                      sids                     : S-1-5-32-546
>                                      sids                     : S-1-22-1-65534
>                                      sids                     : S-1-22-2-1000003
>                                      sids                     : S-1-22-2-1000004
>                                  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                      : 0x000000000000fffe (65534)
>                                  gid                      : 0x000000000000fffe (65534)
>                                  ngroups                  : 0x00000003 (3)
>                                  groups: ARRAY(3)
>                                      groups                   : 0x000000000000fffe (65534)
>                                      groups                   : 0x00000000000f4243 (1000003)
>                                      groups                   : 0x00000000000f4244 (1000004)
>                          info                     : *
>                              info: struct auth_user_info
>                                  account_name             : *
>                                      account_name             : 'nobody'
>                                  user_principal_name      : NULL
>                                  user_principal_constructed: 0x00 (0)
>                                  domain_name              : *
>                                      domain_name              : 'VSA-00000134'
>                                  dns_domain_name          : NULL
>                                  full_name                : NULL
>                                  logon_script             : NULL
>                                  profile_path             : NULL
>                                  home_directory           : NULL
>                                  home_drive               : NULL
>                                  logon_server             : NULL
>                                  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               : 0x00000000 (0)
>                                  authenticated            : 0x00 (0)
>                          unix_info                : *
>                              unix_info: struct auth_user_info_unix
>                                  unix_name                : *
>                                      unix_name                : 'nobody'
>                                  sanitized_username       : *
>                                      sanitized_username       : 'liran'
>                          torture                  : NULL
>                          credentials              : NULL
>                  connection_dialect       : 0x0300 (768)
>                  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                      : 0x0000000000000b3d (2877)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                          local_address            : 'ipv4:170.70.2.104:445'
>                          remote_address           : 'ipv4:170.70.2.21:54923'
>                          remote_name              : '170.70.2.21'
>                          auth_session_info_seqnum : 0x00000001 (1)
>                          connection               : *
>                          encryption_cipher        : 0x0001 (1)
>[2017/06/05 16:22:32.291874,  5, pid=2877, 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/05 16:22:32.291897, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.291919, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 5A21384A
>[2017/06/05 16:22:32.291942, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1405(smbXsrv_session_update)
>[2017/06/05 16:22:32.291954, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1413(smbXsrv_session_update)
>  smbXsrv_session_update: global_id (0x5a21384a) stored
>[2017/06/05 16:22:32.291996,  1, pid=2877, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:413(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                 : 0x5a21384a (1512126538)
>                  global                   : *
>                      global: struct smbXsrv_session_global0
>                          db_rec                   : NULL
>                          session_global_id        : 0x5a21384a (1512126538)
>                          session_wire_id          : 0x000000005a21384a (1512126538)
>                          creation_time            : Mon Jun  5 16:22:32 2017 IDT
>                          expiration_time          : Thu Jan  1 02:00:00 1970 IST
>                          auth_time                : Mon Jun  5 16:22:32 2017 IDT
>                          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                 : 0x00000009 (9)
>                                          sids: ARRAY(9)
>                                              sids                     : S-1-5-21-1893543895-1847372660-4172524467-501
>                                              sids                     : S-1-5-21-1893543895-1847372660-4172524467-514
>                                              sids                     : S-1-22-2-65534
>                                              sids                     : S-1-1-0
>                                              sids                     : S-1-5-2
>                                              sids                     : S-1-5-32-546
>                                              sids                     : S-1-22-1-65534
>                                              sids                     : S-1-22-2-1000003
>                                              sids                     : S-1-22-2-1000004
>                                          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                      : 0x000000000000fffe (65534)
>                                          gid                      : 0x000000000000fffe (65534)
>                                          ngroups                  : 0x00000003 (3)
>                                          groups: ARRAY(3)
>                                              groups                   : 0x000000000000fffe (65534)
>                                              groups                   : 0x00000000000f4243 (1000003)
>                                              groups                   : 0x00000000000f4244 (1000004)
>                                  info                     : *
>                                      info: struct auth_user_info
>                                          account_name             : *
>                                              account_name             : 'nobody'
>                                          user_principal_name      : NULL
>                                          user_principal_constructed: 0x00 (0)
>                                          domain_name              : *
>                                              domain_name              : 'VSA-00000134'
>                                          dns_domain_name          : NULL
>                                          full_name                : NULL
>                                          logon_script             : NULL
>                                          profile_path             : NULL
>                                          home_directory           : NULL
>                                          home_drive               : NULL
>                                          logon_server             : NULL
>                                          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               : 0x00000000 (0)
>                                          authenticated            : 0x00 (0)
>                                  unix_info                : *
>                                      unix_info: struct auth_user_info_unix
>                                          unix_name                : *
>                                              unix_name                : 'nobody'
>                                          sanitized_username       : *
>                                              sanitized_username       : 'liran'
>                                  torture                  : NULL
>                                  credentials              : NULL
>                          connection_dialect       : 0x0300 (768)
>                          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                      : 0x0000000000000b3d (2877)
>                                      task_id                  : 0x00000000 (0)
>                                      vnn                      : 0xffffffff (4294967295)
>                                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                                  local_address            : 'ipv4:170.70.2.104:445'
>                                  remote_address           : 'ipv4:170.70.2.21:54923'
>                                  remote_name              : '170.70.2.21'
>                                  auth_session_info_seqnum : 0x00000001 (1)
>                                  connection               : *
>                                  encryption_cipher        : 0x0001 (1)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Mon Jun  5 16:22:32 2017 IDT
>                  nonce_high_random        : 0x5d8110aabdabd278 (6737684843035611768)
>                  nonce_high_max           : 0x0000000000ffffff (16777215)
>                  nonce_high               : 0x0000000000000000 (0)
>                  nonce_low                : 0x0000000000000000 (0)
>                  compat                   : *
>                  tcon_table               : *
>                  pending_auth             : NULL
>[2017/06/05 16:22:32.293810, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3014(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:171
>[2017/06/05 16:22:32.293866, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:925(smb2_set_operation_credit)
>  smb2_set_operation_credit: requested 31, charge 1, granted 31, current possible/max 512/512, total granted/max/low/range 31/8192/4/31
>[2017/06/05 16:22:32.294599, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3912(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2017/06/05 16:22:32.294871, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 4 (position 4) from bitmap
>[2017/06/05 16:22:32.295068, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_TCON] mid = 4
>[2017/06/05 16:22:32.295286,  0, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=(nil)
>[2017/06/05 16:22:32.295615,  4, pid=2877, 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/05 16:22:32.295852,  5, pid=2877, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2017/06/05 16:22:32.296064,  5, pid=2877, 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/05 16:22:32.296298,  5, pid=2877, 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/05 16:22:32.296533, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_tcon.c:211(smbd_smb2_tree_connect)
>  smbd_smb2_tree_connect: path[\\170.70.2.104\vol1] share[vol1]
>[2017/06/05 16:22:32.296754,  7, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:4102(lp_servicenumber)
>  lp_servicenumber: couldn't find vol1
>[2017/06/05 16:22:32.296955,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc)
>  Finding user vol1
>[2017/06/05 16:22:32.297170,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is vol1
>[2017/06/05 16:22:32.297773,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/username.c:141(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as uppercase is VOL1
>[2017/06/05 16:22:32.298134,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/username.c:153(Get_Pwnam_internals)
>  Checking combinations of 0 uppercase letters in vol1
>[2017/06/05 16:22:32.298184,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals)
>  Get_Pwnam_internals didn't find user [vol1]!
>[2017/06/05 16:22:32.298237,  3, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/service.c:150(find_service)
>  checking for home directory vol1 gave (NULL)
>[2017/06/05 16:22:32.298404,  7, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:4102(lp_servicenumber)
>  lp_servicenumber: couldn't find printers
>[2017/06/05 16:22:32.298589,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2058(process_registry_service)
>  process_registry_service: service name printers
>[2017/06/05 16:22:32.298641,  7, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_api.c:143(regkey_open_onelevel)
>  regkey_open_onelevel: name = [printers]
>[2017/06/05 16:22:32.298673, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:857(regdb_open)
>  regdb_open: incrementing refcount (2->3)
>[2017/06/05 16:22:32.298908, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_cachehook.c:125(reghook_cache_find)
>  reghook_cache_find: Searching for keyname [\HKLM\SOFTWARE\Samba\smbconf\printers]
>[2017/06/05 16:22:32.298943, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:367(pathtree_find)
>  pathtree_find: Enter [\HKLM\SOFTWARE\Samba\smbconf\printers]
>[2017/06/05 16:22:32.299071, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:440(pathtree_find)
>  pathtree_find: Exit
>[2017/06/05 16:22:32.299116, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_cachehook.c:130(reghook_cache_find)
>  reghook_cache_find: found ops 0x7f38e87c4580 for key [\HKLM\SOFTWARE\Samba\smbconf\printers]
>[2017/06/05 16:22:32.299169, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1739(regdb_fetch_keys_internal)
>  key [HKLM\SOFTWARE\Samba\smbconf\printers] not found
>[2017/06/05 16:22:32.299336, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:902(regdb_close)
>  regdb_close: decrementing refcount (3->2)
>[2017/06/05 16:22:32.299376,  7, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:4102(lp_servicenumber)
>  lp_servicenumber: couldn't find printers
>[2017/06/05 16:22:32.299408,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2058(process_registry_service)
>  process_registry_service: service name vol1
>[2017/06/05 16:22:32.299438,  7, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_api.c:143(regkey_open_onelevel)
>  regkey_open_onelevel: name = [vol1]
>[2017/06/05 16:22:32.299630, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:857(regdb_open)
>  regdb_open: incrementing refcount (2->3)
>[2017/06/05 16:22:32.299676, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_cachehook.c:125(reghook_cache_find)
>  reghook_cache_find: Searching for keyname [\HKLM\SOFTWARE\Samba\smbconf\vol1]
>[2017/06/05 16:22:32.299876, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:367(pathtree_find)
>  pathtree_find: Enter [\HKLM\SOFTWARE\Samba\smbconf\vol1]
>[2017/06/05 16:22:32.299933, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:440(pathtree_find)
>  pathtree_find: Exit
>[2017/06/05 16:22:32.299963, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_cachehook.c:130(reghook_cache_find)
>  reghook_cache_find: found ops 0x7f38e87c4580 for key [\HKLM\SOFTWARE\Samba\smbconf\vol1]
>[2017/06/05 16:22:32.300236, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:902(regdb_close)
>  regdb_close: decrementing refcount (3->2)
>[2017/06/05 16:22:32.300410,  7, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_api.c:143(regkey_open_onelevel)
>  regkey_open_onelevel: name = [vol1]
>[2017/06/05 16:22:32.300443, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:857(regdb_open)
>  regdb_open: incrementing refcount (2->3)
>[2017/06/05 16:22:32.300501, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_cachehook.c:125(reghook_cache_find)
>  reghook_cache_find: Searching for keyname [\HKLM\SOFTWARE\Samba\smbconf\vol1]
>[2017/06/05 16:22:32.300669, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:367(pathtree_find)
>  pathtree_find: Enter [\HKLM\SOFTWARE\Samba\smbconf\vol1]
>[2017/06/05 16:22:32.300711, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:440(pathtree_find)
>  pathtree_find: Exit
>[2017/06/05 16:22:32.300911, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_cachehook.c:130(reghook_cache_find)
>  reghook_cache_find: found ops 0x7f38e87c4580 for key [\HKLM\SOFTWARE\Samba\smbconf\vol1]
>[2017/06/05 16:22:32.301008, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_dispatcher.c:151(fetch_reg_values)
>  fetch_reg_values called for key 'HKLM\SOFTWARE\Samba\smbconf\vol1' (ops 0x7f38e87c4580)
>[2017/06/05 16:22:32.301176, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1905(regdb_fetch_values_internal)
>  regdb_fetch_values: Looking for values of key [HKLM\SOFTWARE\Samba\smbconf\vol1]
>[2017/06/05 16:22:32.301370, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[0]: name[path] len[26]
>[2017/06/05 16:22:32.301416, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[1]: name[read only] len[6]
>[2017/06/05 16:22:32.301588, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[2]: name[hosts deny] len[8]
>[2017/06/05 16:22:32.301829, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[3]: name[kernel oplocks] len[8]
>[2017/06/05 16:22:32.302050, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[4]: name[level2 oplocks] len[6]
>[2017/06/05 16:22:32.302241, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[5]: name[map archive] len[8]
>[2017/06/05 16:22:32.302415, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[6]: name[create mask] len[10]
>[2017/06/05 16:22:32.302578, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[7]: name[force create mode] len[10]
>[2017/06/05 16:22:32.302786, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[8]: name[directory mask] len[10]
>[2017/06/05 16:22:32.302833, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[9]: name[force directory mode] len[10]
>[2017/06/05 16:22:32.302869, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[10]: name[aio read size] len[4]
>[2017/06/05 16:22:32.302907, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[11]: name[aio write size] len[4]
>[2017/06/05 16:22:32.302944, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[12]: name[browseable] len[8]
>[2017/06/05 16:22:32.303196, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[13]: name[hide unreadable] len[6]
>[2017/06/05 16:22:32.303523, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[14]: name[hide unwriteable files] len[6]
>[2017/06/05 16:22:32.303871, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[15]: name[hide dot files] len[6]
>[2017/06/05 16:22:32.304237, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[16]: name[hosts allow] len[24]
>[2017/06/05 16:22:32.304566, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[17]: name[guest ok] len[8]
>[2017/06/05 16:22:32.304925, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:1850(regdb_unpack_values)
>  regdb_unpack_values: value[18]: name[hide files] len[12]
>[2017/06/05 16:22:32.305750, 10, pid=2877, effective(0, 0), real(0, 0), class=registry] ../source3/registry/reg_backend_db.c:902(regdb_close)
>  regdb_close: decrementing refcount (3->2)
>[2017/06/05 16:22:32.305930,  2, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2691(lp_do_section)
>  Processing section "[vol1]"
>[2017/06/05 16:22:32.306185,  8, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1434(add_a_service)
>  add_a_service: Creating snum = 1 for vol1
>[2017/06/05 16:22:32.306402, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1484(hash_a_service)
>  hash_a_service: hashing index 1 for service name vol1
>  doing parameter path = /export/vol1
>  doing parameter read only = no
>  doing parameter hosts deny = ALL
>  doing parameter kernel oplocks = Yes
>  doing parameter level2 oplocks = No
>  doing parameter map archive = Yes
>  doing parameter create mask = 0744
>  doing parameter force create mode = 0744
>  doing parameter directory mask = 0755
>  doing parameter force directory mode = 0755
>  doing parameter aio read size = 1
>  doing parameter aio write size = 1
>  doing parameter browseable = Yes
>  doing parameter hide unreadable = No
>  doing parameter hide unwriteable files = No
>  doing parameter hide dot files = No
>  doing parameter hosts allow = 170.70.2.21
>  doing parameter guest ok = Yes
>  doing parameter hide files = file2
>[2017/06/05 16:22:32.309234,  5, pid=2877, 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/05 16:22:32.309434, 10, pid=2877, 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/05 16:22:32.309612, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key E394D695
>[2017/06/05 16:22:32.309844, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3a4c00
>[2017/06/05 16:22:32.310145, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:709(smbXsrv_tcon_global_store)
>[2017/06/05 16:22:32.310265, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:711(smbXsrv_tcon_global_store)
>  smbXsrv_tcon_global_store: key 'E394D695' stored
>[2017/06/05 16:22:32.310479,  1, pid=2877, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:413(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           : 0xe394d695 (3818182293)
>                  tcon_wire_id             : 0xe394d695 (3818182293)
>                  server_id: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  creation_time            : Mon Jun  5 16:22:32 2017 IDT
>                  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
>[2017/06/05 16:22:32.313251, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key E394D695
>[2017/06/05 16:22:32.313432,  5, pid=2877, 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/05 16:22:32.313636, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.313862, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:831(smbXsrv_tcon_create)
>[2017/06/05 16:22:32.313998, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:839(smbXsrv_tcon_create)
>  smbXsrv_tcon_create: global_id (0xe394d695) stored
>[2017/06/05 16:22:32.314045,  1, pid=2877, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:413(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                 : 0xe394d695 (3818182293)
>                  global                   : *
>                      global: struct smbXsrv_tcon_global0
>                          db_rec                   : NULL
>                          tcon_global_id           : 0xe394d695 (3818182293)
>                          tcon_wire_id             : 0xe394d695 (3818182293)
>                          server_id: struct server_id
>                              pid                      : 0x0000000000000b3d (2877)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                          creation_time            : Mon Jun  5 16:22:32 2017 IDT
>                          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                : Mon Jun  5 16:22:32 2017 IDT
>                  compat                   : NULL
>[2017/06/05 16:22:32.314464,  3, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/access.c:338(allow_access)
>  Allowed connection from 170.70.2.21 (170.70.2.21)
>[2017/06/05 16:22:32.314563, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:72(set_conn_connectpath)
>  set_conn_connectpath: service vol1, connectpath = /export/vol1
>[2017/06/05 16:22:32.314590,  3, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:581(make_connection_snum)
>  Connect path is '/export/vol1' for service [vol1]
>[2017/06/05 16:22:32.314612, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:221(user_ok_token)
>  user_ok_token: share vol1 is ok for unix user nobody
>[2017/06/05 16:22:32.314632, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:268(is_share_read_only_for_token)
>  is_share_read_only_for_user: share vol1 is read-write for unix user nobody
>[2017/06/05 16:22:32.314682, 10, pid=2877, 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
>[2017/06/05 16:22:32.314706,  3, pid=2877, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:113(vfs_init_default)
>  Initialising default vfs hooks
>[2017/06/05 16:22:32.314756, 10, pid=2877, 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]/
>[2017/06/05 16:22:32.314777,  5, pid=2877, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:103(smb_register_vfs)
>  Successfully added vfs backend '/[Default VFS]/'
>[2017/06/05 16:22:32.314805, 10, pid=2877, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:64(vfs_find_backend_entry)
>  vfs_find_backend_entry called for posixacl
>[2017/06/05 16:22:32.314822,  5, pid=2877, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:103(smb_register_vfs)
>  Successfully added vfs backend 'posixacl'
>[2017/06/05 16:22:32.314838,  3, pid=2877, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:139(vfs_init_custom)
>  Initialising custom vfs hooks from [/[Default VFS]/]
>[2017/06/05 16:22:32.314854, 10, pid=2877, 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
>[2017/06/05 16:22:32.314919, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/notify_msg.c:80(notify_init)
>  notify_init: notifyd=2602
>[2017/06/05 16:22:32.314942,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:356(messaging_register)
>  Registering messaging pointer for type 784 - private_data=0x7f38ed3b0ed0
>[2017/06/05 16:22:32.314962,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:356(messaging_register)
>  Registering messaging pointer for type 793 - private_data=0x7f38ed39da20
>[2017/06/05 16:22:32.315025,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:356(messaging_register)
>  Registering messaging pointer for type 799 - private_data=0x7f38ed39da20
>[2017/06/05 16:22:32.315141,  3, pid=2877, effective(0, 0), real(0, 0), class=locking] ../source3/smbd/oplock_linux.c:260(linux_init_kernel_oplocks)
>  Linux kernel oplocks enabled
>[2017/06/05 16:22:32.315203, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:72(set_conn_connectpath)
>  set_conn_connectpath: service vol1, connectpath = /export/vol1
>[2017/06/05 16:22:32.315290,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:686(make_connection_snum)
>  cmd=/var/lib/zadara/scripts/vc/samba/zadara_smb_preexec.sh "nobody" "vol1" "vm21-win2012se" "170.70.2.21"
>[2017/06/05 16:22:32.321536, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:221(user_ok_token)
>  user_ok_token: share vol1 is ok for unix user nobody
>[2017/06/05 16:22:32.321621, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:268(is_share_read_only_for_token)
>  is_share_read_only_for_user: share vol1 is read-write for unix user nobody
>[2017/06/05 16:22:32.321706, 10, pid=2877, 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
>[2017/06/05 16:22:32.321874,  4, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
>  setting sec ctx (65534, 65534) - sec_ctx_stack_ndx = 0
>[2017/06/05 16:22:32.321928,  5, pid=2877, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:63(security_token_debug)
>  Security token SIDs (9):
>    SID[  0]: S-1-5-21-1893543895-1847372660-4172524467-501
>    SID[  1]: S-1-5-21-1893543895-1847372660-4172524467-514
>    SID[  2]: S-1-22-2-65534
>    SID[  3]: S-1-1-0
>    SID[  4]: S-1-5-2
>    SID[  5]: S-1-5-32-546
>    SID[  6]: S-1-22-1-65534
>    SID[  7]: S-1-22-2-1000003
>    SID[  8]: S-1-22-2-1000004
>   Privileges (0x               0):
>   Rights (0x               0):
>[2017/06/05 16:22:32.322147,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token)
>  UNIX token of user 65534
>  Primary group is 65534 and contains 3 supplementary groups
>  Group[  0]: 65534
>  Group[  1]: 1000003
>  Group[  2]: 1000004
>[2017/06/05 16:22:32.322248,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:363(change_to_user_internal)
>  Impersonated user: uid=(65534,65534), gid=(0,65534)
>[2017/06/05 16:22:32.322299,  4, pid=2877, 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/05 16:22:32.322338,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2017/06/05 16:22:32.322373,  5, pid=2877, 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/05 16:22:32.322432,  5, pid=2877, 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/05 16:22:32.322493, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:72(set_conn_connectpath)
>  set_conn_connectpath: service vol1, connectpath = /export/vol1
>[2017/06/05 16:22:32.322661,  1, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:842(make_connection_snum)
>  zsamba_stats_open(/export/vol1, 170.70.2.21), remote_hostname=170.70.2.21
>[2017/06/05 16:22:32.322888, 10, pid=2877, effective(0, 0), real(0, 0), class=vfs] ../source3/modules/vfs_default.c:170(vfswrap_fs_capabilities)
>  vfswrap_fs_capabilities: timestamp resolution of sec available on share vol1, directory /export/vol1
>[2017/06/05 16:22:32.322947,  2, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:868(make_connection_snum)
>  vm21-win2012se (ipv4:170.70.2.21:54923) connect to service vol1 initially as user nobody (uid=65534, gid=65534) (pid 2877)
>[2017/06/05 16:22:32.323082,  5, pid=2877, 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/05 16:22:32.323131, 10, pid=2877, 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/05 16:22:32.323179, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key E394D695
>[2017/06/05 16:22:32.323232, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3828d0
>[2017/06/05 16:22:32.323297, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:709(smbXsrv_tcon_global_store)
>[2017/06/05 16:22:32.323346, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:711(smbXsrv_tcon_global_store)
>  smbXsrv_tcon_global_store: key 'E394D695' stored
>[2017/06/05 16:22:32.323391,  1, pid=2877, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:413(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           : 0xe394d695 (3818182293)
>                  tcon_wire_id             : 0xe394d695 (3818182293)
>                  server_id: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  creation_time            : Mon Jun  5 16:22:32 2017 IDT
>                  share_name               : 'vol1'
>                  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        : 0x5a21384a (1512126538)
>                  signing_flags            : 0x00 (0)
>                         0: SMBXSRV_SIGNING_REQUIRED 
>                         0: SMBXSRV_PROCESSED_SIGNED_PACKET
>                         0: SMBXSRV_PROCESSED_UNSIGNED_PACKET
>[2017/06/05 16:22:32.323916, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key E394D695
>[2017/06/05 16:22:32.323964,  5, pid=2877, 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/05 16:22:32.324052, 10, pid=2877, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.324094, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:876(smbXsrv_tcon_update)
>[2017/06/05 16:22:32.324115, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:884(smbXsrv_tcon_update)
>  smbXsrv_tcon_update: global_id (0xe394d695) stored
>[2017/06/05 16:22:32.324152,  1, pid=2877, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:413(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                 : 0xe394d695 (3818182293)
>                  global                   : *
>                      global: struct smbXsrv_tcon_global0
>                          db_rec                   : NULL
>                          tcon_global_id           : 0xe394d695 (3818182293)
>                          tcon_wire_id             : 0xe394d695 (3818182293)
>                          server_id: struct server_id
>                              pid                      : 0x0000000000000b3d (2877)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                          creation_time            : Mon Jun  5 16:22:32 2017 IDT
>                          share_name               : 'vol1'
>                          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        : 0x5a21384a (1512126538)
>                          signing_flags            : 0x00 (0)
>                                 0: SMBXSRV_SIGNING_REQUIRED 
>                                 0: SMBXSRV_PROCESSED_SIGNED_PACKET
>                                 0: SMBXSRV_PROCESSED_UNSIGNED_PACKET
>                  status                   : NT_STATUS_OK
>                  idle_time                : Mon Jun  5 16:22:32 2017 IDT
>                  compat                   : *
>[2017/06/05 16:22:32.324845, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3014(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:170
>[2017/06/05 16:22:32.324896, 10, pid=2877, effective(0, 0), real(0, 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/5/31
>[2017/06/05 16:22:32.325632, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3912(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2017/06/05 16:22:32.325688, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 5 (position 5) from bitmap
>[2017/06/05 16:22:32.325765, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 5
>[2017/06/05 16:22:32.325822,  4, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
>  setting sec ctx (65534, 65534) - sec_ctx_stack_ndx = 0
>[2017/06/05 16:22:32.325869,  5, pid=2877, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:63(security_token_debug)
>  Security token SIDs (9):
>    SID[  0]: S-1-5-21-1893543895-1847372660-4172524467-501
>    SID[  1]: S-1-5-21-1893543895-1847372660-4172524467-514
>    SID[  2]: S-1-22-2-65534
>    SID[  3]: S-1-1-0
>    SID[  4]: S-1-5-2
>    SID[  5]: S-1-5-32-546
>    SID[  6]: S-1-22-1-65534
>    SID[  7]: S-1-22-2-1000003
>    SID[  8]: S-1-22-2-1000004
>   Privileges (0x               0):
>   Rights (0x               0):
>[2017/06/05 16:22:32.326109,  5, pid=2877, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token)
>  UNIX token of user 65534
>  Primary group is 65534 and contains 3 supplementary groups
>  Group[  0]: 65534
>  Group[  1]: 1000003
>  Group[  2]: 1000004
>[2017/06/05 16:22:32.326197,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:363(change_to_user_internal)
>  Impersonated user: uid=(65534,65534), gid=(0,65534)
>[2017/06/05 16:22:32.326242,  4, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:874(vfs_ChDir)
>  vfs_ChDir to /export/vol1
>[2017/06/05 16:22:32.326313,  4, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:885(vfs_ChDir)
>  vfs_ChDir got /export/vol1
>[2017/06/05 16:22:32.326360,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
>  check lock order 1 for /var/lock/samba/smbXsrv_tcon_global.tdb
>[2017/06/05 16:22:32.326402, 10, pid=2877, effective(65534, 65534), real(65534, 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/05 16:22:32.326447, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key E394D695
>[2017/06/05 16:22:32.326496, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3828d0
>[2017/06/05 16:22:32.326580, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_tcon.c:709(smbXsrv_tcon_global_store)
>[2017/06/05 16:22:32.326613, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_tcon.c:711(smbXsrv_tcon_global_store)
>  smbXsrv_tcon_global_store: key 'E394D695' stored
>[2017/06/05 16:22:32.326658,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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           : 0xe394d695 (3818182293)
>                  tcon_wire_id             : 0xe394d695 (3818182293)
>                  server_id: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  creation_time            : Mon Jun  5 16:22:32 2017 IDT
>                  share_name               : 'vol1'
>                  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        : 0x5a21384a (1512126538)
>                  signing_flags            : 0x04 (4)
>                         0: SMBXSRV_SIGNING_REQUIRED 
>                         0: SMBXSRV_PROCESSED_SIGNED_PACKET
>                         1: SMBXSRV_PROCESSED_UNSIGNED_PACKET
>[2017/06/05 16:22:32.327225, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key E394D695
>[2017/06/05 16:22:32.327274,  5, pid=2877, 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_tcon_global.tdb
>[2017/06/05 16:22:32.327314, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.327355, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_tcon.c:876(smbXsrv_tcon_update)
>[2017/06/05 16:22:32.327383, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_tcon.c:884(smbXsrv_tcon_update)
>  smbXsrv_tcon_update: global_id (0xe394d695) stored
>[2017/06/05 16:22:32.327421,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                 : 0xe394d695 (3818182293)
>                  global                   : *
>                      global: struct smbXsrv_tcon_global0
>                          db_rec                   : NULL
>                          tcon_global_id           : 0xe394d695 (3818182293)
>                          tcon_wire_id             : 0xe394d695 (3818182293)
>                          server_id: struct server_id
>                              pid                      : 0x0000000000000b3d (2877)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                          creation_time            : Mon Jun  5 16:22:32 2017 IDT
>                          share_name               : 'vol1'
>                          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        : 0x5a21384a (1512126538)
>                          signing_flags            : 0x04 (4)
>                                 0: SMBXSRV_SIGNING_REQUIRED 
>                                 0: SMBXSRV_PROCESSED_SIGNED_PACKET
>                                 1: SMBXSRV_PROCESSED_UNSIGNED_PACKET
>                  status                   : NT_STATUS_OK
>                  idle_time                : Mon Jun  5 16:22:32 2017 IDT
>                  compat                   : *
>[2017/06/05 16:22:32.328135,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=(nil)
>[2017/06/05 16:22:32.328339, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:503(smbd_smb2_create_send)
>  smbd_smb2_create: name[]
>[2017/06/05 16:22:32.328393, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:997(smbd_smb2_create_send)
>  smbd_smb2_create_send: open execution phase
>[2017/06/05 16:22:32.328458,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:443(unix_convert)
>  unix_convert called on file ""
>[2017/06/05 16:22:32.328496,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:477(unix_convert)
>  conversion finished "" -> .
>[2017/06/05 16:22:32.328527, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1199(check_reduced_name)
>  check_reduced_name: check_reduced_name [.] [/export/vol1]
>[2017/06/05 16:22:32.328564, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1259(check_reduced_name)
>  check_reduced_name realpath [.] -> [/export/vol1]
>[2017/06/05 16:22:32.328597,  5, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1370(check_reduced_name)
>  check_reduced_name: . reduced to /export/vol1
>[2017/06/05 16:22:32.328641, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5515(create_file_default)
>  create_file: access_mask = 0x100081 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x2 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = .
>[2017/06/05 16:22:32.328777, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4988(create_file_unixpath)
>  create_file_unixpath: access_mask = 0x100081 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x2 private_flags = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = .
>[2017/06/05 16:22:32.328829,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:65(fsp_new)
>  fsp_new: fsp=0x7f38ed3b32c0
>[2017/06/05 16:22:32.329035,  5, pid=2877, 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/05 16:22:32.329077, 10, pid=2877, 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/05 16:22:32.329117, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 381F9B1E
>[2017/06/05 16:22:32.329171, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed39c3c0
>[2017/06/05 16:22:32.329208, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:624(smbXsrv_open_global_verify_record)
>  smbXsrv_open_global_verify_record: empty value
>[2017/06/05 16:22:32.329312, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:743(smbXsrv_open_global_store)
>  smbXsrv_open_global_store: key '381F9B1E' stored
>[2017/06/05 16:22:32.329396,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  open_global_id           : 0x381f9b1e (941595422)
>                  open_persistent_id       : 0x00000000381f9b1e (941595422)
>                  open_volatile_id         : 0x00000000a53bedbd (2772168125)
>                  open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                  open_time                : Mon Jun  5 16:22:32 2017 IDT
>                  create_guid              : 00000000-0000-0000-0000-000000000000
>                  client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                  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         : 0x0000000000000000 (0)
>[2017/06/05 16:22:32.330015, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 381F9B1E
>[2017/06/05 16:22:32.330072,  5, pid=2877, 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/05 16:22:32.330113, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.330155, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:910(smbXsrv_open_create)
>  smbXsrv_open_create: global_id (0x381f9b1e) stored
>[2017/06/05 16:22:32.330193,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                 : 0xa53bedbd (2772168125)
>                  global                   : *
>                      global: struct smbXsrv_open_global0
>                          db_rec                   : NULL
>                          server_id: struct server_id
>                              pid                      : 0x0000000000000b3d (2877)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                          open_global_id           : 0x381f9b1e (941595422)
>                          open_persistent_id       : 0x00000000381f9b1e (941595422)
>                          open_volatile_id         : 0x00000000a53bedbd (2772168125)
>                          open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                          open_time                : Mon Jun  5 16:22:32 2017 IDT
>                          create_guid              : 00000000-0000-0000-0000-000000000000
>                          client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                          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         : 0x0000000000000000 (0)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Mon Jun  5 16:22:32 2017 IDT
>                  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)
>[2017/06/05 16:22:32.330925,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:130(file_new)
>  allocated file structure fnum 2772168125 (1 used)
>[2017/06/05 16:22:32.330999, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:763(file_name_hash)
>  file_name_hash: /export/vol1/. hash 0xd7088907
>[2017/06/05 16:22:32.331058,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:206(unix_mode)
>  unix_mode: unix_mode(.) returning 0744
>[2017/06/05 16:22:32.331100, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2972(open_file_ntcreate)
>  open_file_ntcreate: fname=., dos_attrs=0x0 access_mask=0x100081 share_access=0x7 create_disposition = 0x1 create_options=0x0 unix mode=0744 oplock_request=2 private_flags = 0x0
>[2017/06/05 16:22:32.331150, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:3142(open_file_ntcreate)
>  open_file_ntcreate: fname=., after mapping access_mask=0x100081
>[2017/06/05 16:22:32.331192,  4, pid=2877, 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 = 0x100081, open_access_mask = 0x100081
>[2017/06/05 16:22:32.331237, 10, pid=2877, 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 .
>[2017/06/05 16:22:32.331402, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1251(uid_to_sid)
>  uid 0 -> sid S-1-22-1-0
>[2017/06/05 16:22:32.331486, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1300(gid_to_sid)
>  gid 0 -> sid S-1-22-2-0
>[2017/06/05 16:22:32.331541, 10, pid=2877, 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/05 16:22:32.331583, 10, pid=2877, 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/05 16:22:32.331632, 10, pid=2877, 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-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.331828, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.331935, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) 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/05 16:22:32.332208, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.332253, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.332294, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.332354, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:181(smbd_check_access_rights)
>  smbd_check_access_rights: file . requesting 0x100081 returning 0x100001 (NT_STATUS_OK)
>[2017/06/05 16:22:32.332426, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1199(check_reduced_name)
>  check_reduced_name: check_reduced_name [.] [/export/vol1]
>[2017/06/05 16:22:32.332475, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1259(check_reduced_name)
>  check_reduced_name realpath [.] -> [/export/vol1]
>[2017/06/05 16:22:32.332516,  5, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1370(check_reduced_name)
>  check_reduced_name: . reduced to /export/vol1
>[2017/06/05 16:22:32.332573, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:689(fd_open)
>  fd_open: name ., flags = 04000 mode = 0744, fd = 35. 
>[2017/06/05 16:22:32.332643, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/posix.c:498(delete_lock_ref_count)
>  delete_lock_ref_count for file .
>[2017/06/05 16:22:32.332708,  5, pid=2877, 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/05 16:22:32.332768, 10, pid=2877, 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/05 16:22:32.332817, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 381F9B1E
>[2017/06/05 16:22:32.332866, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed382ca0
>[2017/06/05 16:22:32.332931, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 381F9B1E
>[2017/06/05 16:22:32.333001,  5, pid=2877, 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/05 16:22:32.333045, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.333099,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:513(fsp_free)
>  fsp_free(fsp=0x7f38ed3b32c0)
>[2017/06/05 16:22:32.333288,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:570(file_free)
>  freed files structure 2772168125 (0 used)
>[2017/06/05 16:22:32.333325,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:3917(open_directory)
>  open_directory: opening directory ., access_mask = 0x100081, share_access = 0x7 create_options = 0x0, create_disposition = 0x1, file_attributes = 0x10
>[2017/06/05 16:22:32.333364, 10, pid=2877, 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 .
>[2017/06/05 16:22:32.333432, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1251(uid_to_sid)
>  uid 0 -> sid S-1-22-1-0
>[2017/06/05 16:22:32.333483, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1300(gid_to_sid)
>  gid 0 -> sid S-1-22-2-0
>[2017/06/05 16:22:32.333522, 10, pid=2877, 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/05 16:22:32.333549, 10, pid=2877, 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/05 16:22:32.333586, 10, pid=2877, 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-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.333680, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.333819, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) 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/05 16:22:32.334178, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.334225, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.334255, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.334314, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:181(smbd_check_access_rights)
>  smbd_check_access_rights: file . requesting 0x100081 returning 0x100001 (NT_STATUS_OK)
>[2017/06/05 16:22:32.334365,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:65(fsp_new)
>  fsp_new: fsp=0x7f38ed3a4570
>[2017/06/05 16:22:32.334551,  5, pid=2877, 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/05 16:22:32.334590, 10, pid=2877, 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/05 16:22:32.334626, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key A4052486
>[2017/06/05 16:22:32.334663, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3bb7d0
>[2017/06/05 16:22:32.334712, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:624(smbXsrv_open_global_verify_record)
>  smbXsrv_open_global_verify_record: empty value
>[2017/06/05 16:22:32.334845, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:743(smbXsrv_open_global_store)
>  smbXsrv_open_global_store: key 'A4052486' stored
>[2017/06/05 16:22:32.334897,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  open_global_id           : 0xa4052486 (2751800454)
>                  open_persistent_id       : 0x00000000a4052486 (2751800454)
>                  open_volatile_id         : 0x00000000c7c26114 (3351404820)
>                  open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                  open_time                : Mon Jun  5 16:22:32 2017 IDT
>                  create_guid              : 00000000-0000-0000-0000-000000000000
>                  client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                  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         : 0x0000000000000000 (0)
>[2017/06/05 16:22:32.335423, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key A4052486
>[2017/06/05 16:22:32.335473,  5, pid=2877, 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/05 16:22:32.335514, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.335555, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:910(smbXsrv_open_create)
>  smbXsrv_open_create: global_id (0xa4052486) stored
>[2017/06/05 16:22:32.335583,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                 : 0xc7c26114 (3351404820)
>                  global                   : *
>                      global: struct smbXsrv_open_global0
>                          db_rec                   : NULL
>                          server_id: struct server_id
>                              pid                      : 0x0000000000000b3d (2877)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                          open_global_id           : 0xa4052486 (2751800454)
>                          open_persistent_id       : 0x00000000a4052486 (2751800454)
>                          open_volatile_id         : 0x00000000c7c26114 (3351404820)
>                          open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                          open_time                : Mon Jun  5 16:22:32 2017 IDT
>                          create_guid              : 00000000-0000-0000-0000-000000000000
>                          client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                          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         : 0x0000000000000000 (0)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Mon Jun  5 16:22:32 2017 IDT
>                  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)
>[2017/06/05 16:22:32.336357,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:130(file_new)
>  allocated file structure fnum 3351404820 (1 used)
>[2017/06/05 16:22:32.336411, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:763(file_name_hash)
>  file_name_hash: /export/vol1/. hash 0xd7088907
>[2017/06/05 16:22:32.336476, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1199(check_reduced_name)
>  check_reduced_name: check_reduced_name [.] [/export/vol1]
>[2017/06/05 16:22:32.336516, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1259(check_reduced_name)
>  check_reduced_name realpath [.] -> [/export/vol1]
>[2017/06/05 16:22:32.336547,  5, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1370(check_reduced_name)
>  check_reduced_name: . reduced to /export/vol1
>[2017/06/05 16:22:32.336602, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:689(fd_open)
>  fd_open: name ., flags = 0200000 mode = 00, fd = 35. 
>[2017/06/05 16:22:32.336650,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
>  check lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:32.336694, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:<none>
>[2017/06/05 16:22:32.336795, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 1CFD0000000000008000
>[2017/06/05 16:22:32.336882, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3ae900
>[2017/06/05 16:22:32.336934, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:366(unparse_share_modes)
>  unparse_share_modes:
>[2017/06/05 16:22:32.337025,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(ndr_print_debug)
>       d: struct share_mode_data
>          sequence_number          : 0xbb5d755ab6502ab2 (-4945667783316723022)
>          servicepath              : *
>              servicepath              : '/export/vol1'
>          base_name                : *
>              base_name                : '.'
>          stream_name              : NULL
>          num_share_modes          : 0x00000001 (1)
>          share_modes: ARRAY(1)
>              share_modes: struct share_mode_entry
>                  pid: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  op_mid                   : 0x0000000000000005 (5)
>                  op_type                  : 0x0000 (0)
>                  lease_idx                : 0xffffffff (4294967295)
>                  access_mask              : 0x00100081 (1048705)
>                  share_access             : 0x00000007 (7)
>                  private_options          : 0x00000000 (0)
>                  time                     : Mon Jun  5 16:22:32 2017 IDT.334539
>                  id: struct file_id
>                      devid                    : 0x000000000000fd1c (64796)
>                      inode                    : 0x0000000000000080 (128)
>                      extid                    : 0x0000000000000000 (0)
>                  share_file_id            : 0x00000000397e3497 (964572311)
>                  uid                      : 0x0000fffe (65534)
>                  flags                    : 0x0000 (0)
>                  name_hash                : 0xd7088907 (3607660807)
>                  stale                    : 0x00 (0)
>                  lease                    : NULL
>          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                    : 0x01 (1)
>          modified                 : 0x01 (1)
>          record                   : *
>          id: struct file_id
>              devid                    : 0x000000000000fd1c (64796)
>              inode                    : 0x0000000000000080 (128)
>              extid                    : 0x0000000000000000 (0)
>[2017/06/05 16:22:32.337835, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:155(share_mode_memcache_delete)
>  deleting entry for file . seq 0x13501076290392828594 key fd1c:80:0
>[2017/06/05 16:22:32.337936,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:32.338000, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.338041, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 1CFD0000000000008000
>[2017/06/05 16:22:32.338090, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:169(share_mode_memcache_store)
>  stored entry for file . seq 0x13501076290392828595 key fd1c:80:0
>[2017/06/05 16:22:32.338165, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5322(create_file_unixpath)
>  create_file_unixpath: info=1
>[2017/06/05 16:22:32.338209, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5603(create_file_default)
>  create_file: info=1
>[2017/06/05 16:22:32.338237, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1188(smbd_smb2_create_send)
>  smbd_smb2_create_send: response construction phase
>[2017/06/05 16:22:32.338276, 10, pid=2877, 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 .
>[2017/06/05 16:22:32.338359, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1251(uid_to_sid)
>  uid 0 -> sid S-1-22-1-0
>[2017/06/05 16:22:32.338436, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1300(gid_to_sid)
>  gid 0 -> sid S-1-22-2-0
>[2017/06/05 16:22:32.338481, 10, pid=2877, 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/05 16:22:32.338508, 10, pid=2877, 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/05 16:22:32.338559, 10, pid=2877, 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-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.338708, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.338870, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) 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/05 16:22:32.339130, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.339174, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.339214, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.339272, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../libcli/security/access_check.c:188(se_access_check)
>  se_access_check: MAX desired = 0x2000000, granted = 0x1f01ff, remaining = 0x1f01ff
>[2017/06/05 16:22:32.339327,  5, pid=2877, 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/05 16:22:32.339368, 10, pid=2877, 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/05 16:22:32.339413, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key A4052486
>[2017/06/05 16:22:32.339454, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3ba930
>[2017/06/05 16:22:32.339520, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:743(smbXsrv_open_global_store)
>  smbXsrv_open_global_store: key 'A4052486' stored
>[2017/06/05 16:22:32.339569,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(ndr_print_debug)
>       &global_blob: struct smbXsrv_open_globalB
>          version                  : SMBXSRV_VERSION_0 (0)
>          seqnum                   : 0x00000002 (2)
>          info                     : union smbXsrv_open_globalU(case 0)
>          info0                    : *
>              info0: struct smbXsrv_open_global0
>                  db_rec                   : *
>                  server_id: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  open_global_id           : 0xa4052486 (2751800454)
>                  open_persistent_id       : 0x00000000a4052486 (2751800454)
>                  open_volatile_id         : 0x00000000c7c26114 (3351404820)
>                  open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                  open_time                : Mon Jun  5 16:22:32 2017 IDT
>                  create_guid              : eb46097a-4694-11e7-9429-005056ae0ecf
>                  client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                  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         : 0x0000000000000000 (0)
>[2017/06/05 16:22:32.340145, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key A4052486
>[2017/06/05 16:22:32.340197,  5, pid=2877, 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/05 16:22:32.340240, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.340292, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:1055(smbXsrv_open_update)
>  smbXsrv_open_update: global_id (0xa4052486) stored
>[2017/06/05 16:22:32.340333,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                 : 0xc7c26114 (3351404820)
>                  global                   : *
>                      global: struct smbXsrv_open_global0
>                          db_rec                   : NULL
>                          server_id: struct server_id
>                              pid                      : 0x0000000000000b3d (2877)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                          open_global_id           : 0xa4052486 (2751800454)
>                          open_persistent_id       : 0x00000000a4052486 (2751800454)
>                          open_volatile_id         : 0x00000000c7c26114 (3351404820)
>                          open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                          open_time                : Mon Jun  5 16:22:32 2017 IDT
>                          create_guid              : eb46097a-4694-11e7-9429-005056ae0ecf
>                          client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                          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         : 0x0000000000000000 (0)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Mon Jun  5 16:22:32 2017 IDT
>                  compat                   : *
>                  flags                    : 0x02 (2)
>                         0: SMBXSRV_OPEN_NEED_REPLAY_CACHE
>                         1: SMBXSRV_OPEN_HAVE_REPLAY_CACHE
>                  create_action            : 0x00000000 (0)
>                  request_count            : 0x0000000000000000 (0)
>                  pre_request_count        : 0x0000000000000000 (0)
>[2017/06/05 16:22:32.341149, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1248(smbd_smb2_create_send)
>  smb2_create_send: smbXsrv_open_update returned NT_STATUS_OK
>[2017/06/05 16:22:32.341209,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1352(smbd_smb2_create_send)
>  smbd_smb2_create_send: smb2req->compat_chain_fsp=0x7f38ed3a4570
>[2017/06/05 16:22:32.341377,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:611(dos_mode)
>  dos_mode: .
>[2017/06/05 16:22:32.341419,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode_from_sbuf returning (0x10): "d"
>[2017/06/05 16:22:32.341463,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1009(is_in_path)
>  is_in_path: .
>[2017/06/05 16:22:32.341492,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1033(is_in_path)
>  is_in_path: match not found
>[2017/06/05 16:22:32.341518,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode returning (0x10): "d"
>[2017/06/05 16:22:32.341549, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1397(smbd_smb2_create_send)
>  smbd_smb2_create_send: . - fnum 3351404820
>[2017/06/05 16:22:32.341599, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3014(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:364
>[2017/06/05 16:22:32.341640, 10, pid=2877, 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/6/31
>[2017/06/05 16:22:32.342375, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3912(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 9 vectors
>[2017/06/05 16:22:32.342550, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 6 (position 6) from bitmap
>[2017/06/05 16:22:32.342586, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 7 (position 7) from bitmap
>[2017/06/05 16:22:32.342630, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_QUERY_DIRECTORY] mid = 6
>[2017/06/05 16:22:32.342668,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2017/06/05 16:22:32.342751,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:697(file_fsp_smb2)
>  file_fsp_smb2: smb2req->compat_chain_fsp=(nil)
>[2017/06/05 16:22:32.342963,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=0x7f38ed3a4570
>[2017/06/05 16:22:32.343160, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_query_directory.c:94(smbd_smb2_request_process_query_directory)
>  smbd_smb2_request_find_done: in_output_buffer_length = 65536
>[2017/06/05 16:22:32.343216, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_query_directory.c:242(smbd_smb2_query_directory_send)
>  smbd_smb2_query_directory_send: . - fnum 3351404820
>[2017/06/05 16:22:32.343252, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1955(smbd_smb2_request_verify_creditcharge)
>  mid 6, CreditCharge: 1, NeededCharge: 1
>[2017/06/05 16:22:32.343282,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:474(dptr_create)
>  dptr_create dir=.
>[2017/06/05 16:22:32.343330,  3, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:656(dptr_create)
>  creating new dirptr 0 for path ., expect_close = 0
>[2017/06/05 16:22:32.343380,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_query_directory.c:447(smbd_smb2_query_directory_send)
>  smbd_smb2_query_directory_send: dirpath=<.> dontdescend=<>, in_output_buffer_length = 65528
>[2017/06/05 16:22:32.343432,  6, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:1136(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry: dirptr 0x7f38ed3b2790 now at offset 0
>[2017/06/05 16:22:32.343486,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:611(dos_mode)
>  dos_mode: .
>[2017/06/05 16:22:32.343522,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode_from_sbuf returning (0x10): "d"
>[2017/06/05 16:22:32.343591,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1009(is_in_path)
>  is_in_path: .
>[2017/06/05 16:22:32.343635,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1033(is_in_path)
>  is_in_path: match not found
>[2017/06/05 16:22:32.343662,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode returning (0x10): "d"
>[2017/06/05 16:22:32.343711, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:283(share_mode_memcache_fetch)
>  fetched entry for file . seq 0x13501076290392828595 key fd1c:80:0
>[2017/06/05 16:22:32.343824,  3, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:1227(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry mask=[*] found . fname=. (.)
>[2017/06/05 16:22:32.343868, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:1821(smbd_marshall_dir_entry)
>  smbd_marshall_dir_entry: space_remaining = 65528
>[2017/06/05 16:22:32.343898, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:2226(smbd_marshall_dir_entry)
>  smbd_marshall_dir_entry: SMB_FIND_ID_BOTH_DIRECTORY_INFO
>[2017/06/05 16:22:32.343937,  6, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:1136(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry: dirptr 0x7f38ed3b2790 now at offset 2147483648
>[2017/06/05 16:22:32.344025,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:611(dos_mode)
>  dos_mode: ..
>[2017/06/05 16:22:32.344067,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode_from_sbuf returning (0x10): "d"
>[2017/06/05 16:22:32.344097,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1009(is_in_path)
>  is_in_path: ..
>[2017/06/05 16:22:32.344126,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1033(is_in_path)
>  is_in_path: match not found
>[2017/06/05 16:22:32.344163,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode returning (0x10): "d"
>[2017/06/05 16:22:32.344208,  3, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:1227(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry mask=[*] found .. fname=.. (..)
>[2017/06/05 16:22:32.344303, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:1821(smbd_marshall_dir_entry)
>  smbd_marshall_dir_entry: space_remaining = 65416
>[2017/06/05 16:22:32.344338, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:2226(smbd_marshall_dir_entry)
>  smbd_marshall_dir_entry: SMB_FIND_ID_BOTH_DIRECTORY_INFO
>[2017/06/05 16:22:32.344410,  6, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:1136(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry: dirptr 0x7f38ed3b2790 now at offset 512
>[2017/06/05 16:22:32.344457,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:611(dos_mode)
>  dos_mode: New Text Document.txt
>[2017/06/05 16:22:32.344492,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode_from_sbuf returning (0x20): "a"
>[2017/06/05 16:22:32.344525,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1009(is_in_path)
>  is_in_path: New Text Document.txt
>[2017/06/05 16:22:32.344556,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1033(is_in_path)
>  is_in_path: match not found
>[2017/06/05 16:22:32.344584,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode returning (0x20): "a"
>[2017/06/05 16:22:32.344630,  3, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:1227(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry mask=[*] found New Text Document.txt fname=New Text Document.txt (New Text Document.txt)
>[2017/06/05 16:22:32.344675, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:1821(smbd_marshall_dir_entry)
>  smbd_marshall_dir_entry: space_remaining = 65304
>[2017/06/05 16:22:32.344706, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:2226(smbd_marshall_dir_entry)
>  smbd_marshall_dir_entry: SMB_FIND_ID_BOTH_DIRECTORY_INFO
>[2017/06/05 16:22:32.344802, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/mangle_hash2.c:791(hash2_name_to_8_3)
>  hash2_name_to_8_3: New Text Document.txt -> 124541D5 -> N52HZ2~T.TXT (cache=1)
>[2017/06/05 16:22:32.344863,  6, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:1136(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry: dirptr 0x7f38ed3b2790 now at offset -1
>[2017/06/05 16:22:32.344916, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_query_directory.c:184(smbd_smb2_request_find_done)
>  smbd_smb2_request_find_done: out_output_buffer.length = 370
>[2017/06/05 16:22:32.344957, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3014(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[8] dyn[yes:370] at ../source3/smbd/smb2_query_directory.c:188
>[2017/06/05 16:22:32.345029,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2717(smbd_smb2_request_reply_update_counts)
>  smbd_smb2_request_reply_update_counts: compat_chain_fsp=0x7f38ed3a4570
>[2017/06/05 16:22:32.345201, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2982(smbd_smb2_request_dispatch_immediate)
>  smbd_smb2_request_dispatch_immediate: idx[5] of 9 vectors
>  	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 = 32
>  	req->in.vector[4].iov_len = 8
>  	req->in.vector[5].iov_len = 0
>  	req->in.vector[6].iov_len = 64
>  	req->in.vector[7].iov_len = 32
>  	req->in.vector[8].iov_len = 2
>  	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 = 376
>  	req->out.vector[5].iov_len = 0
>  	req->out.vector[6].iov_len = 64
>  	req->out.vector[7].iov_len = 8
>  	req->out.vector[8].iov_len = 0
>[2017/06/05 16:22:32.345390, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_QUERY_DIRECTORY] mid = 7
>[2017/06/05 16:22:32.345442,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2017/06/05 16:22:32.345478,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=0x7f38ed3a4570
>[2017/06/05 16:22:32.345570, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_query_directory.c:94(smbd_smb2_request_process_query_directory)
>  smbd_smb2_request_find_done: in_output_buffer_length = 128
>[2017/06/05 16:22:32.345610, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_query_directory.c:242(smbd_smb2_query_directory_send)
>  smbd_smb2_query_directory_send: . - fnum 3351404820
>[2017/06/05 16:22:32.345681, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1955(smbd_smb2_request_verify_creditcharge)
>  mid 7, CreditCharge: 1, NeededCharge: 1
>[2017/06/05 16:22:32.345717,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_query_directory.c:447(smbd_smb2_query_directory_send)
>  smbd_smb2_query_directory_send: dirpath=<.> dontdescend=<>, in_output_buffer_length = 120
>[2017/06/05 16:22:32.345782,  6, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:1136(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry: dirptr 0x7f38ed3b2790 now at offset -1
>[2017/06/05 16:22:32.345820,  3, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3132(smbd_smb2_request_error_ex)
>  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[STATUS_NO_MORE_FILES] || at ../source3/smbd/smb2_query_directory.c:155
>[2017/06/05 16:22:32.345855, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3014(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[5] status[STATUS_NO_MORE_FILES] body[8] dyn[yes:1] at ../source3/smbd/smb2_server.c:3189
>[2017/06/05 16:22:32.345888,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2717(smbd_smb2_request_reply_update_counts)
>  smbd_smb2_request_reply_update_counts: compat_chain_fsp=0x7f38ed3a4570
>[2017/06/05 16:22:32.345966, 10, pid=2877, 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 483/512, total granted/max/low/range 30/8192/8/30
>[2017/06/05 16:22:32.346054, 10, pid=2877, 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/8/31
>[2017/06/05 16:22:32.346679, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3912(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 9 vectors
>[2017/06/05 16:22:32.346831, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 8 (position 8) from bitmap
>[2017/06/05 16:22:32.346886, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 9 (position 9) from bitmap
>[2017/06/05 16:22:32.347021, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 8
>[2017/06/05 16:22:32.347081,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2017/06/05 16:22:32.347211,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=(nil)
>[2017/06/05 16:22:32.347321, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:503(smbd_smb2_create_send)
>  smbd_smb2_create: name[]
>[2017/06/05 16:22:32.347360, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:997(smbd_smb2_create_send)
>  smbd_smb2_create_send: open execution phase
>[2017/06/05 16:22:32.347393,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:443(unix_convert)
>  unix_convert called on file ""
>[2017/06/05 16:22:32.347444,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:477(unix_convert)
>  conversion finished "" -> .
>[2017/06/05 16:22:32.347471, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1199(check_reduced_name)
>  check_reduced_name: check_reduced_name [.] [/export/vol1]
>[2017/06/05 16:22:32.347502, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1259(check_reduced_name)
>  check_reduced_name realpath [.] -> [/export/vol1]
>[2017/06/05 16:22:32.347532,  5, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1370(check_reduced_name)
>  check_reduced_name: . reduced to /export/vol1
>[2017/06/05 16:22:32.347622, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5515(create_file_default)
>  create_file: access_mask = 0x100081 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x1 oplock_request = 0x0 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = .
>[2017/06/05 16:22:32.347665, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4988(create_file_unixpath)
>  create_file_unixpath: access_mask = 0x100081 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x1 oplock_request = 0x0 private_flags = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = .
>[2017/06/05 16:22:32.347701,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:3917(open_directory)
>  open_directory: opening directory ., access_mask = 0x100081, share_access = 0x7 create_options = 0x1, create_disposition = 0x1, file_attributes = 0x10
>[2017/06/05 16:22:32.347847, 10, pid=2877, 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 .
>[2017/06/05 16:22:32.347994, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1251(uid_to_sid)
>  uid 0 -> sid S-1-22-1-0
>[2017/06/05 16:22:32.348162, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1300(gid_to_sid)
>  gid 0 -> sid S-1-22-2-0
>[2017/06/05 16:22:32.348219, 10, pid=2877, 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/05 16:22:32.348258, 10, pid=2877, 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/05 16:22:32.348315, 10, pid=2877, 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-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.348432, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.348578, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) 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/05 16:22:32.348928, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.348997, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.349044, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.349102, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:181(smbd_check_access_rights)
>  smbd_check_access_rights: file . requesting 0x100081 returning 0x100001 (NT_STATUS_OK)
>[2017/06/05 16:22:32.349155,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:65(fsp_new)
>  fsp_new: fsp=0x7f38ed3ba6f0
>[2017/06/05 16:22:32.349245,  5, pid=2877, 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/05 16:22:32.349281, 10, pid=2877, 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/05 16:22:32.349318, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key C311E6B8
>[2017/06/05 16:22:32.349355, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3b2a70
>[2017/06/05 16:22:32.349383, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:624(smbXsrv_open_global_verify_record)
>  smbXsrv_open_global_verify_record: empty value
>[2017/06/05 16:22:32.349453, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:743(smbXsrv_open_global_store)
>  smbXsrv_open_global_store: key 'C311E6B8' stored
>[2017/06/05 16:22:32.349552,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  open_global_id           : 0xc311e6b8 (3272730296)
>                  open_persistent_id       : 0x00000000c311e6b8 (3272730296)
>                  open_volatile_id         : 0x0000000006ab4715 (111888149)
>                  open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                  open_time                : Mon Jun  5 16:22:32 2017 IDT
>                  create_guid              : 00000000-0000-0000-0000-000000000000
>                  client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                  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         : 0x0000000000000000 (0)
>[2017/06/05 16:22:32.350354, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key C311E6B8
>[2017/06/05 16:22:32.350406,  5, pid=2877, 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/05 16:22:32.350440, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.350534, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:910(smbXsrv_open_create)
>  smbXsrv_open_create: global_id (0xc311e6b8) stored
>[2017/06/05 16:22:32.350574,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                 : 0x06ab4715 (111888149)
>                  global                   : *
>                      global: struct smbXsrv_open_global0
>                          db_rec                   : NULL
>                          server_id: struct server_id
>                              pid                      : 0x0000000000000b3d (2877)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                          open_global_id           : 0xc311e6b8 (3272730296)
>                          open_persistent_id       : 0x00000000c311e6b8 (3272730296)
>                          open_volatile_id         : 0x0000000006ab4715 (111888149)
>                          open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                          open_time                : Mon Jun  5 16:22:32 2017 IDT
>                          create_guid              : 00000000-0000-0000-0000-000000000000
>                          client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                          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         : 0x0000000000000000 (0)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Mon Jun  5 16:22:32 2017 IDT
>                  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)
>[2017/06/05 16:22:32.351464,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:130(file_new)
>  allocated file structure fnum 111888149 (2 used)
>[2017/06/05 16:22:32.351517, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:763(file_name_hash)
>  file_name_hash: /export/vol1/. hash 0xd7088907
>[2017/06/05 16:22:32.351581, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1199(check_reduced_name)
>  check_reduced_name: check_reduced_name [.] [/export/vol1]
>[2017/06/05 16:22:32.351646, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1259(check_reduced_name)
>  check_reduced_name realpath [.] -> [/export/vol1]
>[2017/06/05 16:22:32.351689,  5, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1370(check_reduced_name)
>  check_reduced_name: . reduced to /export/vol1
>[2017/06/05 16:22:32.351759, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:689(fd_open)
>  fd_open: name ., flags = 0200000 mode = 00, fd = 39. 
>[2017/06/05 16:22:32.351800,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
>  check lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:32.351891, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:<none>
>[2017/06/05 16:22:32.351943, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 1CFD0000000000008000
>[2017/06/05 16:22:32.352014, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3b9430
>[2017/06/05 16:22:32.352061, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:233(share_mode_memcache_fetch)
>  failed to find entry for key fd1c:80:0
>[2017/06/05 16:22:32.352379, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:346(parse_share_modes)
>  parse_share_modes:
>[2017/06/05 16:22:32.352574,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(ndr_print_debug)
>       d: struct share_mode_data
>          sequence_number          : 0xbb5d755ab6502ab3 (-4945667783316723021)
>          servicepath              : *
>              servicepath              : '/export/vol1'
>          base_name                : *
>              base_name                : '.'
>          stream_name              : NULL
>          num_share_modes          : 0x00000001 (1)
>          share_modes: ARRAY(1)
>              share_modes: struct share_mode_entry
>                  pid: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  op_mid                   : 0x0000000000000005 (5)
>                  op_type                  : 0x0000 (0)
>                  lease_idx                : 0xffffffff (4294967295)
>                  access_mask              : 0x00100081 (1048705)
>                  share_access             : 0x00000007 (7)
>                  private_options          : 0x00000000 (0)
>                  time                     : Mon Jun  5 16:22:32 2017 IDT.334539
>                  id: struct file_id
>                      devid                    : 0x000000000000fd1c (64796)
>                      inode                    : 0x0000000000000080 (128)
>                      extid                    : 0x0000000000000000 (0)
>                  share_file_id            : 0x00000000397e3497 (964572311)
>                  uid                      : 0x0000fffe (65534)
>                  flags                    : 0x0000 (0)
>                  name_hash                : 0xd7088907 (3607660807)
>                  stale                    : 0x00 (0)
>                  lease                    : NULL
>          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                 : 0x00 (0)
>          record                   : NULL
>          id: struct file_id
>              devid                    : 0x000000000000fd1c (64796)
>              inode                    : 0x0000000000000080 (128)
>              extid                    : 0x0000000000000000 (0)
>[2017/06/05 16:22:32.353410, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:1229(find_delete_on_close_token)
>  find_delete_on_close_token: name_hash = 0xd7088907
>[2017/06/05 16:22:32.353452, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1342(share_conflict)
>  share_conflict: entry->access_mask = 0x100081, entry->share_access = 0x7, entry->private_options = 0x0
>[2017/06/05 16:22:32.353490, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1353(share_conflict)
>  share_conflict: access_mask = 0x100081, share_access = 0x7
>[2017/06/05 16:22:32.353517, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1402(share_conflict)
>  share_conflict: [1] am (0x100081) & right (0x6) = 0x0
>[2017/06/05 16:22:32.353550, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1402(share_conflict)
>  share_conflict: [1] sa (0x7) & share (0x2) = 0x2
>[2017/06/05 16:22:32.353577, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1404(share_conflict)
>  share_conflict: [2] am (0x100081) & right (0x6) = 0x0
>[2017/06/05 16:22:32.353611, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1404(share_conflict)
>  share_conflict: [2] sa (0x7) & share (0x2) = 0x2
>[2017/06/05 16:22:32.353637, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1407(share_conflict)
>  share_conflict: [3] am (0x100081) & right (0x21) = 0x1
>[2017/06/05 16:22:32.353670, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1407(share_conflict)
>  share_conflict: [3] sa (0x7) & share (0x1) = 0x1
>[2017/06/05 16:22:32.353704, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1409(share_conflict)
>  share_conflict: [4] am (0x100081) & right (0x21) = 0x1
>[2017/06/05 16:22:32.353808, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1409(share_conflict)
>  share_conflict: [4] sa (0x7) & share (0x1) = 0x1
>[2017/06/05 16:22:32.353842, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1412(share_conflict)
>  share_conflict: [5] am (0x100081) & right (0x10000) = 0x0
>[2017/06/05 16:22:32.353878, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1412(share_conflict)
>  share_conflict: [5] sa (0x7) & share (0x4) = 0x4
>[2017/06/05 16:22:32.353912, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1414(share_conflict)
>  share_conflict: [6] am (0x100081) & right (0x10000) = 0x0
>[2017/06/05 16:22:32.353937, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1414(share_conflict)
>  share_conflict: [6] sa (0x7) & share (0x4) = 0x4
>[2017/06/05 16:22:32.353962, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1416(share_conflict)
>  share_conflict: No conflict.
>[2017/06/05 16:22:32.354039, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:366(unparse_share_modes)
>  unparse_share_modes:
>[2017/06/05 16:22:32.354069,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(ndr_print_debug)
>       d: struct share_mode_data
>          sequence_number          : 0xbb5d755ab6502ab3 (-4945667783316723021)
>          servicepath              : *
>              servicepath              : '/export/vol1'
>          base_name                : *
>              base_name                : '.'
>          stream_name              : NULL
>          num_share_modes          : 0x00000002 (2)
>          share_modes: ARRAY(2)
>              share_modes: struct share_mode_entry
>                  pid: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  op_mid                   : 0x0000000000000005 (5)
>                  op_type                  : 0x0000 (0)
>                  lease_idx                : 0xffffffff (4294967295)
>                  access_mask              : 0x00100081 (1048705)
>                  share_access             : 0x00000007 (7)
>                  private_options          : 0x00000000 (0)
>                  time                     : Mon Jun  5 16:22:32 2017 IDT.334539
>                  id: struct file_id
>                      devid                    : 0x000000000000fd1c (64796)
>                      inode                    : 0x0000000000000080 (128)
>                      extid                    : 0x0000000000000000 (0)
>                  share_file_id            : 0x00000000397e3497 (964572311)
>                  uid                      : 0x0000fffe (65534)
>                  flags                    : 0x0000 (0)
>                  name_hash                : 0xd7088907 (3607660807)
>                  stale                    : 0x00 (0)
>                  lease                    : NULL
>              share_modes: struct share_mode_entry
>                  pid: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  op_mid                   : 0x0000000000000008 (8)
>                  op_type                  : 0x0000 (0)
>                  lease_idx                : 0xffffffff (4294967295)
>                  access_mask              : 0x00100081 (1048705)
>                  share_access             : 0x00000007 (7)
>                  private_options          : 0x00000000 (0)
>                  time                     : Mon Jun  5 16:22:32 2017 IDT.349235
>                  id: struct file_id
>                      devid                    : 0x000000000000fd1c (64796)
>                      inode                    : 0x0000000000000080 (128)
>                      extid                    : 0x0000000000000000 (0)
>                  share_file_id            : 0x000000005b30c763 (1529923427)
>                  uid                      : 0x0000fffe (65534)
>                  flags                    : 0x0000 (0)
>                  name_hash                : 0xd7088907 (3607660807)
>                  stale                    : 0x00 (0)
>                  lease                    : NULL
>          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/05 16:22:32.355196, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:155(share_mode_memcache_delete)
>  deleting entry for file . seq 0x13501076290392828595 key fd1c:80:0
>[2017/06/05 16:22:32.355390,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:32.355438, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.355558, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 1CFD0000000000008000
>[2017/06/05 16:22:32.355608, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:169(share_mode_memcache_store)
>  stored entry for file . seq 0x13501076290392828596 key fd1c:80:0
>[2017/06/05 16:22:32.355695, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5322(create_file_unixpath)
>  create_file_unixpath: info=1
>[2017/06/05 16:22:32.355804, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5603(create_file_default)
>  create_file: info=1
>[2017/06/05 16:22:32.355840, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1188(smbd_smb2_create_send)
>  smbd_smb2_create_send: response construction phase
>[2017/06/05 16:22:32.355878, 10, pid=2877, 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 .
>[2017/06/05 16:22:32.355953, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1251(uid_to_sid)
>  uid 0 -> sid S-1-22-1-0
>[2017/06/05 16:22:32.356034, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1300(gid_to_sid)
>  gid 0 -> sid S-1-22-2-0
>[2017/06/05 16:22:32.356127, 10, pid=2877, 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/05 16:22:32.356167, 10, pid=2877, 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/05 16:22:32.356271, 10, pid=2877, 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-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.356423, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.356569, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) 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/05 16:22:32.356902, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.357003, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.357104, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.357200, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../libcli/security/access_check.c:188(se_access_check)
>  se_access_check: MAX desired = 0x2000000, granted = 0x1f01ff, remaining = 0x1f01ff
>[2017/06/05 16:22:32.357253,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1352(smbd_smb2_create_send)
>  smbd_smb2_create_send: smb2req->compat_chain_fsp=0x7f38ed3ba6f0
>[2017/06/05 16:22:32.357520,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:611(dos_mode)
>  dos_mode: .
>[2017/06/05 16:22:32.357570,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode_from_sbuf returning (0x10): "d"
>[2017/06/05 16:22:32.357600,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1009(is_in_path)
>  is_in_path: .
>[2017/06/05 16:22:32.357625,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1033(is_in_path)
>  is_in_path: match not found
>[2017/06/05 16:22:32.357651,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode returning (0x10): "d"
>[2017/06/05 16:22:32.357834, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1397(smbd_smb2_create_send)
>  smbd_smb2_create_send: . - fnum 111888149
>[2017/06/05 16:22:32.357901, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3014(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[88] dyn[yes:32] at ../source3/smbd/smb2_create.c:364
>[2017/06/05 16:22:32.358024, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2982(smbd_smb2_request_dispatch_immediate)
>  smbd_smb2_request_dispatch_immediate: idx[5] of 9 vectors
>  	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 = 32
>  	req->in.vector[5].iov_len = 0
>  	req->in.vector[6].iov_len = 64
>  	req->in.vector[7].iov_len = 32
>  	req->in.vector[8].iov_len = 0
>  	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 = 88
>  	req->out.vector[4].iov_len = 32
>  	req->out.vector[5].iov_len = 0
>  	req->out.vector[6].iov_len = 64
>  	req->out.vector[7].iov_len = 8
>  	req->out.vector[8].iov_len = 0
>[2017/06/05 16:22:32.358315, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_NOTIFY] mid = 9
>[2017/06/05 16:22:32.358362,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2017/06/05 16:22:32.358390,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=0x7f38ed3ba6f0
>[2017/06/05 16:22:32.358540, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1955(smbd_smb2_request_verify_creditcharge)
>  mid 9, CreditCharge: 1, NeededCharge: 1
>[2017/06/05 16:22:32.358577, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_notify.c:232(smbd_smb2_notify_send)
>  smbd_smb2_notify_send: . - fnum 111888149
>[2017/06/05 16:22:32.358616,  3, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_notify.c:252(smbd_smb2_notify_send)
>  smbd_smb2_notify_send: notify change called on ., filter = FILE_NAME|DIR_NAME|ATTRIBUTES|LAST_WRITE, recursive = 0
>[2017/06/05 16:22:32.358711, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/notify_msg.c:154(notify_add)
>  notify_add: path=[/export/vol1], filter=23, subdir_filter=0, private_data=0x7f38ed3ba6f0
>[2017/06/05 16:22:32.358813,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
>  push_sec_ctx(65534, 65534) : sec_ctx_stack_ndx = 1
>[2017/06/05 16:22:32.358929,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(1512126538) : conn_ctx_stack_ndx = 0
>[2017/06/05 16:22:32.358956,  4, pid=2877, 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 = 1
>[2017/06/05 16:22:32.359027,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2017/06/05 16:22:32.359145,  5, pid=2877, 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/05 16:22:32.359202, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/messages_dgm.c:323(messaging_dgm_send)
>  messaging_dgm_send: Sending message to 2602
>[2017/06/05 16:22:32.359338,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx)
>  pop_sec_ctx (65534, 65534) - sec_ctx_stack_ndx = 0
>[2017/06/05 16:22:32.359384, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/notify.c:331(change_notify_add_request)
>  change_notify_add_request: Adding request for .: max_param = 32
>  smbd_smb2_request_pending_queue: req->current_idx = 5
>  	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 = 32
>  	req->in.vector[5].iov_len = 0
>  	req->in.vector[6].iov_len = 64
>  	req->in.vector[7].iov_len = 32
>  	req->in.vector[8].iov_len = 0
>  	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 = 88
>  	req->out.vector[4].iov_len = 32
>  	req->out.vector[5].iov_len = 0
>  	req->out.vector[6].iov_len = 64
>  	req->out.vector[7].iov_len = 8
>  	req->out.vector[8].iov_len = 0
>[2017/06/05 16:22:32.359614, 10, pid=2877, 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 483/512, total granted/max/low/range 30/8192/10/30
>  smb2_send_async_interim_response: nreq->current_idx = 1
>  smb2_send_async_interim_response: returning 5 vectors
>  	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 = 88
>  	req->out.vector[4].iov_len = 32
>[2017/06/05 16:22:32.359839, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3912(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2017/06/05 16:22:32.359889, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 10 (position 10) from bitmap
>[2017/06/05 16:22:32.359920, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_CLOSE] mid = 10
>[2017/06/05 16:22:32.359951,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2017/06/05 16:22:32.360008,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:697(file_fsp_smb2)
>  file_fsp_smb2: smb2req->compat_chain_fsp=(nil)
>[2017/06/05 16:22:32.360148,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=0x7f38ed3a4570
>[2017/06/05 16:22:32.360304, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_close.c:227(smbd_smb2_close)
>  smbd_smb2_close: . - fnum 3351404820
>[2017/06/05 16:22:32.360347,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
>  check lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:32.360375, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:<none>
>[2017/06/05 16:22:32.360459, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 1CFD0000000000008000
>[2017/06/05 16:22:32.360496, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3b7960
>[2017/06/05 16:22:32.360598, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:283(share_mode_memcache_fetch)
>  fetched entry for file . seq 0x13501076290392828596 key fd1c:80:0
>[2017/06/05 16:22:32.360648, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:1229(find_delete_on_close_token)
>  find_delete_on_close_token: name_hash = 0xd7088907
>[2017/06/05 16:22:32.360679, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:366(unparse_share_modes)
>  unparse_share_modes:
>[2017/06/05 16:22:32.360707,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(ndr_print_debug)
>       d: struct share_mode_data
>          sequence_number          : 0xbb5d755ab6502ab4 (-4945667783316723020)
>          servicepath              : *
>              servicepath              : '/export/vol1'
>          base_name                : *
>              base_name                : '.'
>          stream_name              : NULL
>          num_share_modes          : 0x00000001 (1)
>          share_modes: ARRAY(1)
>              share_modes: struct share_mode_entry
>                  pid: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  op_mid                   : 0x0000000000000008 (8)
>                  op_type                  : 0x0000 (0)
>                  lease_idx                : 0xffffffff (4294967295)
>                  access_mask              : 0x00100081 (1048705)
>                  share_access             : 0x00000007 (7)
>                  private_options          : 0x00000000 (0)
>                  time                     : Mon Jun  5 16:22:32 2017 IDT.349235
>                  id: struct file_id
>                      devid                    : 0x000000000000fd1c (64796)
>                      inode                    : 0x0000000000000080 (128)
>                      extid                    : 0x0000000000000000 (0)
>                  share_file_id            : 0x000000005b30c763 (1529923427)
>                  uid                      : 0x0000fffe (65534)
>                  flags                    : 0x0000 (0)
>                  name_hash                : 0xd7088907 (3607660807)
>                  stale                    : 0x00 (0)
>                  lease                    : NULL
>          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/05 16:22:32.362274, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:155(share_mode_memcache_delete)
>  deleting entry for file . seq 0x13501076290392828596 key fd1c:80:0
>[2017/06/05 16:22:32.362499,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:32.362547, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.362643, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 1CFD0000000000008000
>[2017/06/05 16:22:32.362774, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:169(share_mode_memcache_store)
>  stored entry for file . seq 0x13501076290392828597 key fd1c:80:0
>[2017/06/05 16:22:32.362892,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dir.c:233(dptr_close_internal)
>  closing dptr key 0
>[2017/06/05 16:22:32.363055,  5, pid=2877, 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/05 16:22:32.363089, 10, pid=2877, 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/05 16:22:32.363166, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key A4052486
>[2017/06/05 16:22:32.363205, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed382ca0
>[2017/06/05 16:22:32.363252, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key A4052486
>[2017/06/05 16:22:32.363296,  5, pid=2877, 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/05 16:22:32.363405, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.363494,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:513(fsp_free)
>  fsp_free(fsp=0x7f38ed3a4570)
>[2017/06/05 16:22:32.363772,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:570(file_free)
>  freed files structure 3351404820 (1 used)
>[2017/06/05 16:22:32.363823,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:611(dos_mode)
>  dos_mode: .
>[2017/06/05 16:22:32.363855,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode_from_sbuf returning (0x10): "d"
>[2017/06/05 16:22:32.363895,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1009(is_in_path)
>  is_in_path: .
>[2017/06/05 16:22:32.364023,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1033(is_in_path)
>  is_in_path: match not found
>[2017/06/05 16:22:32.364057,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode returning (0x10): "d"
>[2017/06/05 16:22:32.364095, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3014(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:144
>[2017/06/05 16:22:32.364219,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2717(smbd_smb2_request_reply_update_counts)
>  smbd_smb2_request_reply_update_counts: compat_chain_fsp=(nil)
>[2017/06/05 16:22:32.364471, 10, pid=2877, 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 483/512, total granted/max/low/range 30/8192/11/30
>[2017/06/05 16:22:32.364550, 10, pid=2877, 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_NOTIFY] mid 9 going async
>[2017/06/05 16:22:32.364704, 10, pid=2877, 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/11/31
>[2017/06/05 16:22:32.364778, 10, pid=2877, 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/05 16:22:32.370834, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3912(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 9 vectors
>[2017/06/05 16:22:32.370883, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 11 (position 11) from bitmap
>[2017/06/05 16:22:32.370913, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 12 (position 12) from bitmap
>[2017/06/05 16:22:32.370944, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 11
>[2017/06/05 16:22:32.371004,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2017/06/05 16:22:32.371046,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=(nil)
>[2017/06/05 16:22:32.371263, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:503(smbd_smb2_create_send)
>  smbd_smb2_create: name[]
>[2017/06/05 16:22:32.371302, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:997(smbd_smb2_create_send)
>  smbd_smb2_create_send: open execution phase
>[2017/06/05 16:22:32.371387,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:443(unix_convert)
>  unix_convert called on file ""
>[2017/06/05 16:22:32.371438,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:477(unix_convert)
>  conversion finished "" -> .
>[2017/06/05 16:22:32.371466, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1199(check_reduced_name)
>  check_reduced_name: check_reduced_name [.] [/export/vol1]
>[2017/06/05 16:22:32.371507, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1259(check_reduced_name)
>  check_reduced_name realpath [.] -> [/export/vol1]
>[2017/06/05 16:22:32.371537,  5, pid=2877, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1370(check_reduced_name)
>  check_reduced_name: . reduced to /export/vol1
>[2017/06/05 16:22:32.371614, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5515(create_file_default)
>  create_file: access_mask = 0x100080 file_attributes = 0x0, share_access = 0x0, create_disposition = 0x1 create_options = 0x800001 oplock_request = 0x0 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = .
>[2017/06/05 16:22:32.371691, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4988(create_file_unixpath)
>  create_file_unixpath: access_mask = 0x100080 file_attributes = 0x0, share_access = 0x0, create_disposition = 0x1 create_options = 0x800001 oplock_request = 0x0 private_flags = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = .
>[2017/06/05 16:22:32.371808,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:3917(open_directory)
>  open_directory: opening directory ., access_mask = 0x100080, share_access = 0x0 create_options = 0x800001, create_disposition = 0x1, file_attributes = 0x10
>[2017/06/05 16:22:32.371857, 10, pid=2877, 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 .
>[2017/06/05 16:22:32.372060, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1251(uid_to_sid)
>  uid 0 -> sid S-1-22-1-0
>[2017/06/05 16:22:32.372345, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1300(gid_to_sid)
>  gid 0 -> sid S-1-22-2-0
>[2017/06/05 16:22:32.372406, 10, pid=2877, 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/05 16:22:32.372504, 10, pid=2877, 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/05 16:22:32.372607, 10, pid=2877, 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-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.372788, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.372933, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) 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/05 16:22:32.373291, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.373368, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.373467, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.373565, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:181(smbd_check_access_rights)
>  smbd_check_access_rights: file . requesting 0x100080 returning 0x100000 (NT_STATUS_OK)
>[2017/06/05 16:22:32.373614,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:65(fsp_new)
>  fsp_new: fsp=0x7f38ed3b9960
>[2017/06/05 16:22:32.373892,  5, pid=2877, 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/05 16:22:32.373928, 10, pid=2877, 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/05 16:22:32.373964, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key C86CD68C
>[2017/06/05 16:22:32.374104, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3b2790
>[2017/06/05 16:22:32.374151, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:624(smbXsrv_open_global_verify_record)
>  smbXsrv_open_global_verify_record: empty value
>[2017/06/05 16:22:32.374336, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:743(smbXsrv_open_global_store)
>  smbXsrv_open_global_store: key 'C86CD68C' stored
>[2017/06/05 16:22:32.374386,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  open_global_id           : 0xc86cd68c (3362576012)
>                  open_persistent_id       : 0x00000000c86cd68c (3362576012)
>                  open_volatile_id         : 0x00000000afd51f7d (2949980029)
>                  open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                  open_time                : Mon Jun  5 16:22:32 2017 IDT
>                  create_guid              : 00000000-0000-0000-0000-000000000000
>                  client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                  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         : 0x0000000000000000 (0)
>[2017/06/05 16:22:32.374908, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key C86CD68C
>[2017/06/05 16:22:32.374954,  5, pid=2877, 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/05 16:22:32.375033, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.375076, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:910(smbXsrv_open_create)
>  smbXsrv_open_create: global_id (0xc86cd68c) stored
>[2017/06/05 16:22:32.375112,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(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                 : 0xafd51f7d (2949980029)
>                  global                   : *
>                      global: struct smbXsrv_open_global0
>                          db_rec                   : NULL
>                          server_id: struct server_id
>                              pid                      : 0x0000000000000b3d (2877)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                          open_global_id           : 0xc86cd68c (3362576012)
>                          open_persistent_id       : 0x00000000c86cd68c (3362576012)
>                          open_volatile_id         : 0x00000000afd51f7d (2949980029)
>                          open_owner               : S-1-5-21-1893543895-1847372660-4172524467-501
>                          open_time                : Mon Jun  5 16:22:32 2017 IDT
>                          create_guid              : 00000000-0000-0000-0000-000000000000
>                          client_guid              : eb460979-4694-11e7-9429-005056ae0ecf
>                          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         : 0x0000000000000000 (0)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Mon Jun  5 16:22:32 2017 IDT
>                  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)
>[2017/06/05 16:22:32.375838,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:130(file_new)
>  allocated file structure fnum 2949980029 (2 used)
>[2017/06/05 16:22:32.375879, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:763(file_name_hash)
>  file_name_hash: /export/vol1/. hash 0xd7088907
>[2017/06/05 16:22:32.375918, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4125(open_directory)
>  Not opening Directory .
>[2017/06/05 16:22:32.375953,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
>  check lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:32.376099, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:<none>
>[2017/06/05 16:22:32.376157, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 1CFD0000000000008000
>[2017/06/05 16:22:32.376269, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3bada0
>[2017/06/05 16:22:32.376366, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:283(share_mode_memcache_fetch)
>  fetched entry for file . seq 0x13501076290392828597 key fd1c:80:0
>[2017/06/05 16:22:32.376417, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:1229(find_delete_on_close_token)
>  find_delete_on_close_token: name_hash = 0xd7088907
>[2017/06/05 16:22:32.376459, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:366(unparse_share_modes)
>  unparse_share_modes:
>[2017/06/05 16:22:32.376498,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(ndr_print_debug)
>       d: struct share_mode_data
>          sequence_number          : 0xbb5d755ab6502ab5 (-4945667783316723019)
>          servicepath              : *
>              servicepath              : '/export/vol1'
>          base_name                : *
>              base_name                : '.'
>          stream_name              : NULL
>          num_share_modes          : 0x00000002 (2)
>          share_modes: ARRAY(2)
>              share_modes: struct share_mode_entry
>                  pid: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  op_mid                   : 0x0000000000000008 (8)
>                  op_type                  : 0x0000 (0)
>                  lease_idx                : 0xffffffff (4294967295)
>                  access_mask              : 0x00100081 (1048705)
>                  share_access             : 0x00000007 (7)
>                  private_options          : 0x00000000 (0)
>                  time                     : Mon Jun  5 16:22:32 2017 IDT.349235
>                  id: struct file_id
>                      devid                    : 0x000000000000fd1c (64796)
>                      inode                    : 0x0000000000000080 (128)
>                      extid                    : 0x0000000000000000 (0)
>                  share_file_id            : 0x000000005b30c763 (1529923427)
>                  uid                      : 0x0000fffe (65534)
>                  flags                    : 0x0000 (0)
>                  name_hash                : 0xd7088907 (3607660807)
>                  stale                    : 0x00 (0)
>                  lease                    : NULL
>              share_modes: struct share_mode_entry
>                  pid: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  op_mid                   : 0x000000000000000b (11)
>                  op_type                  : 0x0000 (0)
>                  lease_idx                : 0xffffffff (4294967295)
>                  access_mask              : 0x00100080 (1048704)
>                  share_access             : 0x00000000 (0)
>                  private_options          : 0x00000000 (0)
>                  time                     : Mon Jun  5 16:22:32 2017 IDT.373882
>                  id: struct file_id
>                      devid                    : 0x000000000000fd1c (64796)
>                      inode                    : 0x0000000000000080 (128)
>                      extid                    : 0x0000000000000000 (0)
>                  share_file_id            : 0x0000000068f82785 (1761093509)
>                  uid                      : 0x0000fffe (65534)
>                  flags                    : 0x0000 (0)
>                  name_hash                : 0xd7088907 (3607660807)
>                  stale                    : 0x00 (0)
>                  lease                    : NULL
>          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/05 16:22:32.377707, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:155(share_mode_memcache_delete)
>  deleting entry for file . seq 0x13501076290392828597 key fd1c:80:0
>[2017/06/05 16:22:32.377856,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:32.377902, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:32.378033, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 1CFD0000000000008000
>[2017/06/05 16:22:32.378172, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:169(share_mode_memcache_store)
>  stored entry for file . seq 0x13501076290392828598 key fd1c:80:0
>[2017/06/05 16:22:32.378224, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5322(create_file_unixpath)
>  create_file_unixpath: info=1
>[2017/06/05 16:22:32.378261, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5603(create_file_default)
>  create_file: info=1
>[2017/06/05 16:22:32.378309, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1188(smbd_smb2_create_send)
>  smbd_smb2_create_send: response construction phase
>[2017/06/05 16:22:32.378341, 10, pid=2877, 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 .
>[2017/06/05 16:22:32.378464, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1251(uid_to_sid)
>  uid 0 -> sid S-1-22-1-0
>[2017/06/05 16:22:32.378524, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1300(gid_to_sid)
>  gid 0 -> sid S-1-22-2-0
>[2017/06/05 16:22:32.378657, 10, pid=2877, 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/05 16:22:32.378797, 10, pid=2877, 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/05 16:22:32.378851, 10, pid=2877, 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-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.379083, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2017/06/05 16:22:32.379184, 10, pid=2877, 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-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) 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/05 16:22:32.379428, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.379472, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.379502, 10, pid=2877, 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) 1f01ff
>[2017/06/05 16:22:32.379622, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../libcli/security/access_check.c:188(se_access_check)
>  se_access_check: MAX desired = 0x2000000, granted = 0x1f01ff, remaining = 0x1f01ff
>[2017/06/05 16:22:32.379717,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1352(smbd_smb2_create_send)
>  smbd_smb2_create_send: smb2req->compat_chain_fsp=0x7f38ed3b9960
>[2017/06/05 16:22:32.379930,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:611(dos_mode)
>  dos_mode: .
>[2017/06/05 16:22:32.379966,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode_from_sbuf returning (0x10): "d"
>[2017/06/05 16:22:32.380024,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1009(is_in_path)
>  is_in_path: .
>[2017/06/05 16:22:32.380060,  8, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/util.c:1033(is_in_path)
>  is_in_path: match not found
>[2017/06/05 16:22:32.380084,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:70(dos_mode_debug_print)
>  dos_mode_debug_print: dos_mode returning (0x10): "d"
>[2017/06/05 16:22:32.380124, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1397(smbd_smb2_create_send)
>  smbd_smb2_create_send: . - fnum 2949980029
>[2017/06/05 16:22:32.380210, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3014(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[88] dyn[yes:32] at ../source3/smbd/smb2_create.c:364
>[2017/06/05 16:22:32.380278, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2982(smbd_smb2_request_dispatch_immediate)
>  smbd_smb2_request_dispatch_immediate: idx[5] of 9 vectors
>  	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 = 32
>  	req->in.vector[5].iov_len = 0
>  	req->in.vector[6].iov_len = 64
>  	req->in.vector[7].iov_len = 40
>  	req->in.vector[8].iov_len = 0
>  	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 = 88
>  	req->out.vector[4].iov_len = 32
>  	req->out.vector[5].iov_len = 0
>  	req->out.vector[6].iov_len = 64
>  	req->out.vector[7].iov_len = 8
>  	req->out.vector[8].iov_len = 0
>[2017/06/05 16:22:32.380633, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_GETINFO] mid = 12
>[2017/06/05 16:22:32.380680,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2017/06/05 16:22:32.380732,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=0x7f38ed3b9960
>[2017/06/05 16:22:32.380901, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1955(smbd_smb2_request_verify_creditcharge)
>  mid 12, CreditCharge: 1, NeededCharge: 1
>[2017/06/05 16:22:32.380939, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_getinfo.c:272(smbd_smb2_getinfo_send)
>  smbd_smb2_getinfo_send: . - fnum 2949980029
>[2017/06/05 16:22:32.381018,  3, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:3422(smbd_do_qfsinfo)
>  smbd_do_qfsinfo: level = 1007
>[2017/06/05 16:22:32.381545, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas.c:466(sys_get_quota)
>  sys_get_quota() uid(65534, 65534), fs(xfs)
>[2017/06/05 16:22:32.381596, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas_xfs.c:121(sys_get_xfs_quota)
>  sys_get_xfs_quota: path[/export/vol1] bdev[/dev/dm-28] SMB_USER_FS_QUOTA_TYPE (uid[4294967295])
>[2017/06/05 16:22:32.381636, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas.c:476(sys_get_quota)
>  sys_get_xfs_quota() called for mntpath[/export/vol1] bdev[/dev/dm-28] qtype[1] id[-1].
>[2017/06/05 16:22:32.381910, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas.c:466(sys_get_quota)
>  sys_get_quota() uid(65534, 65534), fs(xfs)
>[2017/06/05 16:22:32.381957, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas_xfs.c:138(sys_get_xfs_quota)
>  sys_get_xfs_quota: path[/export/vol1] bdev[/dev/dm-28] SMB_GROUP_FS_QUOTA_TYPE (gid[4294967295])
>[2017/06/05 16:22:32.382043, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas.c:476(sys_get_quota)
>  sys_get_xfs_quota() called for mntpath[/export/vol1] bdev[/dev/dm-28] qtype[3] id[-1].
>[2017/06/05 16:22:32.382083,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:3661(smbd_do_qfsinfo)
>  smbd_do_qfsinfo : SMB_QUERY_FS_FULL_SIZE_INFO bsize=1024, cSectorUnit=2, cBytesSector=512, cUnitTotal=10475520, cUnitAvail=10442592
>[2017/06/05 16:22:32.382183, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3014(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[5] status[NT_STATUS_OK] body[8] dyn[yes:32] at ../source3/smbd/smb2_getinfo.c:201
>[2017/06/05 16:22:32.382223,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2717(smbd_smb2_request_reply_update_counts)
>  smbd_smb2_request_reply_update_counts: compat_chain_fsp=0x7f38ed3b9960
>[2017/06/05 16:22:32.382388, 10, pid=2877, 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 483/512, total granted/max/low/range 30/8192/13/30
>[2017/06/05 16:22:32.382425, 10, pid=2877, 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/13/31
>[2017/06/05 16:22:32.400406, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3912(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2017/06/05 16:22:32.400456, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:673(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 13 (position 13) from bitmap
>[2017/06/05 16:22:32.400488, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2272(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_GETINFO] mid = 13
>[2017/06/05 16:22:32.400522,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2017/06/05 16:22:32.400564,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:697(file_fsp_smb2)
>  file_fsp_smb2: smb2req->compat_chain_fsp=(nil)
>[2017/06/05 16:22:32.400826,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2145(smbd_smb2_request_dispatch_update_counts)
>  smbd_smb2_request_dispatch_update_counts: compat_chain_fsp=0x7f38ed3b9960
>[2017/06/05 16:22:32.401060, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1955(smbd_smb2_request_verify_creditcharge)
>  mid 13, CreditCharge: 1, NeededCharge: 1
>[2017/06/05 16:22:32.401099, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_getinfo.c:272(smbd_smb2_getinfo_send)
>  smbd_smb2_getinfo_send: . - fnum 2949980029
>[2017/06/05 16:22:32.401140,  3, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:3422(smbd_do_qfsinfo)
>  smbd_do_qfsinfo: level = 1007
>[2017/06/05 16:22:32.401770, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas.c:466(sys_get_quota)
>  sys_get_quota() uid(65534, 65534), fs(xfs)
>[2017/06/05 16:22:32.401847, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas_xfs.c:121(sys_get_xfs_quota)
>  sys_get_xfs_quota: path[/export/vol1] bdev[/dev/dm-28] SMB_USER_FS_QUOTA_TYPE (uid[4294967295])
>[2017/06/05 16:22:32.401884, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas.c:476(sys_get_quota)
>  sys_get_xfs_quota() called for mntpath[/export/vol1] bdev[/dev/dm-28] qtype[1] id[-1].
>[2017/06/05 16:22:32.402198, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas.c:466(sys_get_quota)
>  sys_get_quota() uid(65534, 65534), fs(xfs)
>[2017/06/05 16:22:32.402251, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas_xfs.c:138(sys_get_xfs_quota)
>  sys_get_xfs_quota: path[/export/vol1] bdev[/dev/dm-28] SMB_GROUP_FS_QUOTA_TYPE (gid[4294967295])
>[2017/06/05 16:22:32.402286, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=quota] ../source3/lib/sysquotas.c:476(sys_get_quota)
>  sys_get_xfs_quota() called for mntpath[/export/vol1] bdev[/dev/dm-28] qtype[3] id[-1].
>[2017/06/05 16:22:32.402369,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/trans2.c:3661(smbd_do_qfsinfo)
>  smbd_do_qfsinfo : SMB_QUERY_FS_FULL_SIZE_INFO bsize=1024, cSectorUnit=2, cBytesSector=512, cUnitTotal=10475520, cUnitAvail=10442592
>[2017/06/05 16:22:32.402413, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3014(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[8] dyn[yes:32] at ../source3/smbd/smb2_getinfo.c:201
>[2017/06/05 16:22:32.402452,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2717(smbd_smb2_request_reply_update_counts)
>  smbd_smb2_request_reply_update_counts: compat_chain_fsp=0x7f38ed3b9960
>[2017/06/05 16:22:32.402626, 10, pid=2877, 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/14/31
>[2017/06/05 16:22:42.005403, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/lib/messages.c:152(messaging_recv_cb)
>  messaging_recv_cb: Received message 0x302 len 5 (num_fds:0) from 3162
>[2017/06/05 16:22:42.005483,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/conn_idle.c:120(conn_force_tdis)
>  conn_force_tdis: Forcing close of share 'vol1' (wire_id=0xe394d695)
>[2017/06/05 16:22:42.005520,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
>  check lock order 1 for /var/lock/samba/smbXsrv_tcon_global.tdb
>[2017/06/05 16:22:42.005601, 10, pid=2877, effective(65534, 65534), real(65534, 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/05 16:22:42.005648, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key E394D695
>[2017/06/05 16:22:42.005687, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3bb540
>[2017/06/05 16:22:42.005734, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key E394D695
>[2017/06/05 16:22:42.005781,  5, pid=2877, 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_tcon_global.tdb
>[2017/06/05 16:22:42.005812, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:42.005859,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
>  check lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:42.005902, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:<none>
>[2017/06/05 16:22:42.005940, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 1CFD0000000000008000
>[2017/06/05 16:22:42.006003, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3c1d40
>[2017/06/05 16:22:42.006051, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:283(share_mode_memcache_fetch)
>  fetched entry for file . seq 0x13501076290392828598 key fd1c:80:0
>[2017/06/05 16:22:42.006089, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:1229(find_delete_on_close_token)
>  find_delete_on_close_token: name_hash = 0xd7088907
>[2017/06/05 16:22:42.006120, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:366(unparse_share_modes)
>  unparse_share_modes:
>[2017/06/05 16:22:42.006163,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(ndr_print_debug)
>       d: struct share_mode_data
>          sequence_number          : 0xbb5d755ab6502ab6 (-4945667783316723018)
>          servicepath              : *
>              servicepath              : '/export/vol1'
>          base_name                : *
>              base_name                : '.'
>          stream_name              : NULL
>          num_share_modes          : 0x00000001 (1)
>          share_modes: ARRAY(1)
>              share_modes: struct share_mode_entry
>                  pid: struct server_id
>                      pid                      : 0x0000000000000b3d (2877)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x27330f1f08b45cf6 (2824618017255873782)
>                  op_mid                   : 0x0000000000000008 (8)
>                  op_type                  : 0x0000 (0)
>                  lease_idx                : 0xffffffff (4294967295)
>                  access_mask              : 0x00100081 (1048705)
>                  share_access             : 0x00000007 (7)
>                  private_options          : 0x00000000 (0)
>                  time                     : Mon Jun  5 16:22:32 2017 IDT.349235
>                  id: struct file_id
>                      devid                    : 0x000000000000fd1c (64796)
>                      inode                    : 0x0000000000000080 (128)
>                      extid                    : 0x0000000000000000 (0)
>                  share_file_id            : 0x000000005b30c763 (1529923427)
>                  uid                      : 0x0000fffe (65534)
>                  flags                    : 0x0000 (0)
>                  name_hash                : 0xd7088907 (3607660807)
>                  stale                    : 0x00 (0)
>                  lease                    : NULL
>          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/05 16:22:42.006960, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:155(share_mode_memcache_delete)
>  deleting entry for file . seq 0x13501076290392828598 key fd1c:80:0
>[2017/06/05 16:22:42.007070,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:42.007143, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:42.007185, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 1CFD0000000000008000
>[2017/06/05 16:22:42.007227, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:169(share_mode_memcache_store)
>  stored entry for file . seq 0x13501076290392828599 key fd1c:80:0
>[2017/06/05 16:22:42.007271,  5, pid=2877, 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/05 16:22:42.007299, 10, pid=2877, 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/05 16:22:42.007342, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key C86CD68C
>[2017/06/05 16:22:42.007376, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed382ca0
>[2017/06/05 16:22:42.007418, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key C86CD68C
>[2017/06/05 16:22:42.007447,  5, pid=2877, 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/05 16:22:42.007476, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:42.007518,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:513(fsp_free)
>  fsp_free(fsp=0x7f38ed3b9960)
>[2017/06/05 16:22:42.008446,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:570(file_free)
>  freed files structure 2949980029 (1 used)
>[2017/06/05 16:22:42.008503,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:159(dbwrap_check_lock_order)
>  check lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:42.008535, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:<none>
>[2017/06/05 16:22:42.008602, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 1CFD0000000000008000
>[2017/06/05 16:22:42.008766, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed3c23e0
>[2017/06/05 16:22:42.008822, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:283(share_mode_memcache_fetch)
>  fetched entry for file . seq 0x13501076290392828599 key fd1c:80:0
>[2017/06/05 16:22:42.008934, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:1229(find_delete_on_close_token)
>  find_delete_on_close_token: name_hash = 0xd7088907
>[2017/06/05 16:22:42.009012, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:366(unparse_share_modes)
>  unparse_share_modes:
>[2017/06/05 16:22:42.009055,  1, pid=2877, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:413(ndr_print_debug)
>       d: struct share_mode_data
>          sequence_number          : 0xbb5d755ab6502ab7 (-4945667783316723017)
>          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/05 16:22:42.009402, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:155(share_mode_memcache_delete)
>  deleting entry for file . seq 0x13501076290392828599 key fd1c:80:0
>[2017/06/05 16:22:42.009463, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:378(unparse_share_modes)
>  No used share mode found
>[2017/06/05 16:22:42.009511,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:127(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/lock/samba/locking.tdb
>[2017/06/05 16:22:42.009595, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:42.009646, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 1CFD0000000000008000
>[2017/06/05 16:22:42.009715, 10, pid=2877, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/posix.c:498(delete_lock_ref_count)
>  delete_lock_ref_count for file .
>[2017/06/05 16:22:42.009777,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
>  push_sec_ctx(65534, 65534) : sec_ctx_stack_ndx = 1
>[2017/06/05 16:22:42.009824,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(1512126538) : conn_ctx_stack_ndx = 0
>[2017/06/05 16:22:42.009855,  4, pid=2877, 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 = 1
>[2017/06/05 16:22:42.009893,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2017/06/05 16:22:42.009932,  5, pid=2877, 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/05 16:22:42.010023, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/messages_dgm.c:323(messaging_dgm_send)
>  messaging_dgm_send: Sending message to 2602
>[2017/06/05 16:22:42.010744,  4, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx)
>  pop_sec_ctx (65534, 65534) - sec_ctx_stack_ndx = 0
>[2017/06/05 16:22:42.010794,  5, pid=2877, 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/05 16:22:42.010826, 10, pid=2877, 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/05 16:22:42.010873, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key C311E6B8
>[2017/06/05 16:22:42.010914, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f38ed382ca0
>[2017/06/05 16:22:42.010998, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key C311E6B8
>[2017/06/05 16:22:42.011049,  5, pid=2877, 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/05 16:22:42.011091, 10, pid=2877, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:114(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2017/06/05 16:22:42.011140,  0, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:513(fsp_free)
>  fsp_free(fsp=0x7f38ed3ba6f0)
>[2017/06/05 16:22:42.011626,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:570(file_free)
>  freed files structure 111888149 (0 used)
>[2017/06/05 16:22:42.011680,  4, pid=2877, 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/05 16:22:42.011795,  5, pid=2877, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2017/06/05 16:22:42.011851,  5, pid=2877, 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/05 16:22:42.011917,  5, pid=2877, 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/05 16:22:42.011961,  2, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:1144(close_cnum)
>  vm21-win2012se (ipv4:170.70.2.21:54923) closed connection to service vol1
>[2017/06/05 16:22:42.012054,  4, pid=2877, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:874(vfs_ChDir)
>  vfs_ChDir to /
>[2017/06/05 16:22:42.012116,  4, pid=2877, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:885(vfs_ChDir)
>  vfs_ChDir got /
>[2017/06/05 16:22:42.012166,  4, pid=2877, 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/05 16:22:42.012197,  5, pid=2877, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2017/06/05 16:22:42.012282,  5, pid=2877, 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/05 16:22:42.012335,  5, pid=2877, 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/05 16:22:42.018515,  4, pid=2877, 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/05 16:22:42.018586,  5, pid=2877, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2017/06/05 16:22:42.018615,  5, pid=2877, 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/05 16:22:42.018681,  5, pid=2877, 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/05 16:22:42.018771,  6, pid=2877, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2229(lp_file_list_changed)
>  lp_file_list_changed()
>  file /etc/samba/smb.conf -> /etc/samba/smb.conf  last mod_time: Mon Jun  5 14:14:33 2017
>  
>[2017/06/05 16:22:42.018911,  0, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_notify.c:118(smbd_smb2_request_notify_done)
>  smbd_smb2_request_notify_done: req->compat_chain_fsp=0x7f38ed3ba6f0
>[2017/06/05 16:22:42.019636,  3, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3132(smbd_smb2_request_error_ex)
>  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[STATUS_NOTIFY_CLEANUP] || at ../source3/smbd/smb2_notify.c:125
>[2017/06/05 16:22:42.019732, 10, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3014(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[STATUS_NOTIFY_CLEANUP] body[8] dyn[yes:1] at ../source3/smbd/smb2_server.c:3189
>[2017/06/05 16:22:42.019811,  0, pid=2877, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2717(smbd_smb2_request_reply_update_counts)
>  smbd_smb2_request_reply_update_counts: compat_chain_fsp=0x7f38ed3ba6f0
>[2017/06/05 16:22:42.020173,  0, pid=2877, effective(0, 0), real(0, 0)] ../lib/util/fault.c:78(fault_report)
>  ===============================================================
>[2017/06/05 16:22:42.020853,  0, pid=2877, effective(0, 0), real(0, 0)] ../lib/util/fault.c:79(fault_report)
>  INTERNAL ERROR: Signal 11 in pid 2877 (4.5.10)
>  Please read the Trouble-Shooting section of the Samba HOWTO
>[2017/06/05 16:22:42.021481,  0, pid=2877, effective(0, 0), real(0, 0)] ../lib/util/fault.c:81(fault_report)
>  ===============================================================
>[2017/06/05 16:22:42.021992,  0, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/util.c:791(smb_panic_s3)
>  PANIC (pid 2877): internal error
>[2017/06/05 16:22:42.023094,  0, pid=2877, effective(0, 0), real(0, 0)] ../source3/lib/util.c:910(log_stack_trace)
>  BACKTRACE: 34 stack frames:
>   #0 /usr/lib/libsmbconf.so.0(log_stack_trace+0x1f) [0x7f38e855f4b9]
>   #1 /usr/lib/libsmbconf.so.0(smb_panic_s3+0x70) [0x7f38e855f2ef]
>   #2 /usr/lib/libsamba-util.so.0(smb_panic+0x28) [0x7f38eb04814d]
>   #3 /usr/lib/libsamba-util.so.0(+0x21e25) [0x7f38eb047e25]
>   #4 /usr/lib/libsamba-util.so.0(+0x21e3a) [0x7f38eb047e3a]
>   #5 /lib/x86_64-linux-gnu/libpthread.so.0(+0x10330) [0x7f38eb2b4330]
>   #6 /usr/lib/samba/libsmbd-base-samba4.so(+0x1a6bf1) [0x7f38eabb7bf1]
>   #7 /usr/lib/samba/libsmbd-base-samba4.so(+0x1a6e50) [0x7f38eabb7e50]
>   #8 /usr/lib/samba/libsmbd-base-samba4.so(smbd_smb2_request_done_ex+0x622) [0x7f38eabb9638]
>   #9 /usr/lib/samba/libsmbd-base-samba4.so(smbd_smb2_request_error_ex+0x2f4) [0x7f38eabb993a]
>   #10 /usr/lib/samba/libsmbd-base-samba4.so(+0x1c9205) [0x7f38eabda205]
>   #11 /usr/lib/samba/libtevent.so.0(_tevent_req_notify_callback+0x6a) [0x7f38e9ff0367]
>   #12 /usr/lib/samba/libtevent.so.0(+0x643a) [0x7f38e9ff043a]
>   #13 /usr/lib/samba/libtevent.so.0(+0x655f) [0x7f38e9ff055f]
>   #14 /usr/lib/samba/libtevent.so.0(tevent_common_loop_immediate+0x1f5) [0x7f38e9fef77c]
>   #15 /usr/lib/samba/libtevent.so.0(+0xe19a) [0x7f38e9ff819a]
>   #16 /usr/lib/samba/libtevent.so.0(+0xb11e) [0x7f38e9ff511e]
>   #17 /usr/lib/samba/libtevent.so.0(_tevent_loop_once+0xf4) [0x7f38e9fee8c3]
>   #18 /usr/lib/samba/libtevent.so.0(tevent_common_loop_wait+0x25) [0x7f38e9feeb0d]
>   #19 /usr/lib/samba/libtevent.so.0(+0xb1c0) [0x7f38e9ff51c0]
>   #20 /usr/lib/samba/libtevent.so.0(_tevent_loop_wait+0x2b) [0x7f38e9feebd8]
>   #21 /usr/lib/samba/libsmbd-base-samba4.so(smbd_process+0xc3b) [0x7f38eab99f34]
>   #22 smbd(+0xdd16) [0x7f38eb906d16]
>   #23 /usr/lib/samba/libtevent.so.0(+0xdc16) [0x7f38e9ff7c16]
>   #24 /usr/lib/samba/libtevent.so.0(+0xe234) [0x7f38e9ff8234]
>   #25 /usr/lib/samba/libtevent.so.0(+0xb11e) [0x7f38e9ff511e]
>   #26 /usr/lib/samba/libtevent.so.0(_tevent_loop_once+0xf4) [0x7f38e9fee8c3]
>   #27 /usr/lib/samba/libtevent.so.0(tevent_common_loop_wait+0x25) [0x7f38e9feeb0d]
>   #28 /usr/lib/samba/libtevent.so.0(+0xb1c0) [0x7f38e9ff51c0]
>   #29 /usr/lib/samba/libtevent.so.0(_tevent_loop_wait+0x2b) [0x7f38e9feebd8]
>   #30 smbd(+0xeb26) [0x7f38eb907b26]
>   #31 smbd(main+0x189c) [0x7f38eb909579]
>   #32 /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f38e6e44f45]
>   #33 smbd(+0x68b9) [0x7f38eb8ff8b9]

Actions: View

Attachments on bug 12818: 13252 | 13298 | 13301