Attachment 12353 Details for Bug 12139 – Client-1 log

Client-1 log

vm80-win2012r2.log (text/plain), 101.75 KB, created by Lev on 2016-08-10 14:44:41 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Lev

Created: 2016-08-10 14:44:41 UTC

Size: 101.75 KB

patch

obsolete

>[2016/08/10 15:25:11.938923,  5, pid=17685, 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:11.939284, 10, pid=17685, 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:11.939590, 10, pid=17685, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Locking key B9846B52
>[2016/08/10 15:25:11.939905, 10, pid=17685, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f5023ec73e0
>[2016/08/10 15:25:11.940377, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:882(smbXsrv_session_global_store)
>[2016/08/10 15:25:11.940517, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:884(smbXsrv_session_global_store)
>  smbXsrv_session_global_store: key 'B9846B52' stored
>[2016/08/10 15:25:11.940921,  1, pid=17685, 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        : 0xb9846b52 (3112463186)
>                  session_wire_id          : 0x00000000b9846b52 (3112463186)
>                  creation_time            : Wed Aug 10 15:25:12 2016 IDT
>                  expiration_time          : Thu Jan  1 02:00:00 1970 IST
>                  auth_time                : Wed Aug 10 15:25:12 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                      : 0x0000000000004515 (17685)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                          local_address            : 'ipv4:160.60.2.105:445'
>                          remote_address           : 'ipv4:160.60.2.80:51759'
>                          remote_name              : '160.60.2.80'
>                          auth_session_info_seqnum : 0x00000001 (1)
>                          connection               : *
>[2016/08/10 15:25:11.943271, 10, pid=17685, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Unlocking key B9846B52
>[2016/08/10 15:25:11.943296,  5, pid=17685, 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:11.943313, 10, pid=17685, 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:11.943330, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1330(smbXsrv_session_update)
>[2016/08/10 15:25:11.943339, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1338(smbXsrv_session_update)
>  smbXsrv_session_update: global_id (0xb9846b52) stored
>[2016/08/10 15:25:11.943353,  1, pid=17685, 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                 : 0xb9846b52 (3112463186)
>                  global                   : *
>                      global: struct smbXsrv_session_global0
>                          db_rec                   : NULL
>                          session_global_id        : 0xb9846b52 (3112463186)
>                          session_wire_id          : 0x00000000b9846b52 (3112463186)
>                          creation_time            : Wed Aug 10 15:25:12 2016 IDT
>                          expiration_time          : Thu Jan  1 02:00:00 1970 IST
>                          auth_time                : Wed Aug 10 15:25:12 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                      : 0x0000000000004515 (17685)
>                                      task_id                  : 0x00000000 (0)
>                                      vnn                      : 0xffffffff (4294967295)
>                                      unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                                  local_address            : 'ipv4:160.60.2.105:445'
>                                  remote_address           : 'ipv4:160.60.2.80:51759'
>                                  remote_name              : '160.60.2.80'
>                                  auth_session_info_seqnum : 0x00000001 (1)
>                                  connection               : *
>                  status                   : NT_STATUS_OK
>                  idle_time                : Wed Aug 10 15:25:12 2016 IDT
>                  nonce_high               : 0x770128038952c7e1 (8575179161144051681)
>                  nonce_low                : 0x0000000000000001 (1)
>                  gensec                   : *
>                  compat                   : *
>                  tcon_table               : *
>                  encryption_desired       : 0x00 (0)
>[2016/08/10 15:25:11.944526, 10, pid=17685, 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:11.944565, 10, pid=17685, 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:11.945615, 10, pid=17685, 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:11.945983, 10, pid=17685, 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:11.946283, 10, pid=17685, 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:11.946568,  4, pid=17685, 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:11.946847,  5, pid=17685, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:11.947133,  5, pid=17685, 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:11.947591,  5, pid=17685, 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:11.948184, 10, pid=17685, 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:11.948477,  7, pid=17685, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3998(lp_servicenumber)
>  lp_servicenumber: couldn't find v1
>[2016/08/10 15:25:11.948737,  5, pid=17685, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc)
>  Finding user v1
>[2016/08/10 15:25:11.949013,  5, pid=17685, 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:11.949670,  0, pid=17685, 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:11.950212,  5, pid=17685, 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:11.950763,  0, pid=17685, 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:11.951218,  5, pid=17685, 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:11.951389,  5, pid=17685, 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:11.951421,  3, pid=17685, 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:11.951442,  7, pid=17685, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3998(lp_servicenumber)
>  lp_servicenumber: couldn't find printers
>[2016/08/10 15:25:11.951458,  5, pid=17685, 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:11.951481, 10, pid=17685, 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:11.951501, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:440(pathtree_find)
>  pathtree_find: Exit
>[2016/08/10 15:25:11.951537,  7, pid=17685, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3998(lp_servicenumber)
>  lp_servicenumber: couldn't find printers
>[2016/08/10 15:25:11.951555,  5, pid=17685, 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:11.951575, 10, pid=17685, 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:11.951605, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:440(pathtree_find)
>  pathtree_find: Exit
>[2016/08/10 15:25:11.951647, 10, pid=17685, 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:11.951668, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/lib/adt_tree.c:440(pathtree_find)
>  pathtree_find: Exit
>[2016/08/10 15:25:11.952113,  2, pid=17685, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2610(lp_do_section)
>  Processing section "[v1]"
>[2016/08/10 15:25:11.952171,  8, pid=17685, 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:11.952189, 10, pid=17685, 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:11.952614,  5, pid=17685, 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:11.952635, 10, pid=17685, 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:11.952655, 10, pid=17685, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Locking key 86CF782C
>[2016/08/10 15:25:11.952681, 10, pid=17685, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f5023eda230
>[2016/08/10 15:25:11.952793, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:673(smbXsrv_tcon_global_store)
>[2016/08/10 15:25:11.952812, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:675(smbXsrv_tcon_global_store)
>  smbXsrv_tcon_global_store: key '86CF782C' stored
>[2016/08/10 15:25:11.952830,  1, pid=17685, 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           : 0x86cf782c (2261743660)
>                  tcon_wire_id             : 0x86cf782c (2261743660)
>                  server_id: struct server_id
>                      pid                      : 0x0000000000004515 (17685)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                  creation_time            : Wed Aug 10 15:25:12 2016 IDT
>                  share_name               : NULL
>                  encryption_required      : 0x00 (0)
>                  session_global_id        : 0x00000000 (0)
>[2016/08/10 15:25:11.952981, 10, pid=17685, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Unlocking key 86CF782C
>[2016/08/10 15:25:11.953000,  5, pid=17685, 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:11.953027, 10, pid=17685, 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:11.953045, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:798(smbXsrv_tcon_create)
>[2016/08/10 15:25:11.953054, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:806(smbXsrv_tcon_create)
>  smbXsrv_tcon_create: global_id (0x86cf782c) stored
>[2016/08/10 15:25:11.953700,  1, pid=17685, 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                 : 0x86cf782c (2261743660)
>                  global                   : *
>                      global: struct smbXsrv_tcon_global0
>                          db_rec                   : NULL
>                          tcon_global_id           : 0x86cf782c (2261743660)
>                          tcon_wire_id             : 0x86cf782c (2261743660)
>                          server_id: struct server_id
>                              pid                      : 0x0000000000004515 (17685)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                          creation_time            : Wed Aug 10 15:25:12 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:12 2016 IDT
>                  compat                   : NULL
>                  encryption_desired       : 0x00 (0)
>[2016/08/10 15:25:11.955895,  3, pid=17685, effective(0, 0), real(0, 0)] ../source3/lib/access.c:338(allow_access)
>  Allowed connection from 160.60.2.80 (160.60.2.80)
>[2016/08/10 15:25:11.955995, 10, pid=17685, 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:11.956022,  3, pid=17685, 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:11.956043, 10, pid=17685, 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:11.956098, 10, pid=17685, 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:11.956149, 10, pid=17685, 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:11.956172,  3, pid=17685, 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:11.956193, 10, pid=17685, 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:11.956210,  5, pid=17685, 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:11.956224, 10, pid=17685, 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:11.956250,  5, pid=17685, 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:11.956265,  3, pid=17685, 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:11.956281, 10, pid=17685, 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:11.956590,  5, pid=17685, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register)
>  Registering messaging pointer for type 784 - private_data=0x7f5023eda230
>[2016/08/10 15:25:11.956890,  5, pid=17685, 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:11.957189, 10, pid=17685, 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:11.957506,  5, pid=17685, 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" "vm80-win2012r2" "160.60.2.80"
>[2016/08/10 15:25:12.048908, 10, pid=17685, 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:12.049211, 10, pid=17685, 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:12.049429, 10, pid=17685, 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:12.049657,  4, pid=17685, 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:12.049840,  5, pid=17685, 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:12.050692,  5, pid=17685, 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:12.051014,  5, pid=17685, 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:12.051197,  4, pid=17685, 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:12.051363,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:12.051516,  5, pid=17685, 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:12.051774,  5, pid=17685, 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:12.051948, 10, pid=17685, 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:12.052419, 10, pid=17685, 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:12.052589,  2, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:908(make_connection_snum)
>  vm80-win2012r2 (ipv4:160.60.2.80:51759) connect to service v1 initially as user nobody (uid=65534, gid=65534) (pid 17685)
>[2016/08/10 15:25:12.052792,  5, pid=17685, 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:12.052957, 10, pid=17685, 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:12.053136, 10, pid=17685, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Locking key 86CF782C
>[2016/08/10 15:25:12.053305, 10, pid=17685, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f5023ed9980
>[2016/08/10 15:25:12.053482, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:673(smbXsrv_tcon_global_store)
>[2016/08/10 15:25:12.053577, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:675(smbXsrv_tcon_global_store)
>  smbXsrv_tcon_global_store: key '86CF782C' stored
>[2016/08/10 15:25:12.053600,  1, pid=17685, 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           : 0x86cf782c (2261743660)
>                  tcon_wire_id             : 0x86cf782c (2261743660)
>                  server_id: struct server_id
>                      pid                      : 0x0000000000004515 (17685)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                  creation_time            : Wed Aug 10 15:25:12 2016 IDT
>                  share_name               : 'v1'
>                  encryption_required      : 0x00 (0)
>                  session_global_id        : 0xb9846b52 (3112463186)
>[2016/08/10 15:25:12.053708, 10, pid=17685, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Unlocking key 86CF782C
>[2016/08/10 15:25:12.053721,  5, pid=17685, 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:12.053730, 10, pid=17685, 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:12.053749, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:851(smbXsrv_tcon_update)
>[2016/08/10 15:25:12.053755, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:859(smbXsrv_tcon_update)
>  smbXsrv_tcon_update: global_id (0x86cf782c) stored
>[2016/08/10 15:25:12.053763,  1, pid=17685, 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                 : 0x86cf782c (2261743660)
>                  global                   : *
>                      global: struct smbXsrv_tcon_global0
>                          db_rec                   : NULL
>                          tcon_global_id           : 0x86cf782c (2261743660)
>                          tcon_wire_id             : 0x86cf782c (2261743660)
>                          server_id: struct server_id
>                              pid                      : 0x0000000000004515 (17685)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                          creation_time            : Wed Aug 10 15:25:12 2016 IDT
>                          share_name               : 'v1'
>                          encryption_required      : 0x00 (0)
>                          session_global_id        : 0xb9846b52 (3112463186)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Wed Aug 10 15:25:12 2016 IDT
>                  compat                   : *
>                  encryption_desired       : 0x00 (0)
>[2016/08/10 15:25:12.053908, 10, pid=17685, 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:12.053932, 10, pid=17685, 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:12.054326, 10, pid=17685, 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:12.054493, 10, pid=17685, 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:12.054668, 10, pid=17685, 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:12.054851,  4, pid=17685, 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:12.054970,  5, pid=17685, 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:12.055029,  5, pid=17685, 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:12.055172,  5, pid=17685, 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:12.055322,  4, pid=17685, 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:12.055382,  4, pid=17685, 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:12.055435, 10, pid=17685, 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:12.055452, 10, pid=17685, 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:12.055473,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:257(unix_convert)
>  unix_convert called on file "b4"
>[2016/08/10 15:25:12.055487, 10, pid=17685, 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:12.055498,  5, pid=17685, 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:12.055516, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled b4 ?
>[2016/08/10 15:25:12.055526, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component b4 (len 2) ?
>[2016/08/10 15:25:12.055536, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled b4 ?
>[2016/08/10 15:25:12.055544, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component b4 (len 2) ?
>[2016/08/10 15:25:12.055579, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled b4 ?
>[2016/08/10 15:25:12.055589, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component b4 (len 2) ?
>[2016/08/10 15:25:12.055597,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:844(unix_convert)
>  New file b4
>[2016/08/10 15:25:12.055607,  3, pid=17685, 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:12.055621, 10, pid=17685, 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:12.055631,  3, pid=17685, 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:12.055645, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4983(create_file_default)
>  create_file: access_mask = 0x12019f file_attributes = 0x80, share_access = 0x0, 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:12.055659, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4460(create_file_unixpath)
>  create_file_unixpath: access_mask = 0x12019f file_attributes = 0x80, share_access = 0x0, 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:12.055681,  5, pid=17685, 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:12.055691, 10, pid=17685, 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:12.055710, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Locking key 945A4DF6
>[2016/08/10 15:25:12.055726, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f5023ed8bd0
>[2016/08/10 15:25:12.055736, 10, pid=17685, 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:12.055834, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:702(smbXsrv_open_global_store)
>  smbXsrv_open_global_store: key '945A4DF6' stored
>[2016/08/10 15:25:12.055850,  1, pid=17685, 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                      : 0x0000000000004515 (17685)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                  open_global_id           : 0x945a4df6 (2488946166)
>                  open_persistent_id       : 0x00000000945a4df6 (2488946166)
>                  open_volatile_id         : 0x000000007a38da0b (2050546187)
>                  open_owner               : S-1-5-21-1329707852-3482275279-3224653934-501
>                  open_time                : Wed Aug 10 15:25:12 2016 IDT
>                  create_guid              : 00000000-0000-0000-0000-000000000000
>                  client_guid              : 4044de64-4e5a-11e6-80ed-005056aeb322
>                  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:12.055973, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Unlocking key 945A4DF6
>[2016/08/10 15:25:12.055985,  5, pid=17685, 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:12.055994, 10, pid=17685, 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:12.056005, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:876(smbXsrv_open_create)
>  smbXsrv_open_create: global_id (0x945a4df6) stored
>[2016/08/10 15:25:12.056013,  1, pid=17685, 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                 : 0x7a38da0b (2050546187)
>                  global                   : *
>                      global: struct smbXsrv_open_global0
>                          db_rec                   : NULL
>                          server_id: struct server_id
>                              pid                      : 0x0000000000004515 (17685)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                          open_global_id           : 0x945a4df6 (2488946166)
>                          open_persistent_id       : 0x00000000945a4df6 (2488946166)
>                          open_volatile_id         : 0x000000007a38da0b (2050546187)
>                          open_owner               : S-1-5-21-1329707852-3482275279-3224653934-501
>                          open_time                : Wed Aug 10 15:25:12 2016 IDT
>                          create_guid              : 00000000-0000-0000-0000-000000000000
>                          client_guid              : 4044de64-4e5a-11e6-80ed-005056aeb322
>                          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:12 2016 IDT
>                  compat                   : NULL
>[2016/08/10 15:25:12.056201,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:129(file_new)
>  allocated file structure fnum 2050546187 (1 used)
>[2016/08/10 15:25:12.056215, 10, pid=17685, 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:12.056229,  3, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:196(unix_mode)
>  unix_mode(b4) returning 0744
>[2016/08/10 15:25:12.056238, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2478(open_file_ntcreate)
>  open_file_ntcreate: fname=b4, dos_attrs=0x80 access_mask=0x12019f share_access=0x0 create_disposition = 0x3 create_options=0x40 unix mode=0744 oplock_request=2 private_flags = 0x0
>[2016/08/10 15:25:12.056252, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2636(open_file_ntcreate)
>  open_file_ntcreate: fname=b4, after mapping access_mask=0x12019f
>[2016/08/10 15:25:12.056263,  4, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:2726(open_file_ntcreate)
>  calling open_file with flags=0x2 flags2=0x40 mode=0744, access_mask = 0x12019f, open_access_mask = 0x12019f
>[2016/08/10 15:25:12.056277, 10, pid=17685, 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 .
>[2016/08/10 15:25:12.056373,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1229(uid_to_sid)
>  uid_to_sid: winbind failed to find a sid for uid 0
>[2016/08/10 15:25:12.056393,  4, pid=17685, 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:12.056404,  4, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(3112463186) : conn_ctx_stack_ndx = 0
>[2016/08/10 15:25:12.056413,  4, pid=17685, 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:12.056422,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:12.056430,  5, pid=17685, 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:12.057175,  4, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2016/08/10 15:25:12.057324,  4, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(3112463186) : conn_ctx_stack_ndx = 1
>[2016/08/10 15:25:12.057527,  4, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2016/08/10 15:25:12.057685,  5, pid=17685, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:12.057849,  5, pid=17685, 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:12.058133,  4, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2016/08/10 15:25:12.058282,  4, pid=17685, 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:12.058442, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1107(legacy_uid_to_sid)
>  LEGACY: uid 0 -> sid S-1-22-1-0
>[2016/08/10 15:25:12.058622,  5, pid=17685, 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 0
>[2016/08/10 15:25:12.058800,  4, pid=17685, 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:12.058967,  4, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(3112463186) : conn_ctx_stack_ndx = 0
>[2016/08/10 15:25:12.059138,  4, pid=17685, 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:12.059293,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:12.059445,  5, pid=17685, 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:12.059524,  4, pid=17685, 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:12.059542, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1141(legacy_gid_to_sid)
>  LEGACY: gid 0 -> sid S-1-22-2-0
>[2016/08/10 15:25:12.059559, 10, pid=17685, 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:12.059568, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
>  canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms rwx
>[2016/08/10 15:25:12.059581, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2016/08/10 15:25:12.059938, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
>  canon_ace index 2. Type = allow SID = S-1-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2016/08/10 15:25:12.060260, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:848(print_canon_ace_list)
>  print_canon_ace_list: canonicalise_acl: ace entries after arrange
>  canon_ace index 0. Type = allow SID = S-1-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms rwx
>[2016/08/10 15:25:12.060942, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
>  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
>[2016/08/10 15:25:12.061137, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
>  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
>[2016/08/10 15:25:12.061158, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
>  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
>[2016/08/10 15:25:12.069296, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:408(fd_open)
>  fd_open: name b4, flags = 0302 mode = 0744, fd = 40. 
>[2016/08/10 15:25:12.069400, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/notify_internal.c:615(notify_trigger)
>  notify_trigger called action=0x1, filter=0x1, path=/export/v1/b4
>[2016/08/10 15:25:12.069434,  2, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1005(open_file)
>  nobody opened file b4 read=Yes write=Yes (numopen=1)
>[2016/08/10 15:25:12.069452,  5, pid=17685, 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:12.069462, 10, pid=17685, 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:12.069475, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Locking key 1BFD0000000000009000
>[2016/08/10 15:25:12.069517, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f5023ec67e0
>[2016/08/10 15:25:12.069544, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/brlock.c:2025(brl_get_locks_readonly)
>  seqnum=0, fsp->brlock_seqnum=0
>[2016/08/10 15:25:12.069567,  5, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/smbd/oplock.c:87(set_file_oplock)
>  set_file_oplock: granted oplock 0x3 on file /export/v1:b4, fd1b:90:0/2512722705, tv_sec = 57ab1d28, tv_usec = d978
>[2016/08/10 15:25:12.069584, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:1873(grant_fsp_oplock_type)
>  grant_fsp_oplock_type: oplock type 0x3 on file b4
>[2016/08/10 15:25:12.069616, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:187(unparse_share_modes)
>  unparse_share_modes:
>[2016/08/10 15:25:12.069628,  1, pid=17685, 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                    : 0x01 (1)
>          modified                 : 0x01 (1)
>          record                   : *
>[2016/08/10 15:25:12.069913, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Unlocking key 1BFD0000000000009000
>[2016/08/10 15:25:12.069929,  5, pid=17685, 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:12.069938, 10, pid=17685, 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:12.069956, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4792(create_file_unixpath)
>  create_file_unixpath: info=2
>[2016/08/10 15:25:12.069964, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:5071(create_file_default)
>  create_file: info=2
>[2016/08/10 15:25:12.069973, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1098(smbd_smb2_create_send)
>  smbd_smb2_create_send: response construction phase
>[2016/08/10 15:25:12.069983, 10, pid=17685, 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:12.070016, 10, pid=17685, 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:12.070042,  5, pid=17685, 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:12.070052,  4, pid=17685, 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:12.070080,  4, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(3112463186) : conn_ctx_stack_ndx = 0
>[2016/08/10 15:25:12.070091,  4, pid=17685, 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:12.070099,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:12.070107,  5, pid=17685, 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:12.070135,  4, pid=17685, 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:12.070146, 10, pid=17685, 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:12.070166, 10, pid=17685, 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:12.070175, 10, pid=17685, 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:12.070187, 10, pid=17685, 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:12.070671, 10, pid=17685, 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:12.070997, 10, pid=17685, 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:12.071686, 10, pid=17685, 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:12.071858, 10, pid=17685, 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:12.072016, 10, pid=17685, 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:12.072207, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../libcli/security/access_check.c:188(se_access_check)
>  se_access_check: MAX desired = 0x2000000, granted = 0x1e01ff, remaining = 0x1e01ff
>[2016/08/10 15:25:12.072381, 10, pid=17685, 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 .
>[2016/08/10 15:25:12.072571,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1229(uid_to_sid)
>  uid_to_sid: winbind failed to find a sid for uid 0
>[2016/08/10 15:25:12.072730,  4, pid=17685, 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:12.072898,  4, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(3112463186) : conn_ctx_stack_ndx = 0
>[2016/08/10 15:25:12.073056,  4, pid=17685, 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:12.073230,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:12.073309,  5, pid=17685, 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:12.073583,  4, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2016/08/10 15:25:12.073725,  4, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(3112463186) : conn_ctx_stack_ndx = 1
>[2016/08/10 15:25:12.073841,  4, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2016/08/10 15:25:12.073855,  5, pid=17685, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:12.073863,  5, pid=17685, 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:12.073888,  4, pid=17685, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2016/08/10 15:25:12.073902,  4, pid=17685, 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:12.073913, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1107(legacy_uid_to_sid)
>  LEGACY: uid 0 -> sid S-1-22-1-0
>[2016/08/10 15:25:12.073937,  5, pid=17685, 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 0
>[2016/08/10 15:25:12.073948,  4, pid=17685, 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:12.073958,  4, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(3112463186) : conn_ctx_stack_ndx = 0
>[2016/08/10 15:25:12.073967,  4, pid=17685, 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:12.073975,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:12.073983,  5, pid=17685, 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:12.074007,  4, pid=17685, 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:12.074018, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/passdb/lookup_sid.c:1141(legacy_gid_to_sid)
>  LEGACY: gid 0 -> sid S-1-22-2-0
>[2016/08/10 15:25:12.074030, 10, pid=17685, 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:12.074039, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
>  canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms rwx
>[2016/08/10 15:25:12.074051, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2016/08/10 15:25:12.074418, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:2737(canonicalise_acl)
>  canon_ace index 2. Type = allow SID = S-1-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2016/08/10 15:25:12.074720, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:848(print_canon_ace_list)
>  print_canon_ace_list: canonicalise_acl: ace entries after arrange
>  canon_ace index 0. Type = allow SID = S-1-22-1-0 uid 0 (root) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-0 gid 0 (root) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms rwx
>[2016/08/10 15:25:12.075423, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
>  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
>[2016/08/10 15:25:12.075584, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
>  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
>[2016/08/10 15:25:12.075746, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=acls] ../source3/smbd/posix_acls.c:1110(map_canon_ace_perms)
>  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
>[2016/08/10 15:25:12.075778, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:174(smbd_check_access_rights)
>  smbd_check_access_rights: file . requesting 0x40 returning 0x40 (NT_STATUS_OK)
>[2016/08/10 15:25:12.075795,  5, pid=17685, 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:12.075804, 10, pid=17685, 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:12.075817, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Locking key 945A4DF6
>[2016/08/10 15:25:12.075855, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f5023ed7d80
>[2016/08/10 15:25:12.075883, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:702(smbXsrv_open_global_store)
>  smbXsrv_open_global_store: key '945A4DF6' stored
>[2016/08/10 15:25:12.075896,  1, pid=17685, 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                   : 0x00000002 (2)
>          info                     : union smbXsrv_open_globalU(case 0)
>          info0                    : *
>              info0: struct smbXsrv_open_global0
>                  db_rec                   : *
>                  server_id: struct server_id
>                      pid                      : 0x0000000000004515 (17685)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                  open_global_id           : 0x945a4df6 (2488946166)
>                  open_persistent_id       : 0x00000000945a4df6 (2488946166)
>                  open_volatile_id         : 0x000000007a38da0b (2050546187)
>                  open_owner               : S-1-5-21-1329707852-3482275279-3224653934-501
>                  open_time                : Wed Aug 10 15:25:12 2016 IDT
>                  create_guid              : 4044e0db-4e5a-11e6-80ed-005056aeb322
>                  client_guid              : 4044de64-4e5a-11e6-80ed-005056aeb322
>                  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:12.076017, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Unlocking key 945A4DF6
>[2016/08/10 15:25:12.076029,  5, pid=17685, 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:12.076038, 10, pid=17685, 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:12.076054, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smbXsrv_open.c:947(smbXsrv_open_update)
>  smbXsrv_open_update: global_id (0x945a4df6) stored
>[2016/08/10 15:25:12.076079,  1, pid=17685, 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                 : 0x7a38da0b (2050546187)
>                  global                   : *
>                      global: struct smbXsrv_open_global0
>                          db_rec                   : NULL
>                          server_id: struct server_id
>                              pid                      : 0x0000000000004515 (17685)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0xb64c1d958a08702d (-5310837332473515987)
>                          open_global_id           : 0x945a4df6 (2488946166)
>                          open_persistent_id       : 0x00000000945a4df6 (2488946166)
>                          open_volatile_id         : 0x000000007a38da0b (2050546187)
>                          open_owner               : S-1-5-21-1329707852-3482275279-3224653934-501
>                          open_time                : Wed Aug 10 15:25:12 2016 IDT
>                          create_guid              : 4044e0db-4e5a-11e6-80ed-005056aeb322
>                          client_guid              : 4044de64-4e5a-11e6-80ed-005056aeb322
>                          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:12 2016 IDT
>                  compat                   : *
>[2016/08/10 15:25:12.076233, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1154(smbd_smb2_create_send)
>  smb2_create_send: smbXsrv_open_update returned NT_STATUS_OK
>[2016/08/10 15:25:12.076245,  8, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:600(dos_mode)
>  dos_mode: b4
>[2016/08/10 15:25:12.076256,  8, pid=17685, 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:12.076267,  8, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/dosmode.c:36(dos_mode_debug_print)
>  dos_mode returning a
>[2016/08/10 15:25:12.076277, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:1287(smbd_smb2_create_send)
>  smbd_smb2_create_send: b4 - fnum 2050546187
>[2016/08/10 15:25:12.076295, 10, pid=17685, 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_OK] body[88] dyn[yes:88] at ../source3/smbd/smb2_create.c:364
>[2016/08/10 15:25:12.076317, 10, pid=17685, 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
>
>
>  
>[2016/08/10 15:25:17.865926, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/lib/messages.c:252(messaging_recv_cb)
>  messaging_recv_cb: Received message 0x306 len 76 (num_fds:0) from 17743
>[2016/08/10 15:25:17.866427, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/smbd/oplock.c:806(process_oplock_break_message)
>  Got oplock break to 1 message from pid 17743: fd1b:90:0/2512722705
>[2016/08/10 15:25:17.866862,  3, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/smbd/oplock.c:657(initial_break_processing)
>  initial_break_processing: called for fd1b:90:0/2512722705
>  Current oplocks_open (exclusive = 1, levelII = 0)
>[2016/08/10 15:25:17.867347, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/smbd/oplock.c:921(process_oplock_break_message)
>  break_from=7, break_to=1
>[2016/08/10 15:25:17.867441, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_break.c:474(send_break_message_smb2)
>  send_break_message_smb2: sending oplock break for file b4, fnum 2050546187, smb2 level 1
>  
>  
>[2016/08/10 15:25:17.867880, 10, pid=17685, effective(65534, 65534), real(65534, 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.868279, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:659(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 5 (position 5) from bitmap
>[2016/08/10 15:25:17.868508, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1967(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_CLOSE] mid = 5
>[2016/08/10 15:25:17.868603,  4, pid=17685, 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.868687, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_close.c:227(smbd_smb2_close)
>  smbd_smb2_close: b4 - fnum 2050546187
>[2016/08/10 15:25:17.868722, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/smbd/oplock.c:244(remove_oplock)
>  remove_oplock called for b4
>[2016/08/10 15:25:17.868746,  5, pid=17685, 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.868766, 10, pid=17685, 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.868795, 10, pid=17685, 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.869931, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f5023ec5060
>[2016/08/10 15:25:17.870442, 10, pid=17685, 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.870688,  1, pid=17685, 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.871209, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/brlock.c:2025(brl_get_locks_readonly)
>  seqnum=0, fsp->brlock_seqnum=0
>[2016/08/10 15:25:17.871237, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:187(unparse_share_modes)
>  unparse_share_modes:
>[2016/08/10 15:25:17.871255,  1, pid=17685, 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                 : 0x01 (1)
>          record                   : *
>[2016/08/10 15:25:17.871718,  4, pid=17685, 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.871756,  4, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
>  push_conn_ctx(3112463186) : conn_ctx_stack_ndx = 0
>[2016/08/10 15:25:17.871776,  4, pid=17685, 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.871795,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/08/10 15:25:17.871813,  5, pid=17685, 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.871852, 10, pid=17685, effective(0, 0), real(0, 0)] ../source3/lib/messages_dgm.c:325(messaging_dgm_send)
>  messaging_dgm_send: Sending message to 17743
>[2016/08/10 15:25:17.871894,  4, pid=17685, 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.871923, 10, pid=17685, 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.871949,  5, pid=17685, 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.871968, 10, pid=17685, 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.871991,  0, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/close.c:746(close_normal_file)
>  close_normal_file: sleep 0
>[2016/08/10 15:25:18.873361,  0, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/close.c:746(close_normal_file)
>  close_normal_file: sleep 1
>[2016/08/10 15:25:19.874045,  0, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/close.c:746(close_normal_file)
>  close_normal_file: sleep 2
>[2016/08/10 15:25:20.874759,  0, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/close.c:746(close_normal_file)
>  close_normal_file: sleep 3
>[2016/08/10 15:25:21.874967,  0, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/close.c:746(close_normal_file)
>  close_normal_file: sleep 4
>[2016/08/10 15:25:22.875228,  0, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/close.c:751(close_normal_file)
>  close_normal_file: ref_count=1
>  
>[2016/08/10 15:25:22.875347,  5, pid=17685, 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:22.875373, 10, pid=17685, 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:22.875405, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Locking key 1BFD0000000000009000
>[2016/08/10 15:25:22.875448, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f5023ec6250
>[2016/08/10 15:25:22.875511, 10, pid=17685, 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:22.875534,  1, pid=17685, 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:22.875968, 10, pid=17685, 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:22.876001, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:187(unparse_share_modes)
>  unparse_share_modes:
>[2016/08/10 15:25:22.876020,  1, pid=17685, 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          : 0x00000000 (0)
>          share_modes: ARRAY(0)
>          num_leases               : 0x00000000 (0)
>          leases: ARRAY(0)
>          num_delete_tokens        : 0x00000000 (0)
>          delete_tokens: ARRAY(0)
>          old_write_time           : Wed Aug 10 15:25:12 2016 IDT.60507505
>          changed_write_time       : Thu Jan  1 02:00:00 1970 IST.0
>          fresh                    : 0x00 (0)
>          modified                 : 0x01 (1)
>          record                   : *
>[2016/08/10 15:25:22.876207, 10, pid=17685, effective(65534, 65534), real(65534, 0), class=locking] ../source3/locking/share_mode_lock.c:194(unparse_share_modes)
>  No used share mode found
>[2016/08/10 15:25:22.876256, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Unlocking key 1BFD0000000000009000
>[2016/08/10 15:25:22.876280,  5, pid=17685, 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:22.876311, 10, pid=17685, 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:22.876347, 10, pid=17685, 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:22.876947,  2, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/close.c:792(close_normal_file)
>  nobody closed file b4 (numopen=0) NT_STATUS_OK
>[2016/08/10 15:25:22.876999,  5, pid=17685, 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:22.877047, 10, pid=17685, 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:22.877105, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Locking key 945A4DF6
>[2016/08/10 15:25:22.877209, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f5023ebaed0
>[2016/08/10 15:25:22.877508, 10, pid=17685, effective(65534, 65534), real(65534, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
>  Unlocking key 945A4DF6
>[2016/08/10 15:25:22.877811,  5, pid=17685, 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:22.877863, 10, pid=17685, 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:22.877903,  5, pid=17685, effective(65534, 65534), real(65534, 0)] ../source3/smbd/files.c:555(file_free)
>  freed files structure 2050546187 (0 used)
>[2016/08/10 15:25:22.877943, 10, pid=17685, 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_OK] body[60] dyn[no:0] at ../source3/smbd/smb2_close.c:144
>[2016/08/10 15:25:22.878021, 10, pid=17685, 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/6/31

Actions: View

Attachments on bug 12139: 12352 | 12353 | 12354 | 12355 | 12359 | 12360 | 12362