[2016/08/10 15:25:17.682220,  5, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 1 for /var/lock/samba/smbXsrv_session_global.tdb
[2016/08/10 15:25:17.682613, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/smbXsrv_session_global.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.683020, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key A75CA4AE
[2016/08/10 15:25:17.683458, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ed5e80
[2016/08/10 15:25:17.684196, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:882(smbXsrv_session_global_store)
[2016/08/10 15:25:17.684378, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:884(smbXsrv_session_global_store)
  smbXsrv_session_global_store: key 'A75CA4AE' stored
[2016/08/10 15:25:17.684810,  1, pid=17743, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug)
       &global_blob: struct smbXsrv_session_globalB
          version                  : SMBXSRV_VERSION_0 (0)
          seqnum                   : 0x00000002 (2)
          info                     : union smbXsrv_session_globalU(case 0)
          info0                    : *
              info0: struct smbXsrv_session_global0
                  db_rec                   : *
                  session_global_id        : 0xa75ca4ae (2807866542)
                  session_wire_id          : 0x00000000a75ca4ae (2807866542)
                  creation_time            : Wed Aug 10 15:25:18 2016 IDT
                  expiration_time          : Thu Jan  1 02:00:00 1970 IST
                  auth_time                : Wed Aug 10 15:25:18 2016 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                 : 0x00000007 (7)
                                  sids: ARRAY(7)
                                      sids                     : S-1-5-21-1329707852-3482275279-3224653934-501
                                      sids                     : S-1-5-21-1329707852-3482275279-3224653934-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
                                  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                  : 0x00000001 (1)
                                  groups: ARRAY(1)
                                      groups                   : 0x000000000000fffe (65534)
                          info                     : *
                              info: struct auth_user_info
                                  account_name             : *
                                      account_name             : 'nobody'
                                  domain_name              : *
                                      domain_name              : 'VSA-0000007E'
                                  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       : 'lev'
                          torture                  : NULL
                          credentials              : NULL
                  connection_dialect       : 0x0300 (768)
                  signing_required         : 0x00 (0)
                  encryption_required      : 0x00 (0)
                  num_channels             : 0x00000001 (1)
                  channels: ARRAY(1)
                      channels: struct smbXsrv_channel_global0
                          server_id: struct server_id
                              pid                      : 0x000000000000454f (17743)
                              task_id                  : 0x00000000 (0)
                              vnn                      : 0xffffffff (4294967295)
                              unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                          local_address            : 'ipv4:160.60.2.105:445'
                          remote_address           : 'ipv4:160.60.2.86:57119'
                          remote_name              : '160.60.2.86'
                          auth_session_info_seqnum : 0x00000001 (1)
                          connection               : *
[2016/08/10 15:25:17.686621, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key A75CA4AE
[2016/08/10 15:25:17.686656,  5, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 1 for /var/lock/samba/smbXsrv_session_global.tdb
[2016/08/10 15:25:17.686692, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.686716, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1330(smbXsrv_session_update)
[2016/08/10 15:25:17.686729, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1338(smbXsrv_session_update)
  smbXsrv_session_update: global_id (0xa75ca4ae) stored
[2016/08/10 15:25:17.686747,  1, pid=17743, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(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                 : 0xa75ca4ae (2807866542)
                  global                   : *
                      global: struct smbXsrv_session_global0
                          db_rec                   : NULL
                          session_global_id        : 0xa75ca4ae (2807866542)
                          session_wire_id          : 0x00000000a75ca4ae (2807866542)
                          creation_time            : Wed Aug 10 15:25:18 2016 IDT
                          expiration_time          : Thu Jan  1 02:00:00 1970 IST
                          auth_time                : Wed Aug 10 15:25:18 2016 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                 : 0x00000007 (7)
                                          sids: ARRAY(7)
                                              sids                     : S-1-5-21-1329707852-3482275279-3224653934-501
                                              sids                     : S-1-5-21-1329707852-3482275279-3224653934-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
                                          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                  : 0x00000001 (1)
                                          groups: ARRAY(1)
                                              groups                   : 0x000000000000fffe (65534)
                                  info                     : *
                                      info: struct auth_user_info
                                          account_name             : *
                                              account_name             : 'nobody'
                                          domain_name              : *
                                              domain_name              : 'VSA-0000007E'
                                          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       : 'lev'
                                  torture                  : NULL
                                  credentials              : NULL
                          connection_dialect       : 0x0300 (768)
                          signing_required         : 0x00 (0)
                          encryption_required      : 0x00 (0)
                          num_channels             : 0x00000001 (1)
                          channels: ARRAY(1)
                              channels: struct smbXsrv_channel_global0
                                  server_id: struct server_id
                                      pid                      : 0x000000000000454f (17743)
                                      task_id                  : 0x00000000 (0)
                                      vnn                      : 0xffffffff (4294967295)
                                      unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                                  local_address            : 'ipv4:160.60.2.105:445'
                                  remote_address           : 'ipv4:160.60.2.86:57119'
                                  remote_name              : '160.60.2.86'
                                  auth_session_info_seqnum : 0x00000001 (1)
                                  connection               : *
                  status                   : NT_STATUS_OK
                  idle_time                : Wed Aug 10 15:25:18 2016 IDT
                  nonce_high               : 0xf2af8188d99b8922 (-959405770840241886)
                  nonce_low                : 0x0000000000000001 (1)
                  gensec                   : *
                  compat                   : *
                  tcon_table               : *
                  encryption_desired       : 0x00 (0)
[2016/08/10 15:25:17.690982, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2617(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:167
[2016/08/10 15:25:17.691033, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:911(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/3/31
[2016/08/10 15:25:17.692388, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3506(smbd_smb2_io_handler)
  smbd_smb2_request idx[1] of 5 vectors
[2016/08/10 15:25:17.692811, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:659(smb2_validate_sequence_number)
  smb2_validate_sequence_number: clearing id 3 (position 3) from bitmap
[2016/08/10 15:25:17.693289, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1967(smbd_smb2_request_dispatch)
  smbd_smb2_request_dispatch: opcode[SMB2_OP_TCON] mid = 3
[2016/08/10 15:25:17.693774,  4, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/08/10 15:25:17.694212,  5, pid=17743, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
  Security token: (NULL)
[2016/08/10 15:25:17.694254,  5, pid=17743, 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
[2016/08/10 15:25:17.694489,  5, pid=17743, 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)
[2016/08/10 15:25:17.694650, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_tcon.c:199(smbd_smb2_tree_connect)
  smbd_smb2_tree_connect: path[\\160.60.2.105\v1] share[v1]
[2016/08/10 15:25:17.694720,  7, pid=17743, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3998(lp_servicenumber)
  lp_servicenumber: couldn't find v1
[2016/08/10 15:25:17.694745,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc)
  Finding user v1
[2016/08/10 15:25:17.694763,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals)
  Trying _Get_Pwnam(), username as lowercase is v1
[2016/08/10 15:25:17.695561,  0, pid=17743, class=idmap] vc/idmap/nss_wrapper.c:74(_nss_wrapper_getpwnam_r)
  idmap_get_user_by_name(v1) failed, err=2
[2016/08/10 15:25:17.696295,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/username.c:141(Get_Pwnam_internals)
  Trying _Get_Pwnam(), username as uppercase is V1
[2016/08/10 15:25:17.697015,  0, pid=17743, class=idmap] vc/idmap/nss_wrapper.c:74(_nss_wrapper_getpwnam_r)
  idmap_get_user_by_name(V1) failed, err=2
[2016/08/10 15:25:17.697658,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/username.c:153(Get_Pwnam_internals)
  Checking combinations of 0 uppercase letters in v1
[2016/08/10 15:25:17.697900,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals)
  Get_Pwnam_internals didn't find user [v1]!
[2016/08/10 15:25:17.697953,  3, pid=17743, effective(0, 0), real(0, 0)] ../source3/param/service.c:150(find_service)
  checking for home directory v1 gave (NULL)
[2016/08/10 15:25:17.698040,  7, pid=17743, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3998(lp_servicenumber)
  lp_servicenumber: couldn't find printers
[2016/08/10 15:25:17.698092,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1977(process_registry_service)
  process_registry_service: service name printers
[2016/08/10 15:25:17.698125, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:367(pathtree_find)
  pathtree_find: Enter [\HKLM\SOFTWARE\Samba\smbconf\printers]
[2016/08/10 15:25:17.698151, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:440(pathtree_find)
  pathtree_find: Exit
[2016/08/10 15:25:17.698199,  7, pid=17743, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3998(lp_servicenumber)
  lp_servicenumber: couldn't find printers
[2016/08/10 15:25:17.698222,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1977(process_registry_service)
  process_registry_service: service name v1
[2016/08/10 15:25:17.698247, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:367(pathtree_find)
  pathtree_find: Enter [\HKLM\SOFTWARE\Samba\smbconf\v1]
[2016/08/10 15:25:17.698270, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:440(pathtree_find)
  pathtree_find: Exit
[2016/08/10 15:25:17.698321, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:367(pathtree_find)
  pathtree_find: Enter [\HKLM\SOFTWARE\Samba\smbconf\v1]
[2016/08/10 15:25:17.698347, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:440(pathtree_find)
  pathtree_find: Exit
[2016/08/10 15:25:17.698871,  2, pid=17743, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2610(lp_do_section)
  Processing section "[v1]"
[2016/08/10 15:25:17.698942,  8, pid=17743, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1332(add_a_service)
  add_a_service: Creating snum = 1 for v1
[2016/08/10 15:25:17.698964, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1382(hash_a_service)
  hash_a_service: hashing index 1 for service name v1
  doing parameter path = /export/v1
  doing parameter guest ok = yes
  doing parameter read only = no
  doing parameter hosts deny = ALL
  doing parameter kernel 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 files = 
  doing parameter hide unreadable = No
  doing parameter hide unwriteable files = No
  doing parameter hosts allow = 160.60.2.80,160.60.2.86
  doing parameter level2 oplocks = Yes
[2016/08/10 15:25:17.699529,  5, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 1 for /var/lock/samba/smbXsrv_tcon_global.tdb
[2016/08/10 15:25:17.699557, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.699582, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key B1BF41E1
[2016/08/10 15:25:17.699615, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ed9fb0
[2016/08/10 15:25:17.699717, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:673(smbXsrv_tcon_global_store)
[2016/08/10 15:25:17.699741, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:675(smbXsrv_tcon_global_store)
  smbXsrv_tcon_global_store: key 'B1BF41E1' stored
[2016/08/10 15:25:17.699781,  1, pid=17743, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(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           : 0xb1bf41e1 (2982101473)
                  tcon_wire_id             : 0xb1bf41e1 (2982101473)
                  server_id: struct server_id
                      pid                      : 0x000000000000454f (17743)
                      task_id                  : 0x00000000 (0)
                      vnn                      : 0xffffffff (4294967295)
                      unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                  creation_time            : Wed Aug 10 15:25:18 2016 IDT
                  share_name               : NULL
                  encryption_required      : 0x00 (0)
                  session_global_id        : 0x00000000 (0)
[2016/08/10 15:25:17.699968, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key B1BF41E1
[2016/08/10 15:25:17.699992,  5, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 1 for /var/lock/samba/smbXsrv_tcon_global.tdb
[2016/08/10 15:25:17.700013, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.700035, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:798(smbXsrv_tcon_create)
[2016/08/10 15:25:17.700047, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:806(smbXsrv_tcon_create)
  smbXsrv_tcon_create: global_id (0xb1bf41e1) stored
[2016/08/10 15:25:17.700710,  1, pid=17743, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(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                 : 0xb1bf41e1 (2982101473)
                  global                   : *
                      global: struct smbXsrv_tcon_global0
                          db_rec                   : NULL
                          tcon_global_id           : 0xb1bf41e1 (2982101473)
                          tcon_wire_id             : 0xb1bf41e1 (2982101473)
                          server_id: struct server_id
                              pid                      : 0x000000000000454f (17743)
                              task_id                  : 0x00000000 (0)
                              vnn                      : 0xffffffff (4294967295)
                              unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                          creation_time            : Wed Aug 10 15:25:18 2016 IDT
                          share_name               : NULL
                          encryption_required      : 0x00 (0)
                          session_global_id        : 0x00000000 (0)
                  status                   : NT_STATUS_INTERNAL_ERROR
                  idle_time                : Wed Aug 10 15:25:18 2016 IDT
                  compat                   : NULL
                  encryption_desired       : 0x00 (0)
[2016/08/10 15:25:17.704033,  3, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/access.c:338(allow_access)
  Allowed connection from 160.60.2.86 (160.60.2.86)
[2016/08/10 15:25:17.704186, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:169(set_conn_connectpath)
  set_conn_connectpath: service v1, connectpath = /export/v1
[2016/08/10 15:25:17.704240,  3, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:619(make_connection_snum)
  Connect path is '/export/v1' for service [v1]
[2016/08/10 15:25:17.704267, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:237(user_ok_token)
  user_ok_token: share v1 is ok for unix user nobody
[2016/08/10 15:25:17.704300, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:284(is_share_read_only_for_token)
  is_share_read_only_for_user: share v1 is read-write for unix user nobody
[2016/08/10 15:25:17.704357, 10, pid=17743, 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
[2016/08/10 15:25:17.704385,  3, pid=17743, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:113(vfs_init_default)
  Initialising default vfs hooks
[2016/08/10 15:25:17.704411, 10, pid=17743, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:64(vfs_find_backend_entry)
  vfs_find_backend_entry called for posixacl
[2016/08/10 15:25:17.704432,  5, pid=17743, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:103(smb_register_vfs)
  Successfully added vfs backend 'posixacl'
[2016/08/10 15:25:17.704450, 10, pid=17743, 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]/
[2016/08/10 15:25:17.704468,  5, pid=17743, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:103(smb_register_vfs)
  Successfully added vfs backend '/[Default VFS]/'
[2016/08/10 15:25:17.704486,  3, pid=17743, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:139(vfs_init_custom)
  Initialising custom vfs hooks from [/[Default VFS]/]
[2016/08/10 15:25:17.704505, 10, pid=17743, 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
[2016/08/10 15:25:17.704904,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register)
  Registering messaging pointer for type 784 - private_data=0x7f5023ed5e80
[2016/08/10 15:25:17.705345,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register)
  Registering messaging pointer for type 793 - private_data=0x7f5023eba7c0
[2016/08/10 15:25:17.705743, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:169(set_conn_connectpath)
  set_conn_connectpath: service v1, connectpath = /export/v1
[2016/08/10 15:25:17.706204,  5, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:729(make_connection_snum)
  cmd=/var/lib/zadara/scripts/vc/samba/zadara_smb_preexec.sh "nobody" "v1" "vm86_win8_1" "160.60.2.86"
[2016/08/10 15:25:17.840756, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:237(user_ok_token)
  user_ok_token: share v1 is ok for unix user nobody
[2016/08/10 15:25:17.841315, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:284(is_share_read_only_for_token)
  is_share_read_only_for_user: share v1 is read-write for unix user nobody
[2016/08/10 15:25:17.841830, 10, pid=17743, 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
[2016/08/10 15:25:17.842470,  4, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
  setting sec ctx (65534, 65534) - sec_ctx_stack_ndx = 0
[2016/08/10 15:25:17.842850,  5, pid=17743, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:63(security_token_debug)
  Security token SIDs (7):
    SID[  0]: S-1-5-21-1329707852-3482275279-3224653934-501
    SID[  1]: S-1-5-21-1329707852-3482275279-3224653934-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
   Privileges (0x               0):
   Rights (0x               0):
[2016/08/10 15:25:17.845100,  5, pid=17743, 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 1 supplementary groups
  Group[  0]: 65534
[2016/08/10 15:25:17.845428,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:363(change_to_user_internal)
  Impersonated user: uid=(65534,65534), gid=(0,65534)
[2016/08/10 15:25:17.845525,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2016/08/10 15:25:17.845550,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
  Security token: (NULL)
[2016/08/10 15:25:17.845568,  5, pid=17743, 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
[2016/08/10 15:25:17.845603,  5, pid=17743, 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)
[2016/08/10 15:25:17.845642, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:169(set_conn_connectpath)
  set_conn_connectpath: service v1, connectpath = /export/v1
[2016/08/10 15:25:17.845848, 10, pid=17743, effective(0, 0), real(0, 0), class=vfs] ../source3/modules/vfs_default.c:164(vfswrap_fs_capabilities)
  vfswrap_fs_capabilities: timestamp resolution of sec available on share v1, directory /export/v1
[2016/08/10 15:25:17.845874,  2, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:908(make_connection_snum)
  vm86_win8_1 (ipv4:160.60.2.86:57119) connect to service v1 initially as user nobody (uid=65534, gid=65534) (pid 17743)
[2016/08/10 15:25:17.845923,  5, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 1 for /var/lock/samba/smbXsrv_tcon_global.tdb
[2016/08/10 15:25:17.845947, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.845975, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key B1BF41E1
[2016/08/10 15:25:17.846011, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ed79e0
[2016/08/10 15:25:17.846058, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:673(smbXsrv_tcon_global_store)
[2016/08/10 15:25:17.846653, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:675(smbXsrv_tcon_global_store)
  smbXsrv_tcon_global_store: key 'B1BF41E1' stored
[2016/08/10 15:25:17.847165,  1, pid=17743, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(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           : 0xb1bf41e1 (2982101473)
                  tcon_wire_id             : 0xb1bf41e1 (2982101473)
                  server_id: struct server_id
                      pid                      : 0x000000000000454f (17743)
                      task_id                  : 0x00000000 (0)
                      vnn                      : 0xffffffff (4294967295)
                      unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                  creation_time            : Wed Aug 10 15:25:18 2016 IDT
                  share_name               : 'v1'
                  encryption_required      : 0x00 (0)
                  session_global_id        : 0xa75ca4ae (2807866542)
[2016/08/10 15:25:17.847840, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key B1BF41E1
[2016/08/10 15:25:17.847870,  5, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 1 for /var/lock/samba/smbXsrv_tcon_global.tdb
[2016/08/10 15:25:17.847890, 10, pid=17743, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.847912, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:851(smbXsrv_tcon_update)
[2016/08/10 15:25:17.847924, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:859(smbXsrv_tcon_update)
  smbXsrv_tcon_update: global_id (0xb1bf41e1) stored
[2016/08/10 15:25:17.847942,  1, pid=17743, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(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                 : 0xb1bf41e1 (2982101473)
                  global                   : *
                      global: struct smbXsrv_tcon_global0
                          db_rec                   : NULL
                          tcon_global_id           : 0xb1bf41e1 (2982101473)
                          tcon_wire_id             : 0xb1bf41e1 (2982101473)
                          server_id: struct server_id
                              pid                      : 0x000000000000454f (17743)
                              task_id                  : 0x00000000 (0)
                              vnn                      : 0xffffffff (4294967295)
                              unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                          creation_time            : Wed Aug 10 15:25:18 2016 IDT
                          share_name               : 'v1'
                          encryption_required      : 0x00 (0)
                          session_global_id        : 0xa75ca4ae (2807866542)
                  status                   : NT_STATUS_OK
                  idle_time                : Wed Aug 10 15:25:18 2016 IDT
                  compat                   : *
                  encryption_desired       : 0x00 (0)
[2016/08/10 15:25:17.848264, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2617(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:162
[2016/08/10 15:25:17.848315, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:911(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/4/31
[2016/08/10 15:25:17.851541, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3506(smbd_smb2_io_handler)
  smbd_smb2_request idx[1] of 5 vectors
[2016/08/10 15:25:17.851946, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:659(smb2_validate_sequence_number)
  smb2_validate_sequence_number: clearing id 4 (position 4) from bitmap
[2016/08/10 15:25:17.852402, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1967(smbd_smb2_request_dispatch)
  smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 4
[2016/08/10 15:25:17.852836,  4, pid=17743, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
  setting sec ctx (65534, 65534) - sec_ctx_stack_ndx = 0
[2016/08/10 15:25:17.852881,  5, pid=17743, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:63(security_token_debug)
  Security token SIDs (7):
    SID[  0]: S-1-5-21-1329707852-3482275279-3224653934-501
    SID[  1]: S-1-5-21-1329707852-3482275279-3224653934-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
   Privileges (0x               0):
   Rights (0x               0):
[2016/08/10 15:25:17.853032,  5, pid=17743, 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 1 supplementary groups
  Group[  0]: 65534
[2016/08/10 15:25:17.853276,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:363(change_to_user_internal)
  Impersonated user: uid=(65534,65534), gid=(0,65534)
[2016/08/10 15:25:17.853528,  4, pid=17743, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:858(vfs_ChDir)
  vfs_ChDir to /export/v1
[2016/08/10 15:25:17.853654,  4, pid=17743, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:869(vfs_ChDir)
  vfs_ChDir got /export/v1
[2016/08/10 15:25:17.853762, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:501(smbd_smb2_create_send)
  smbd_smb2_create: name[b4]
[2016/08/10 15:25:17.853794, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:917(smbd_smb2_create_send)
  smbd_smb2_create_send: open execution phase
[2016/08/10 15:25:17.853834,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:257(unix_convert)
  unix_convert called on file "b4"
[2016/08/10 15:25:17.853860, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/statcache.c:244(stat_cache_lookup)
  stat_cache_lookup: lookup failed for name [B4]
[2016/08/10 15:25:17.853883,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:449(unix_convert)
  unix_convert begin: name = b4, dirpath = , start = b4
[2016/08/10 15:25:17.853912,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/statcache.c:143(stat_cache_add)
  stat_cache_add: Added entry (7f5023ea5c20:size 2) B4 -> b4
[2016/08/10 15:25:17.853933,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:472(unix_convert)
  conversion of base_name finished b4 -> b4
[2016/08/10 15:25:17.853955,  3, pid=17743, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1174(check_reduced_name)
  check_reduced_name [b4] [/export/v1]
[2016/08/10 15:25:17.853979, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1234(check_reduced_name)
  check_reduced_name realpath [b4] -> [/export/v1/b4]
[2016/08/10 15:25:17.853999,  3, pid=17743, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1322(check_reduced_name)
  check_reduced_name: b4 reduced to /export/v1/b4
[2016/08/10 15:25:17.854027, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4983(create_file_default)
  create_file: access_mask = 0x120089 file_attributes = 0x80, share_access = 0x1, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x2 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = b4
[2016/08/10 15:25:17.854098, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4460(create_file_unixpath)
  create_file_unixpath: access_mask = 0x120089 file_attributes = 0x80, share_access = 0x1, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x2 private_flags = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = b4
[2016/08/10 15:25:17.854147,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb
[2016/08/10 15:25:17.854169, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/smbXsrv_open_global.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.854195, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key 516FD555
[2016/08/10 15:25:17.854229, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ecdc80
[2016/08/10 15:25:17.854251, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:584(smbXsrv_open_global_verify_record)
  smbXsrv_open_global_verify_record: empty value
[2016/08/10 15:25:17.854368, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:702(smbXsrv_open_global_store)
  smbXsrv_open_global_store: key '516FD555' stored
[2016/08/10 15:25:17.854400,  1, pid=17743, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:402(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                      : 0x000000000000454f (17743)
                      task_id                  : 0x00000000 (0)
                      vnn                      : 0xffffffff (4294967295)
                      unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                  open_global_id           : 0x516fd555 (1366283605)
                  open_persistent_id       : 0x00000000516fd555 (1366283605)
                  open_volatile_id         : 0x0000000084a67574 (2225501556)
                  open_owner               : S-1-5-21-1329707852-3482275279-3224653934-501
                  open_time                : Wed Aug 10 15:25:18 2016 IDT
                  create_guid              : 00000000-0000-0000-0000-000000000000
                  client_guid              : 0c2c5103-5d50-11e6-8281-ddb2814ec729
                  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
[2016/08/10 15:25:17.854662, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key 516FD555
[2016/08/10 15:25:17.854708,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb
[2016/08/10 15:25:17.854730, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.854753, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:876(smbXsrv_open_create)
  smbXsrv_open_create: global_id (0x516fd555) stored
[2016/08/10 15:25:17.854771,  1, pid=17743, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:402(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                 : 0x84a67574 (2225501556)
                  global                   : *
                      global: struct smbXsrv_open_global0
                          db_rec                   : NULL
                          server_id: struct server_id
                              pid                      : 0x000000000000454f (17743)
                              task_id                  : 0x00000000 (0)
                              vnn                      : 0xffffffff (4294967295)
                              unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                          open_global_id           : 0x516fd555 (1366283605)
                          open_persistent_id       : 0x00000000516fd555 (1366283605)
                          open_volatile_id         : 0x0000000084a67574 (2225501556)
                          open_owner               : S-1-5-21-1329707852-3482275279-3224653934-501
                          open_time                : Wed Aug 10 15:25:18 2016 IDT
                          create_guid              : 00000000-0000-0000-0000-000000000000
                          client_guid              : 0c2c5103-5d50-11e6-8281-ddb2814ec729
                          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
                  status                   : NT_STATUS_OK
                  idle_time                : Wed Aug 10 15:25:18 2016 IDT
                  compat                   : NULL
[2016/08/10 15:25:17.855163,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:129(file_new)
  allocated file structure fnum 2225501556 (1 used)
[2016/08/10 15:25:17.855192, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:744(file_name_hash)
  file_name_hash: /export/v1/b4 hash 0x32352ca5
[2016/08/10 15:25:17.855222,  3, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:196(unix_mode)
  unix_mode(b4) returning 0744
[2016/08/10 15:25:17.855242, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2478(open_file_ntcreate)
  open_file_ntcreate: fname=b4, dos_attrs=0x80 access_mask=0x120089 share_access=0x1 create_disposition = 0x3 create_options=0x40 unix mode=0744 oplock_request=2 private_flags = 0x0
[2016/08/10 15:25:17.855267,  8, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:600(dos_mode)
  dos_mode: b4
[2016/08/10 15:25:17.855287,  8, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:242(dos_mode_from_sbuf)
  dos_mode_from_sbuf returning a
[2016/08/10 15:25:17.855309,  8, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:36(dos_mode_debug_print)
  dos_mode returning a
[2016/08/10 15:25:17.855331, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2636(open_file_ntcreate)
  open_file_ntcreate: fname=b4, after mapping access_mask=0x120089
[2016/08/10 15:25:17.855351,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2726(open_file_ntcreate)
  calling open_file with flags=0x0 flags2=0x40 mode=0744, access_mask = 0x120089, open_access_mask = 0x120089
[2016/08/10 15:25:17.855379, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:3558(posix_get_nt_acl)
  posix_get_nt_acl: called for file b4
[2016/08/10 15:25:17.855538, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1237(uid_to_sid)
  uid 65534 -> sid S-1-5-21-1329707852-3482275279-3224653934-501
[2016/08/10 15:25:17.855626,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1278(gid_to_sid)
  gid_to_sid: winbind failed to find a sid for gid 65534
[2016/08/10 15:25:17.855653,  4, pid=17743, 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
[2016/08/10 15:25:17.855694,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
  push_conn_ctx(2807866542) : conn_ctx_stack_ndx = 0
[2016/08/10 15:25:17.855716,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/08/10 15:25:17.855734,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
  Security token: (NULL)
[2016/08/10 15:25:17.855752,  5, pid=17743, 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
[2016/08/10 15:25:17.855826,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx)
  pop_sec_ctx (65534, 65534) - sec_ctx_stack_ndx = 0
[2016/08/10 15:25:17.855852, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1141(legacy_gid_to_sid)
  LEGACY: gid 65534 -> sid S-1-22-2-65534
[2016/08/10 15:25:17.855883, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2724(canonicalise_acl)
  canonicalise_acl: Access ace entries before arrange :
[2016/08/10 15:25:17.855901, 10, pid=17743, 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 r--
[2016/08/10 15:25:17.855928, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
  canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nogroup) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r--
[2016/08/10 15:25:17.857619, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
  canon_ace index 2. Type = allow SID = S-1-5-21-1329707852-3482275279-3224653934-501 uid 65534 (nobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
[2016/08/10 15:25:17.858474, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:848(print_canon_ace_list)
  print_canon_ace_list: canonicalise_acl: ace entries after arrange
  canon_ace index 0. Type = allow SID = S-1-5-21-1329707852-3482275279-3224653934-501 uid 65534 (nobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
  canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nogroup) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r--
  canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r--
[2016/08/10 15:25:17.860147, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1e01ff
[2016/08/10 15:25:17.860502, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
  map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089
[2016/08/10 15:25:17.860911, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
  map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089
[2016/08/10 15:25:17.861360, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:174(smbd_check_access_rights)
  smbd_check_access_rights: file b4 requesting 0x120089 returning 0x120009 (NT_STATUS_OK)
[2016/08/10 15:25:17.861777, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:408(fd_open)
  fd_open: name b4, flags = 00 mode = 0744, fd = 40. 
[2016/08/10 15:25:17.862182,  2, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1005(open_file)
  nobody opened file b4 read=Yes write=No (numopen=1)
[2016/08/10 15:25:17.862537,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 1 for /var/lock/samba/locking.tdb
[2016/08/10 15:25:17.862909, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.863307, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key 1BFD0000000000009000
[2016/08/10 15:25:17.863729, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ec69a0
[2016/08/10 15:25:17.863979, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:167(parse_share_modes)
  parse_share_modes:
[2016/08/10 15:25:17.864098,  1, pid=17743, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug)
       d: struct share_mode_data
          servicepath              : *
              servicepath              : '/export/v1'
          base_name                : *
              base_name                : 'b4'
          stream_name              : NULL
          num_share_modes          : 0x00000001 (1)
          share_modes: ARRAY(1)
              share_modes: struct share_mode_entry
                  pid: struct server_id
                      pid                      : 0x0000000000004515 (17685)
                      task_id                  : 0x00000000 (0)
                      vnn                      : 0xffffffff (4294967295)
                      unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
                  op_mid                   : 0x0000000000000004 (4)
                  op_type                  : 0x0003 (3)
                  lease_idx                : 0xffffffff (4294967295)
                  access_mask              : 0x0012019f (1180063)
                  share_access             : 0x00000000 (0)
                  private_options          : 0x00000000 (0)
                  time                     : Wed Aug 10 15:25:12 2016 IDT.55672
                  id: struct file_id
                      devid                    : 0x000000000000fd1b (64795)
                      inode                    : 0x0000000000000090 (144)
                      extid                    : 0x0000000000000000 (0)
                  share_file_id            : 0x0000000095c51b11 (2512722705)
                  uid                      : 0x0000fffe (65534)
                  flags                    : 0x0000 (0)
                  name_hash                : 0x32352ca5 (842345637)
                  stale                    : 0x00 (0)
                  lease                    : NULL
          num_leases               : 0x00000000 (0)
          leases: ARRAY(0)
          num_delete_tokens        : 0x00000000 (0)
          delete_tokens: ARRAY(0)
          old_write_time           : Wed Aug 10 15:25:12 2016 IDT.60507505
          changed_write_time       : Thu Jan  1 02:00:00 1970 IST.0
          fresh                    : 0x00 (0)
          modified                 : 0x00 (0)
          record                   : NULL
[2016/08/10 15:25:17.864532, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:749(share_mode_stale_pid)
  PID 17685 (index 0 out of 1) still exists
[2016/08/10 15:25:17.864571, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:749(share_mode_stale_pid)
  PID 17685 (index 0 out of 1) still exists
[2016/08/10 15:25:17.864609, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:1220(find_delete_on_close_token)
  find_delete_on_close_token: name_hash = 0x32352ca5
[2016/08/10 15:25:17.864630, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1025(share_conflict)
  share_conflict: entry->access_mask = 0x12019f, entry->share_access = 0x0, entry->private_options = 0x0
[2016/08/10 15:25:17.864651, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1036(share_conflict)
  share_conflict: access_mask = 0x120089, share_access = 0x1
[2016/08/10 15:25:17.864669, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1085(share_conflict)
  share_conflict: [1] am (0x12019f) & right (0x6) = 0x6
[2016/08/10 15:25:17.864705, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1085(share_conflict)
  share_conflict: [1] sa (0x1) & share (0x2) = 0x0
[2016/08/10 15:25:17.864725, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1085(share_conflict)
  share_conflict: check 1 conflict am = 0x12019f, right = 0x6, sa = 0x1, share = 0x2
[2016/08/10 15:25:17.864757, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:749(share_mode_stale_pid)
  PID 17685 (index 0 out of 1) still exists
[2016/08/10 15:25:17.864780, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1442(delay_for_oplock)
  entry 0: e_lease_type 7, will_overwrite: 0
[2016/08/10 15:25:17.864808, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:749(share_mode_stale_pid)
  PID 17685 (index 0 out of 1) still exists
[2016/08/10 15:25:17.864829, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1484(delay_for_oplock)
  breaking from 7 to 1
[2016/08/10 15:25:17.864847, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1256(send_break_message)
  Sending break request to PID 17685
[2016/08/10 15:25:17.864872,  4, pid=17743, 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
[2016/08/10 15:25:17.864899,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
  push_conn_ctx(2807866542) : conn_ctx_stack_ndx = 0
[2016/08/10 15:25:17.864918,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/08/10 15:25:17.864937,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
  Security token: (NULL)
[2016/08/10 15:25:17.864954,  5, pid=17743, 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
[2016/08/10 15:25:17.865484, 10, pid=17743, effective(0, 0), real(0, 0)] ../source3/lib/messages_dgm.c:325(messaging_dgm_send)
  messaging_dgm_send: Sending message to 17685
[2016/08/10 15:25:17.867735,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx)
  pop_sec_ctx (65534, 65534) - sec_ctx_stack_ndx = 0
[2016/08/10 15:25:17.869295, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1910(defer_open)
  defer_open_sharing_error: time [1470831917.854133] adding deferred open entry for mid 4
[2016/08/10 15:25:17.869327, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1933(defer_open)
  defering mid 4
[2016/08/10 15:25:17.869367,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 3 for /var/lock/samba/dbwrap_watchers.tdb
[2016/08/10 15:25:17.869390, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:/var/lock/samba/dbwrap_watchers.tdb
[2016/08/10 15:25:17.869430, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key 10000000130000000000
[2016/08/10 15:25:17.869462, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ecf560
[2016/08/10 15:25:17.869560, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key 10000000130000000000
[2016/08/10 15:25:17.869589,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 3 for /var/lock/samba/dbwrap_watchers.tdb
[2016/08/10 15:25:17.869608, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.869637, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1618(push_deferred_open_message_smb2)
  push_deferred_open_message_smb2: timeout at 2016/08/10 15:26:17.854133
[2016/08/10 15:25:17.869671, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key 1BFD0000000000009000

  
  
[2016/08/10 15:25:17.873264,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 1 for /var/lock/samba/locking.tdb
[2016/08/10 15:25:17.873638, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.874026, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/posix.c:492(delete_windows_lock_ref_count)
  delete_windows_lock_ref_count for file b4
[2016/08/10 15:25:17.874440,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb
[2016/08/10 15:25:17.874687, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/smbXsrv_open_global.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.874743, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key 516FD555
[2016/08/10 15:25:17.874776, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ecb5c0
[2016/08/10 15:25:17.874812, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key 516FD555
[2016/08/10 15:25:17.874835,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb
[2016/08/10 15:25:17.874855, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.874886,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:555(file_free)
  freed files structure 2225501556 (0 used)
[2016/08/10 15:25:17.874906, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4804(create_file_unixpath)
  create_file_unixpath: NT_STATUS_SHARING_VIOLATION
[2016/08/10 15:25:17.874925, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5080(create_file_default)
  create_file: NT_STATUS_SHARING_VIOLATION
[2016/08/10 15:25:17.874945, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1427(open_was_deferred_smb2)
  open_was_deferred_smb2: mid = 4
  smbd_smb2_request_pending_queue: req->current_idx = 1
  	req->in.vector[0].iov_len = 0
  	req->in.vector[1].iov_len = 0
  	req->in.vector[2].iov_len = 64
  	req->in.vector[3].iov_len = 56
  	req->in.vector[4].iov_len = 112
  	req->out.vector[0].iov_len = 4
  	req->out.vector[1].iov_len = 0
  	req->out.vector[2].iov_len = 64
  	req->out.vector[3].iov_len = 8
  	req->out.vector[4].iov_len = 0
	
[2016/08/10 15:25:17.875106, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/lib/messages.c:252(messaging_recv_cb)
  messaging_recv_cb: Received message 0xfa3 len 44 (num_fds:0) from 17685
[2016/08/10 15:25:17.875164,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 3 for /var/lock/samba/dbwrap_watchers.tdb
[2016/08/10 15:25:17.875187, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:/var/lock/samba/dbwrap_watchers.tdb
[2016/08/10 15:25:17.875212, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key 10000000130000000000
[2016/08/10 15:25:17.875240, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ec4ca0
[2016/08/10 15:25:17.875277, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key 10000000130000000000
[2016/08/10 15:25:17.875300,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 3 for /var/lock/samba/dbwrap_watchers.tdb
[2016/08/10 15:25:17.875319, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.875340, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1975(defer_open_done)
  scheduling mid 4
[2016/08/10 15:25:17.875361, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1546(schedule_deferred_open_message_smb2)
  schedule_deferred_open_message_smb2: re-processing mid 4
[2016/08/10 15:25:17.875386, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1487(smbd_smb2_create_request_dispatch_immediate)
  smbd_smb2_create_request_dispatch_immediate: re-dispatching mid 4
[2016/08/10 15:25:17.875405, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1967(smbd_smb2_request_dispatch)
  smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 4
[2016/08/10 15:25:17.875429,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
  Skipping user change - already user
[2016/08/10 15:25:17.883919, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:510(smbd_smb2_create_send)
  smbd_smb2_create_send: reentrant for file b4
[2016/08/10 15:25:17.884011, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:917(smbd_smb2_create_send)
  smbd_smb2_create_send: open execution phase
[2016/08/10 15:25:17.884051,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:257(unix_convert)
  unix_convert called on file "b4"
[2016/08/10 15:25:17.884108, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/statcache.c:283(stat_cache_lookup)
  stat_cache_lookup: lookup succeeded for name [B4] -> [b4]
[2016/08/10 15:25:17.884139,  3, pid=17743, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1174(check_reduced_name)
  check_reduced_name [b4] [/export/v1]
[2016/08/10 15:25:17.884166, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1234(check_reduced_name)
  check_reduced_name realpath [b4] -> [/export/v1/b4]
[2016/08/10 15:25:17.884186,  3, pid=17743, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1322(check_reduced_name)
  check_reduced_name: b4 reduced to /export/v1/b4
[2016/08/10 15:25:17.884206, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4983(create_file_default)
  create_file: access_mask = 0x120089 file_attributes = 0x80, share_access = 0x1, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x2 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = b4
[2016/08/10 15:25:17.884232, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4460(create_file_unixpath)
  create_file_unixpath: access_mask = 0x120089 file_attributes = 0x80, share_access = 0x1, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x2 private_flags = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = b4
[2016/08/10 15:25:17.884271,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb
[2016/08/10 15:25:17.884292, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/smbXsrv_open_global.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.884318, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key 1D2A8A29
[2016/08/10 15:25:17.884348, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ece600
[2016/08/10 15:25:17.884368, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:584(smbXsrv_open_global_verify_record)
  smbXsrv_open_global_verify_record: empty value
[2016/08/10 15:25:17.884430, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:702(smbXsrv_open_global_store)
  smbXsrv_open_global_store: key '1D2A8A29' stored
[2016/08/10 15:25:17.884459,  1, pid=17743, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:402(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                      : 0x000000000000454f (17743)
                      task_id                  : 0x00000000 (0)
                      vnn                      : 0xffffffff (4294967295)
                      unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                  open_global_id           : 0x1d2a8a29 (489327145)
                  open_persistent_id       : 0x000000001d2a8a29 (489327145)
                  open_volatile_id         : 0x0000000008f3f0ce (150204622)
                  open_owner               : S-1-5-21-1329707852-3482275279-3224653934-501
                  open_time                : Wed Aug 10 15:25:18 2016 IDT
                  create_guid              : 00000000-0000-0000-0000-000000000000
                  client_guid              : 0c2c5103-5d50-11e6-8281-ddb2814ec729
                  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
[2016/08/10 15:25:17.884753, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key 1D2A8A29
[2016/08/10 15:25:17.884779,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb
[2016/08/10 15:25:17.884799, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.884822, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:876(smbXsrv_open_create)
  smbXsrv_open_create: global_id (0x1d2a8a29) stored
[2016/08/10 15:25:17.884840,  1, pid=17743, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:402(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                 : 0x08f3f0ce (150204622)
                  global                   : *
                      global: struct smbXsrv_open_global0
                          db_rec                   : NULL
                          server_id: struct server_id
                              pid                      : 0x000000000000454f (17743)
                              task_id                  : 0x00000000 (0)
                              vnn                      : 0xffffffff (4294967295)
                              unique_id                : 0x632dd43d5a3747be (7146601543678511038)
                          open_global_id           : 0x1d2a8a29 (489327145)
                          open_persistent_id       : 0x000000001d2a8a29 (489327145)
                          open_volatile_id         : 0x0000000008f3f0ce (150204622)
                          open_owner               : S-1-5-21-1329707852-3482275279-3224653934-501
                          open_time                : Wed Aug 10 15:25:18 2016 IDT
                          create_guid              : 00000000-0000-0000-0000-000000000000
                          client_guid              : 0c2c5103-5d50-11e6-8281-ddb2814ec729
                          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
                  status                   : NT_STATUS_OK
                  idle_time                : Wed Aug 10 15:25:18 2016 IDT
                  compat                   : NULL
[2016/08/10 15:25:17.885224,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:129(file_new)
  allocated file structure fnum 150204622 (1 used)
[2016/08/10 15:25:17.885252, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:744(file_name_hash)
  file_name_hash: /export/v1/b4 hash 0x32352ca5
[2016/08/10 15:25:17.885277,  3, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:196(unix_mode)
  unix_mode(b4) returning 0744
[2016/08/10 15:25:17.885296, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2478(open_file_ntcreate)
  open_file_ntcreate: fname=b4, dos_attrs=0x80 access_mask=0x120089 share_access=0x1 create_disposition = 0x3 create_options=0x40 unix mode=0744 oplock_request=2 private_flags = 0x0
[2016/08/10 15:25:17.885322, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1451(remove_deferred_open_message_smb2_internal)
  remove_deferred_open_message_smb2_internal: mid 4
[2016/08/10 15:25:17.885341,  8, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:600(dos_mode)
  dos_mode: b4
[2016/08/10 15:25:17.885361,  8, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:242(dos_mode_from_sbuf)
  dos_mode_from_sbuf returning a
[2016/08/10 15:25:17.885381,  8, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:36(dos_mode_debug_print)
  dos_mode returning a
[2016/08/10 15:25:17.885402, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2636(open_file_ntcreate)
  open_file_ntcreate: fname=b4, after mapping access_mask=0x120089
[2016/08/10 15:25:17.885422,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2726(open_file_ntcreate)
  calling open_file with flags=0x0 flags2=0x40 mode=0744, access_mask = 0x120089, open_access_mask = 0x120089
[2016/08/10 15:25:17.885445, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:3558(posix_get_nt_acl)
  posix_get_nt_acl: called for file b4
[2016/08/10 15:25:17.885494, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1237(uid_to_sid)
  uid 65534 -> sid S-1-5-21-1329707852-3482275279-3224653934-501
[2016/08/10 15:25:17.886224,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1278(gid_to_sid)
  gid_to_sid: winbind failed to find a sid for gid 65534
[2016/08/10 15:25:17.886618,  4, pid=17743, 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
[2016/08/10 15:25:17.886977,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
  push_conn_ctx(2807866542) : conn_ctx_stack_ndx = 0
[2016/08/10 15:25:17.887223,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/08/10 15:25:17.887252,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
  Security token: (NULL)
[2016/08/10 15:25:17.887270,  5, pid=17743, 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
[2016/08/10 15:25:17.887334,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx)
  pop_sec_ctx (65534, 65534) - sec_ctx_stack_ndx = 0
[2016/08/10 15:25:17.887359, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1141(legacy_gid_to_sid)
  LEGACY: gid 65534 -> sid S-1-22-2-65534
[2016/08/10 15:25:17.887403, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2724(canonicalise_acl)
  canonicalise_acl: Access ace entries before arrange :
[2016/08/10 15:25:17.887423, 10, pid=17743, 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 r--
[2016/08/10 15:25:17.887450, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
  canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nogroup) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r--
[2016/08/10 15:25:17.888267, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
  canon_ace index 2. Type = allow SID = S-1-5-21-1329707852-3482275279-3224653934-501 uid 65534 (nobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
[2016/08/10 15:25:17.888946, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:848(print_canon_ace_list)
  print_canon_ace_list: canonicalise_acl: ace entries after arrange
  canon_ace index 0. Type = allow SID = S-1-5-21-1329707852-3482275279-3224653934-501 uid 65534 (nobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
  canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nogroup) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r--
  canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r--
[2016/08/10 15:25:17.890532, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1e01ff
[2016/08/10 15:25:17.890575, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
  map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089
[2016/08/10 15:25:17.890595, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
  map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089
[2016/08/10 15:25:17.890698, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:174(smbd_check_access_rights)
  smbd_check_access_rights: file b4 requesting 0x120089 returning 0x120009 (NT_STATUS_OK)
[2016/08/10 15:25:17.890744, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:408(fd_open)
  fd_open: name b4, flags = 00 mode = 0744, fd = 40. 
[2016/08/10 15:25:17.890771,  2, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1005(open_file)
  nobody opened file b4 read=Yes write=No (numopen=1)
[2016/08/10 15:25:17.890795,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 1 for /var/lock/samba/locking.tdb
[2016/08/10 15:25:17.890814, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/locking.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.890842, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key 1BFD0000000000009000
[2016/08/10 15:25:17.890881, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ec6930
[2016/08/10 15:25:17.890931, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:167(parse_share_modes)
  parse_share_modes:
[2016/08/10 15:25:17.890953,  1, pid=17743, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug)
       d: struct share_mode_data
          servicepath              : *
              servicepath              : '/export/v1'
          base_name                : *
              base_name                : 'b4'
          stream_name              : NULL
          num_share_modes          : 0x00000001 (1)
          share_modes: ARRAY(1)
              share_modes: struct share_mode_entry
                  pid: struct server_id
                      pid                      : 0x0000000000004515 (17685)
                      task_id                  : 0x00000000 (0)
                      vnn                      : 0xffffffff (4294967295)
                      unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
                  op_mid                   : 0x0000000000000004 (4)
                  op_type                  : 0x0000 (0)
                  lease_idx                : 0xffffffff (4294967295)
                  access_mask              : 0x0012019f (1180063)
                  share_access             : 0x00000000 (0)
                  private_options          : 0x00000000 (0)
                  time                     : Wed Aug 10 15:25:12 2016 IDT.55672
                  id: struct file_id
                      devid                    : 0x000000000000fd1b (64795)
                      inode                    : 0x0000000000000090 (144)
                      extid                    : 0x0000000000000000 (0)
                  share_file_id            : 0x0000000095c51b11 (2512722705)
                  uid                      : 0x0000fffe (65534)
                  flags                    : 0x0000 (0)
                  name_hash                : 0x32352ca5 (842345637)
                  stale                    : 0x00 (0)
                  lease                    : NULL
          num_leases               : 0x00000000 (0)
          leases: ARRAY(0)
          num_delete_tokens        : 0x00000000 (0)
          delete_tokens: ARRAY(0)
          old_write_time           : Wed Aug 10 15:25:12 2016 IDT.60507505
          changed_write_time       : Thu Jan  1 02:00:00 1970 IST.0
          fresh                    : 0x00 (0)
          modified                 : 0x00 (0)
          record                   : NULL
[2016/08/10 15:25:17.892235, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:1220(find_delete_on_close_token)
  find_delete_on_close_token: name_hash = 0x32352ca5

[2016/08/10 15:25:17.892258, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1025(share_conflict)
  share_conflict: entry->access_mask = 0x12019f, entry->share_access = 0x0, entry->private_options = 0x0
[2016/08/10 15:25:17.892280, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1036(share_conflict)
  share_conflict: access_mask = 0x120089, share_access = 0x1
[2016/08/10 15:25:17.892298, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1085(share_conflict)
  share_conflict: [1] am (0x12019f) & right (0x6) = 0x6
[2016/08/10 15:25:17.892316, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1085(share_conflict)
  share_conflict: [1] sa (0x1) & share (0x2) = 0x0
[2016/08/10 15:25:17.892334, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1085(share_conflict)
  share_conflict: check 1 conflict am = 0x12019f, right = 0x6, sa = 0x1, share = 0x2
[2016/08/10 15:25:17.892376, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/locking.c:749(share_mode_stale_pid)
  PID 17685 (index 0 out of 1) still exists
  
[2016/08/10 15:25:17.892402, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1442(delay_for_oplock)
  entry 0: e_lease_type 0, will_overwrite: 0
[2016/08/10 15:25:17.892425, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:3558(posix_get_nt_acl)
  posix_get_nt_acl: called for file b4
[2016/08/10 15:25:17.892474, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1237(uid_to_sid)
  uid 65534 -> sid S-1-5-21-1329707852-3482275279-3224653934-501
[2016/08/10 15:25:17.892934,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1278(gid_to_sid)
  gid_to_sid: winbind failed to find a sid for gid 65534
[2016/08/10 15:25:17.893344,  4, pid=17743, 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
[2016/08/10 15:25:17.893699,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
  push_conn_ctx(2807866542) : conn_ctx_stack_ndx = 0
[2016/08/10 15:25:17.893740,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2016/08/10 15:25:17.893802,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
  Security token: (NULL)
[2016/08/10 15:25:17.893835,  5, pid=17743, 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
[2016/08/10 15:25:17.893901,  4, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx)
  pop_sec_ctx (65534, 65534) - sec_ctx_stack_ndx = 0
[2016/08/10 15:25:17.893926, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1141(legacy_gid_to_sid)
  LEGACY: gid 65534 -> sid S-1-22-2-65534
[2016/08/10 15:25:17.893956, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2724(canonicalise_acl)
  canonicalise_acl: Access ace entries before arrange :
[2016/08/10 15:25:17.893976, 10, pid=17743, 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 r--
[2016/08/10 15:25:17.894002, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
  canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nogroup) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r--
[2016/08/10 15:25:17.894899, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
  canon_ace index 2. Type = allow SID = S-1-5-21-1329707852-3482275279-3224653934-501 uid 65534 (nobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
[2016/08/10 15:25:17.895655, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:848(print_canon_ace_list)
  print_canon_ace_list: canonicalise_acl: ace entries after arrange
  canon_ace index 0. Type = allow SID = S-1-5-21-1329707852-3482275279-3224653934-501 uid 65534 (nobody) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
  canon_ace index 1. Type = allow SID = S-1-22-2-65534 gid 65534 (nogroup) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms r--
  canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r--
[2016/08/10 15:25:17.897301, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1e01ff
[2016/08/10 15:25:17.897529, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
  map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089
[2016/08/10 15:25:17.897558, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
  map_canon_ace_perms: Mapped (UNIX) 100 to (NT) 120089
[2016/08/10 15:25:17.897627, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:174(smbd_check_access_rights)
  smbd_check_access_rights: file b4 requesting 0x1 returning 0x1 (NT_STATUS_OK)
[2016/08/10 15:25:17.897663, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key 1BFD0000000000009000
[2016/08/10 15:25:17.897722,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 1 for /var/lock/samba/locking.tdb
[2016/08/10 15:25:17.897746, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.897777, 10, pid=17743, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/posix.c:492(delete_windows_lock_ref_count)
  delete_windows_lock_ref_count for file b4
[2016/08/10 15:25:17.897806,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
  check lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb
[2016/08/10 15:25:17.897827, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:/var/lock/samba/smbXsrv_open_global.tdb 2:<none> 3:<none>
[2016/08/10 15:25:17.897850, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Locking key 1D2A8A29
[2016/08/10 15:25:17.897878, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
  Allocated locked data 0x0x7f5023ecfd50
[2016/08/10 15:25:17.897914, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
  Unlocking key 1D2A8A29
[2016/08/10 15:25:17.897936,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 1 for /var/lock/samba/smbXsrv_open_global.tdb
[2016/08/10 15:25:17.897955, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
  lock order:  1:<none> 2:<none> 3:<none>
[2016/08/10 15:25:17.897983,  5, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:555(file_free)
  freed files structure 150204622 (0 used)
[2016/08/10 15:25:17.898002, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4804(create_file_unixpath)
  create_file_unixpath: NT_STATUS_SHARING_VIOLATION
[2016/08/10 15:25:17.898021, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5080(create_file_default)
  create_file: NT_STATUS_SHARING_VIOLATION
[2016/08/10 15:25:17.898048, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2733(smbd_smb2_request_error_ex)
  smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_SHARING_VIOLATION] || at ../source3/smbd/smb2_create.c:293
[2016/08/10 15:25:17.898563, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2617(smbd_smb2_request_done_ex)
  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_SHARING_VIOLATION] body[8] dyn[yes:1] at ../source3/smbd/smb2_server.c:2788
[2016/08/10 15:25:17.899146, 10, pid=17743, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:911(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