Attachment 11336 Details for Bug 11438 – server side log with debug level 10 for client PC

server side log with debug level 10 for client PC

log.thinkpad-t510 (text/plain), 133.99 KB, created by Paul Smedley on 2015-08-15 09:40:31 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Paul Smedley

Created: 2015-08-15 09:40:31 UTC

Size: 133.99 KB

patch

obsolete

>[2015/08/14 19:16:53.213542,  6, pid=12342, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2658(lp_file_list_changed)
>  lp_file_list_changed()
>  file /etc/samba/smb.conf -> /etc/samba/smb.conf  last mod_time: Fri Aug 14 19:16:36 2015
>  
>[2015/08/14 19:16:53.213612,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:187(dbwrap_check_lock_order)
>  check lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
>[2015/08/14 19:16:53.213635, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:/var/run/samba/smbXsrv_session_global.tdb 2:<none> 3:<none>
>[2015/08/14 19:16:53.213658, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 29B8FA1E
>[2015/08/14 19:16:53.213686, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f7a46249620
>[2015/08/14 19:16:53.213733, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:853(smbXsrv_session_global_store)
>[2015/08/14 19:16:53.213749, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:855(smbXsrv_session_global_store)
>  smbXsrv_session_global_store: key '29B8FA1E' stored
>[2015/08/14 19:16:53.213771,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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        : 0x29b8fa1e (699988510)
>                  session_wire_id          : 0x0000000029b8fa1e (699988510)
>                  creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                  expiration_time          : Thu Jan  1 09:30:00 1970 ACST
>                  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-2926930320-515016158-3918064283-501
>                                      sids                     : S-1-5-21-2926930320-515016158-3918064283-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              : 'NAS'
>                                  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       : ''
>                          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                      : 0x0000000000003036 (12342)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                          local_address            : 'ipv4:192.168.1.200:445'
>                          remote_address           : 'ipv4:192.168.1.83:37338'
>                          remote_name              : '192.168.1.83'
>                          auth_session_info_seqnum : 0x00000001 (1)
>[2015/08/14 19:16:53.214953, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 29B8FA1E
>[2015/08/14 19:16:53.214976,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
>[2015/08/14 19:16:53.214997, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2015/08/14 19:16:53.215019, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1269(smbXsrv_session_update)
>[2015/08/14 19:16:53.215031, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1277(smbXsrv_session_update)
>  smbXsrv_session_update: global_id (0x29b8fa1e) stored
>[2015/08/14 19:16:53.215050,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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
>                  connection               : *
>                  local_id                 : 0x29b8fa1e (699988510)
>                  global                   : *
>                      global: struct smbXsrv_session_global0
>                          db_rec                   : NULL
>                          session_global_id        : 0x29b8fa1e (699988510)
>                          session_wire_id          : 0x0000000029b8fa1e (699988510)
>                          creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                          expiration_time          : Thu Jan  1 09:30:00 1970 ACST
>                          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-2926930320-515016158-3918064283-501
>                                              sids                     : S-1-5-21-2926930320-515016158-3918064283-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              : 'NAS'
>                                          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       : ''
>                                  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                      : 0x0000000000003036 (12342)
>                                      task_id                  : 0x00000000 (0)
>                                      vnn                      : 0xffffffff (4294967295)
>                                      unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                                  local_address            : 'ipv4:192.168.1.200:445'
>                                  remote_address           : 'ipv4:192.168.1.83:37338'
>                                  remote_name              : '192.168.1.83'
>                                  auth_session_info_seqnum : 0x00000001 (1)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Fri Aug 14 19:16:53 2015 ACST
>                  nonce_high               : 0x9c44d5160646f406 (-7186384814805158906)
>                  nonce_low                : 0x0000000000000001 (1)
>                  gensec                   : *
>                  compat                   : *
>                  tcon_table               : *
>[2015/08/14 19:16:53.216344, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2499(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:168
>[2015/08/14 19:16:53.216373, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit)
>  smb2_set_operation_credit: requested 8192, charge 1, granted 33, current possible/max 512/512, total granted/max/low/range 33/8192/6/33
>[2015/08/14 19:16:53.220411, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3257(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2015/08/14 19:16:53.220466, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:621(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 6 (position 6) from bitmap
>[2015/08/14 19:16:53.220490, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1878(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_TCON] mid = 6
>[2015/08/14 19:16:53.220514,  4, pid=12342, 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
>[2015/08/14 19:16:53.220536,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.220556,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.220613,  5, pid=12342, 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)
>[2015/08/14 19:16:53.220649, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_tcon.c:199(smbd_smb2_tree_connect)
>  smbd_smb2_tree_connect: path[\\192.168.1.200\IPC$] share[IPC$]
>[2015/08/14 19:16:53.220693,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:187(dbwrap_check_lock_order)
>  check lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.220717, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:/var/run/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none>
>[2015/08/14 19:16:53.220741, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 38D44FBA
>[2015/08/14 19:16:53.220769, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f7a46249700
>[2015/08/14 19:16:53.220835, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:672(smbXsrv_tcon_global_store)
>[2015/08/14 19:16:53.220852, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:674(smbXsrv_tcon_global_store)
>  smbXsrv_tcon_global_store: key '38D44FBA' stored
>[2015/08/14 19:16:53.220874,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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           : 0x38d44fba (953438138)
>                  tcon_wire_id             : 0x38d44fba (953438138)
>                  server_id: struct server_id
>                      pid                      : 0x0000000000003036 (12342)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                  creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                  share_name               : NULL
>                  encryption_required      : 0x00 (0)
>                  session_global_id        : 0x00000000 (0)
>[2015/08/14 19:16:53.221061, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 38D44FBA
>[2015/08/14 19:16:53.221091,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.221112, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2015/08/14 19:16:53.221133, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:796(smbXsrv_tcon_create)
>[2015/08/14 19:16:53.221145, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:804(smbXsrv_tcon_create)
>  smbXsrv_tcon_create: global_id (0x38d44fba) stored
>[2015/08/14 19:16:53.221165,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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                 : 0x38d44fba (953438138)
>                  global                   : *
>                      global: struct smbXsrv_tcon_global0
>                          db_rec                   : NULL
>                          tcon_global_id           : 0x38d44fba (953438138)
>                          tcon_wire_id             : 0x38d44fba (953438138)
>                          server_id: struct server_id
>                              pid                      : 0x0000000000003036 (12342)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                          creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                          share_name               : NULL
>                          encryption_required      : 0x00 (0)
>                          session_global_id        : 0x00000000 (0)
>                  status                   : NT_STATUS_INTERNAL_ERROR
>                  idle_time                : Fri Aug 14 19:16:53 2015 ACST
>                  compat                   : NULL
>[2015/08/14 19:16:53.221440,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/access.c:338(allow_access)
>  Allowed connection from 192.168.1.83 (192.168.1.83)
>[2015/08/14 19:16:53.221510, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:163(set_conn_connectpath)
>  set_conn_connectpath: service IPC$, connectpath = /tmp
>[2015/08/14 19:16:53.221538,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:612(make_connection_snum)
>  Connect path is '/tmp' for service [IPC$]
>[2015/08/14 19:16:53.221564, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:237(user_ok_token)
>  user_ok_token: share IPC$ is ok for unix user nobody
>[2015/08/14 19:16:53.221589, 10, pid=12342, 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 IPC$ is read-only for unix user nobody
>[2015/08/14 19:16:53.221635, 10, pid=12342, 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
>[2015/08/14 19:16:53.221663,  3, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:113(vfs_init_default)
>  Initialising default vfs hooks
>[2015/08/14 19:16:53.221694, 10, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:64(vfs_find_backend_entry)
>  vfs_find_backend_entry called for posixacl
>[2015/08/14 19:16:53.221718,  5, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:103(smb_register_vfs)
>  Successfully added vfs backend 'posixacl'
>[2015/08/14 19:16:53.221743, 10, pid=12342, 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]/
>[2015/08/14 19:16:53.221769,  5, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:103(smb_register_vfs)
>  Successfully added vfs backend '/[Default VFS]/'
>[2015/08/14 19:16:53.221790,  3, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:139(vfs_init_custom)
>  Initialising custom vfs hooks from [/[Default VFS]/]
>[2015/08/14 19:16:53.221813, 10, pid=12342, 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
>[2015/08/14 19:16:53.221858, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:163(set_conn_connectpath)
>  set_conn_connectpath: service IPC$, connectpath = /tmp
>[2015/08/14 19:16:53.221886, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:237(user_ok_token)
>  user_ok_token: share IPC$ is ok for unix user nobody
>[2015/08/14 19:16:53.221908, 10, pid=12342, 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 IPC$ is read-only for unix user nobody
>[2015/08/14 19:16:53.221935, 10, pid=12342, 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
>[2015/08/14 19:16:53.221978,  4, pid=12342, 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
>[2015/08/14 19:16:53.222002,  5, pid=12342, 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-2926930320-515016158-3918064283-501
>    SID[  1]: S-1-5-21-2926930320-515016158-3918064283-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):
>[2015/08/14 19:16:53.222103,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 65534
>  Primary group is 65534 and contains 1 supplementary groups
>  Group[  0]: 65534
>[2015/08/14 19:16:53.222147,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:363(change_to_user_internal)
>  Impersonated user: uid=(65534,65534), gid=(0,65534)
>[2015/08/14 19:16:53.222174,  4, pid=12342, 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
>[2015/08/14 19:16:53.222195,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.222215,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.222247,  5, pid=12342, 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)
>[2015/08/14 19:16:53.222273, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:163(set_conn_connectpath)
>  set_conn_connectpath: service IPC$, connectpath = /tmp
>[2015/08/14 19:16:53.222310, 10, pid=12342, 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 IPC$, directory /tmp
>[2015/08/14 19:16:53.222380,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:856(make_connection_snum)
>  thinkpad-t510 (ipv4:192.168.1.83:37338) connect to service IPC$ initially as user nobody (uid=65534, gid=65534) (pid 12342)
>[2015/08/14 19:16:53.222419,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:187(dbwrap_check_lock_order)
>  check lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.222446, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:/var/run/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none>
>[2015/08/14 19:16:53.222470, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 38D44FBA
>[2015/08/14 19:16:53.222493, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f7a4623d0e0
>[2015/08/14 19:16:53.222521, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:672(smbXsrv_tcon_global_store)
>[2015/08/14 19:16:53.222534, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:674(smbXsrv_tcon_global_store)
>  smbXsrv_tcon_global_store: key '38D44FBA' stored
>[2015/08/14 19:16:53.222555,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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           : 0x38d44fba (953438138)
>                  tcon_wire_id             : 0x38d44fba (953438138)
>                  server_id: struct server_id
>                      pid                      : 0x0000000000003036 (12342)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                  creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                  share_name               : 'IPC$'
>                  encryption_required      : 0x00 (0)
>                  session_global_id        : 0x29b8fa1e (699988510)
>[2015/08/14 19:16:53.222738, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 38D44FBA
>[2015/08/14 19:16:53.222761,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.222781, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2015/08/14 19:16:53.222802, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:849(smbXsrv_tcon_update)
>[2015/08/14 19:16:53.222814, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:857(smbXsrv_tcon_update)
>  smbXsrv_tcon_update: global_id (0x38d44fba) stored
>[2015/08/14 19:16:53.222834,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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                 : 0x38d44fba (953438138)
>                  global                   : *
>                      global: struct smbXsrv_tcon_global0
>                          db_rec                   : NULL
>                          tcon_global_id           : 0x38d44fba (953438138)
>                          tcon_wire_id             : 0x38d44fba (953438138)
>                          server_id: struct server_id
>                              pid                      : 0x0000000000003036 (12342)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                          creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                          share_name               : 'IPC$'
>                          encryption_required      : 0x00 (0)
>                          session_global_id        : 0x29b8fa1e (699988510)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Fri Aug 14 19:16:53 2015 ACST
>                  compat                   : *
>[2015/08/14 19:16:53.223105, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2499(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:163
>[2015/08/14 19:16:53.223147, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit)
>  smb2_set_operation_credit: requested 8160, charge 1, granted 33, current possible/max 480/512, total granted/max/low/range 65/8192/7/65
>[2015/08/14 19:16:53.228841, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3257(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2015/08/14 19:16:53.228905, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:621(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 7 (position 7) from bitmap
>[2015/08/14 19:16:53.228930, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1878(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_IOCTL] mid = 7
>[2015/08/14 19:16:53.228956,  4, pid=12342, 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
>[2015/08/14 19:16:53.228979,  5, pid=12342, 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-2926930320-515016158-3918064283-501
>    SID[  1]: S-1-5-21-2926930320-515016158-3918064283-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):
>[2015/08/14 19:16:53.229082,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 65534
>  Primary group is 65534 and contains 1 supplementary groups
>  Group[  0]: 65534
>[2015/08/14 19:16:53.229127,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:363(change_to_user_internal)
>  Impersonated user: uid=(65534,65534), gid=(0,65534)
>[2015/08/14 19:16:53.229156,  4, pid=12342, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:838(vfs_ChDir)
>  vfs_ChDir to /tmp
>[2015/08/14 19:16:53.229197,  4, pid=12342, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:849(vfs_ChDir)
>  vfs_ChDir got /tmp
>[2015/08/14 19:16:53.229222, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1780(smbd_smb2_request_verify_creditcharge)
>  mid 7, CreditCharge: 1, NeededCharge: 1
>[2015/08/14 19:16:53.229244, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_ioctl.c:394(smbd_smb2_ioctl_send)
>  smbd_smb2_ioctl: ctl_code[0x00060194] <no handle>, fnum [fsp is NULL]
>[2015/08/14 19:16:53.229945, 10, pid=12342, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/modules/vfs_default.c:182(vfswrap_get_dfs_referrals)
>[2015/08/14 19:16:53.229960,  1, pid=12342, effective(65534, 65534), real(65534, 0)] ../librpc/ndr/ndr.c:333(ndr_print_function_debug)
>       dfs_GetDFSReferral: struct dfs_GetDFSReferral
>          in: struct dfs_GetDFSReferral
>              req: struct dfs_GetDFSReferral_in
>                  max_referral_level       : 0x0003 (3)
>                  servername               : '\192.168.1.200\Public'
>[2015/08/14 19:16:53.230039, 10, pid=12342, effective(65534, 65534), real(65534, 0), class=msdfs] ../source3/smbd/msdfs.c:115(parse_dfs_path)
>  parse_dfs_path: temp = |192.168.1.200\Public| after trimming \'s
>[2015/08/14 19:16:53.230063, 10, pid=12342, effective(65534, 65534), real(65534, 0), class=msdfs] ../source3/smbd/msdfs.c:140(parse_dfs_path)
>  parse_dfs_path: hostname: 192.168.1.200
>[2015/08/14 19:16:53.230084, 10, pid=12342, effective(65534, 65534), real(65534, 0), class=msdfs] ../source3/smbd/msdfs.c:182(parse_dfs_path)
>  parse_dfs_path: servicename: Public
>[2015/08/14 19:16:53.230112,  3, pid=12342, effective(65534, 65534), real(65534, 0), class=msdfs] ../source3/smbd/msdfs.c:974(get_referred_path)
>  get_referred_path: |Public| in dfs path \192.168.1.200\Public is not a dfs root.
>[2015/08/14 19:16:53.230140, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_ioctl.c:291(smbd_smb2_request_ioctl_done)
>  smbd_smb2_request_ioctl_done: smbd_smb2_ioctl_recv returned 0 status NT_STATUS_NOT_FOUND
>[2015/08/14 19:16:53.230163, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2598(smbd_smb2_request_error_ex)
>  smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_NOT_FOUND] || at ../source3/smbd/smb2_ioctl.c:309
>[2015/08/14 19:16:53.230186, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2499(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_NOT_FOUND] body[8] dyn[yes:1] at ../source3/smbd/smb2_server.c:2651
>[2015/08/14 19:16:53.230208, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit)
>  smb2_set_operation_credit: requested 8128, charge 1, granted 33, current possible/max 448/512, total granted/max/low/range 97/8192/8/97
>[2015/08/14 19:16:53.231202, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3257(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2015/08/14 19:16:53.231263, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:621(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 8 (position 8) from bitmap
>[2015/08/14 19:16:53.231288, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1878(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_TDIS] mid = 8
>[2015/08/14 19:16:53.231311,  4, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2015/08/14 19:16:53.231334,  4, pid=12342, 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
>[2015/08/14 19:16:53.231355,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.231375,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.231412,  5, pid=12342, 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)
>  smbd_smb2_request_pending_queue: req->current_idx = 1
>  	req->in.vector[0].iov_len = 0
>  	req->in.vector[1].iov_len = 0
>  	req->in.vector[2].iov_len = 64
>  	req->in.vector[3].iov_len = 4
>  	req->in.vector[4].iov_len = 0
>  	req->out.vector[0].iov_len = 4
>  	req->out.vector[1].iov_len = 0
>  	req->out.vector[2].iov_len = 64
>  	req->out.vector[3].iov_len = 8
>  	req->out.vector[4].iov_len = 0
>[2015/08/14 19:16:53.231544,  4, pid=12342, 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
>[2015/08/14 19:16:53.231567,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.231593,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.231625,  5, pid=12342, 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)
>[2015/08/14 19:16:53.231648,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:187(dbwrap_check_lock_order)
>  check lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.231669, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:/var/run/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none>
>[2015/08/14 19:16:53.231692, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 38D44FBA
>[2015/08/14 19:16:53.231719, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f7a4623d0e0
>[2015/08/14 19:16:53.231749, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 38D44FBA
>[2015/08/14 19:16:53.231772,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.231793, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2015/08/14 19:16:53.231817,  4, pid=12342, 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
>[2015/08/14 19:16:53.231838,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.231857,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.231887,  5, pid=12342, 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)
>[2015/08/14 19:16:53.231909,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:1130(close_cnum)
>  thinkpad-t510 (ipv4:192.168.1.83:37338) closed connection to service IPC$
>[2015/08/14 19:16:53.231935,  4, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:838(vfs_ChDir)
>  vfs_ChDir to /
>[2015/08/14 19:16:53.231964,  4, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:849(vfs_ChDir)
>  vfs_ChDir got /
>[2015/08/14 19:16:53.231988,  4, pid=12342, 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
>[2015/08/14 19:16:53.232009,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.232028,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.232059,  5, pid=12342, 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)
>[2015/08/14 19:16:53.232094, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2499(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[4] dyn[no:0] at ../source3/smbd/smb2_tcon.c:479
>[2015/08/14 19:16:53.232120, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit)
>  smb2_set_operation_credit: requested 8096, charge 1, granted 33, current possible/max 416/512, total granted/max/low/range 129/8192/9/129
>[2015/08/14 19:16:53.234276, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3257(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2015/08/14 19:16:53.234344, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:621(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 9 (position 9) from bitmap
>[2015/08/14 19:16:53.234369, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1878(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_TCON] mid = 9
>[2015/08/14 19:16:53.234392,  4, pid=12342, 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
>[2015/08/14 19:16:53.234413,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.234433,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.234465,  5, pid=12342, 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)
>[2015/08/14 19:16:53.234489, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_tcon.c:199(smbd_smb2_tree_connect)
>  smbd_smb2_tree_connect: path[\\192.168.1.200\Public] share[Public]
>[2015/08/14 19:16:53.234530,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:187(dbwrap_check_lock_order)
>  check lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.234553, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:/var/run/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none>
>[2015/08/14 19:16:53.234576, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 0BCD3490
>[2015/08/14 19:16:53.234602, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f7a4623b760
>[2015/08/14 19:16:53.234637, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:672(smbXsrv_tcon_global_store)
>[2015/08/14 19:16:53.234652, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:674(smbXsrv_tcon_global_store)
>  smbXsrv_tcon_global_store: key '0BCD3490' stored
>[2015/08/14 19:16:53.234674,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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           : 0x0bcd3490 (197997712)
>                  tcon_wire_id             : 0x0bcd3490 (197997712)
>                  server_id: struct server_id
>                      pid                      : 0x0000000000003036 (12342)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                  creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                  share_name               : NULL
>                  encryption_required      : 0x00 (0)
>                  session_global_id        : 0x00000000 (0)
>[2015/08/14 19:16:53.234862, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 0BCD3490
>[2015/08/14 19:16:53.234884,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.234905, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2015/08/14 19:16:53.234931, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:796(smbXsrv_tcon_create)
>[2015/08/14 19:16:53.234944, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:804(smbXsrv_tcon_create)
>  smbXsrv_tcon_create: global_id (0x0bcd3490) stored
>[2015/08/14 19:16:53.234971,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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                 : 0x0bcd3490 (197997712)
>                  global                   : *
>                      global: struct smbXsrv_tcon_global0
>                          db_rec                   : NULL
>                          tcon_global_id           : 0x0bcd3490 (197997712)
>                          tcon_wire_id             : 0x0bcd3490 (197997712)
>                          server_id: struct server_id
>                              pid                      : 0x0000000000003036 (12342)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                          creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                          share_name               : NULL
>                          encryption_required      : 0x00 (0)
>                          session_global_id        : 0x00000000 (0)
>                  status                   : NT_STATUS_INTERNAL_ERROR
>                  idle_time                : Fri Aug 14 19:16:53 2015 ACST
>                  compat                   : NULL
>[2015/08/14 19:16:53.235238,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/access.c:338(allow_access)
>  Allowed connection from 192.168.1.83 (192.168.1.83)
>[2015/08/14 19:16:53.235292, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:163(set_conn_connectpath)
>  set_conn_connectpath: service Public, connectpath = /NAS/Public
>[2015/08/14 19:16:53.235319,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:612(make_connection_snum)
>  Connect path is '/NAS/Public' for service [Public]
>[2015/08/14 19:16:53.235341, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:237(user_ok_token)
>  user_ok_token: share Public is ok for unix user nobody
>[2015/08/14 19:16:53.235373,  3, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/dom_sid.c:208(dom_sid_parse_endp)
>  string_to_sid: SID julie is not in a valid format
>[2015/08/14 19:16:53.235404, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:77(lookup_name)
>  lookup_name: NAS\julie => domain=[NAS], name=[julie]
>[2015/08/14 19:16:53.235427, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:78(lookup_name)
>  lookup_name: flags = 0x073
>[2015/08/14 19:16:53.235448,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.235470,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2015/08/14 19:16:53.235491,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.235511,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.235530,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.235584, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username)
>  pdb_set_username: setting username julie, was 
>[2015/08/14 19:16:53.235610, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain)
>  pdb_set_domain: setting domain NAS, was 
>[2015/08/14 19:16:53.235631, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username , was 
>[2015/08/14 19:16:53.235651, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname)
>  pdb_set_full_name: setting full name Julie Niedzwiecki, was 
>[2015/08/14 19:16:53.235673,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.235698, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir)
>  pdb_set_homedir: setting home dir \\nas\julie, was 
>[2015/08/14 19:16:53.235720, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive , was NULL
>[2015/08/14 19:16:53.235741, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2015/08/14 19:16:53.235763,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.235785, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path \\nas\julie\profile, was 
>[2015/08/14 19:16:53.235807, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2015/08/14 19:16:53.235828,  4, pid=12342, 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
>[2015/08/14 19:16:53.235849,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.235869,  4, pid=12342, 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
>[2015/08/14 19:16:53.235889,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.235909,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.235943, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.235968,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.235991, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2926930320-515016158-3918064283-1001
>[2015/08/14 19:16:53.236014, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2926930320-515016158-3918064283-1001 from rid 1001
>[2015/08/14 19:16:53.236046,  4, pid=12342, 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
>[2015/08/14 19:16:53.236067,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.236087,  4, pid=12342, 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
>[2015/08/14 19:16:53.236112,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.236132,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.236166, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: maximum password age, val: -1
>[2015/08/14 19:16:53.236191,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.236214,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc)
>  Finding user julie
>[2015/08/14 19:16:53.236234,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is julie
>[2015/08/14 19:16:53.236291,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [julie]!
>[2015/08/14 19:16:53.236332, 10, pid=12342, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:296(gencache_set_data_blob)
>  Adding cache entry with key=[IDMAP/GID2SID/100] and timeout=[Thu Jan  1 09:30:00 1970 ACST] (-1439545613 seconds in the past)
>[2015/08/14 19:16:53.236992,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1212(gid_to_sid)
>  gid_to_sid: winbind failed to find a sid for gid 100
>[2015/08/14 19:16:53.237054,  4, pid=12342, 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
>[2015/08/14 19:16:53.237078,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.237100,  4, pid=12342, 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
>[2015/08/14 19:16:53.237122,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.237143,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.237189,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.237214, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1075(legacy_gid_to_sid)
>  LEGACY: gid 100 -> sid S-1-22-2-100
>[2015/08/14 19:16:53.237244,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1560(get_primary_group_sid)
>  Forcing Primary Group to 'Domain Users' for julie
>[2015/08/14 19:16:53.237268,  4, pid=12342, 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
>[2015/08/14 19:16:53.237290,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.237311,  4, pid=12342, 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
>[2015/08/14 19:16:53.237333,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.237353,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.237389, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.237422,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.237452, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username)
>  pdb_set_username: setting username julie, was 
>[2015/08/14 19:16:53.237475, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain)
>  pdb_set_domain: setting domain NAS, was 
>[2015/08/14 19:16:53.237496, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username , was 
>[2015/08/14 19:16:53.237518, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname)
>  pdb_set_full_name: setting full name Julie Niedzwiecki, was 
>[2015/08/14 19:16:53.237541,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.237567, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir)
>  pdb_set_homedir: setting home dir \\nas\julie, was 
>[2015/08/14 19:16:53.237590, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive , was NULL
>[2015/08/14 19:16:53.237612, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2015/08/14 19:16:53.237635,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.237658, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path \\nas\julie\profile, was 
>[2015/08/14 19:16:53.237680, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2015/08/14 19:16:53.237703,  4, pid=12342, 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
>[2015/08/14 19:16:53.237725,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.237746,  4, pid=12342, 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
>[2015/08/14 19:16:53.237767,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.237787,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.237823, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.237848,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.237870, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2926930320-515016158-3918064283-1001
>[2015/08/14 19:16:53.237894, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2926930320-515016158-3918064283-1001 from rid 1001
>[2015/08/14 19:16:53.237928, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:557(pdb_set_group_sid)
>  pdb_set_group_sid: setting group sid S-1-5-21-2926930320-515016158-3918064283-513
>[2015/08/14 19:16:53.237963,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2015/08/14 19:16:53.238005,  3, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/dom_sid.c:208(dom_sid_parse_endp)
>  string_to_sid: SID psmedley is not in a valid format
>[2015/08/14 19:16:53.238032, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:77(lookup_name)
>  lookup_name: NAS\psmedley => domain=[NAS], name=[psmedley]
>[2015/08/14 19:16:53.238054, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:78(lookup_name)
>  lookup_name: flags = 0x073
>[2015/08/14 19:16:53.238077,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.238098,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2015/08/14 19:16:53.238119,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.238140,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.238161,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.238203, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username)
>  pdb_set_username: setting username psmedley, was 
>[2015/08/14 19:16:53.238227, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain)
>  pdb_set_domain: setting domain NAS, was 
>[2015/08/14 19:16:53.238248, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username , was 
>[2015/08/14 19:16:53.238269, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname)
>  pdb_set_full_name: setting full name Paul Smedley, was 
>[2015/08/14 19:16:53.238291,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.238316, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir)
>  pdb_set_homedir: setting home dir \\nas\psmedley, was 
>[2015/08/14 19:16:53.238338, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive , was NULL
>[2015/08/14 19:16:53.238360, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2015/08/14 19:16:53.238382,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.238405, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path \\nas\psmedley\profile, was 
>[2015/08/14 19:16:53.238427, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2015/08/14 19:16:53.238449,  4, pid=12342, 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
>[2015/08/14 19:16:53.238471,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.238492,  4, pid=12342, 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
>[2015/08/14 19:16:53.238518,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.238540,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.238575, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.238601,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.238623, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2926930320-515016158-3918064283-1000
>[2015/08/14 19:16:53.238646, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2926930320-515016158-3918064283-1000 from rid 1000
>[2015/08/14 19:16:53.238679,  4, pid=12342, 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
>[2015/08/14 19:16:53.238701,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.238722,  4, pid=12342, 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
>[2015/08/14 19:16:53.238743,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.238763,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.238798, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: maximum password age, val: -1
>[2015/08/14 19:16:53.238823,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.238846,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc)
>  Finding user psmedley
>[2015/08/14 19:16:53.238868,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is psmedley
>[2015/08/14 19:16:53.238890,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [psmedley]!
>[2015/08/14 19:16:53.238922,  4, pid=12342, 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
>[2015/08/14 19:16:53.238945,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.238966,  4, pid=12342, 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
>[2015/08/14 19:16:53.238987,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.239007,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.239046,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.239069, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1075(legacy_gid_to_sid)
>  LEGACY: gid 1000 -> sid S-1-22-2-1000
>[2015/08/14 19:16:53.239102,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1560(get_primary_group_sid)
>  Forcing Primary Group to 'Domain Users' for psmedley
>[2015/08/14 19:16:53.239125,  4, pid=12342, 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
>[2015/08/14 19:16:53.239147,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.239168,  4, pid=12342, 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
>[2015/08/14 19:16:53.239189,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.239209,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.239243, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.239268,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.239294, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username)
>  pdb_set_username: setting username psmedley, was 
>[2015/08/14 19:16:53.239317, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain)
>  pdb_set_domain: setting domain NAS, was 
>[2015/08/14 19:16:53.239338, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username , was 
>[2015/08/14 19:16:53.239359, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname)
>  pdb_set_full_name: setting full name Paul Smedley, was 
>[2015/08/14 19:16:53.239381,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.239405, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir)
>  pdb_set_homedir: setting home dir \\nas\psmedley, was 
>[2015/08/14 19:16:53.239427, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive , was NULL
>[2015/08/14 19:16:53.239449, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2015/08/14 19:16:53.239471,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.239494, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path \\nas\psmedley\profile, was 
>[2015/08/14 19:16:53.239516, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2015/08/14 19:16:53.239538,  4, pid=12342, 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
>[2015/08/14 19:16:53.239560,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.239581,  4, pid=12342, 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
>[2015/08/14 19:16:53.239601,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.239627,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.239663, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.239688,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.239711, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2926930320-515016158-3918064283-1000
>[2015/08/14 19:16:53.239733, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2926930320-515016158-3918064283-1000 from rid 1000
>[2015/08/14 19:16:53.239766, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:557(pdb_set_group_sid)
>  pdb_set_group_sid: setting group sid S-1-5-21-2926930320-515016158-3918064283-513
>[2015/08/14 19:16:53.239794,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2015/08/14 19:16:53.239820, 10, pid=12342, 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 Public is read-write for unix user nobody
>[2015/08/14 19:16:53.239853, 10, pid=12342, 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
>[2015/08/14 19:16:53.239878,  3, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:113(vfs_init_default)
>  Initialising default vfs hooks
>[2015/08/14 19:16:53.239899,  3, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:139(vfs_init_custom)
>  Initialising custom vfs hooks from [/[Default VFS]/]
>[2015/08/14 19:16:53.239921, 10, pid=12342, 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
>[2015/08/14 19:16:53.239990,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:293(messaging_register)
>  Registering messaging pointer for type 784 - private_data=0x7f7a4623f730
>[2015/08/14 19:16:53.240026, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:163(set_conn_connectpath)
>  set_conn_connectpath: service Public, connectpath = /NAS/Public
>[2015/08/14 19:16:53.240053, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/share_access.c:237(user_ok_token)
>  user_ok_token: share Public is ok for unix user nobody
>[2015/08/14 19:16:53.240079,  3, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/dom_sid.c:208(dom_sid_parse_endp)
>  string_to_sid: SID julie is not in a valid format
>[2015/08/14 19:16:53.240102, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:77(lookup_name)
>  lookup_name: NAS\julie => domain=[NAS], name=[julie]
>[2015/08/14 19:16:53.240123, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:78(lookup_name)
>  lookup_name: flags = 0x073
>[2015/08/14 19:16:53.240146,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.240167,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2015/08/14 19:16:53.240188,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.240209,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.240234,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.240275, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username)
>  pdb_set_username: setting username julie, was 
>[2015/08/14 19:16:53.240299, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain)
>  pdb_set_domain: setting domain NAS, was 
>[2015/08/14 19:16:53.240322, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username , was 
>[2015/08/14 19:16:53.240343, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname)
>  pdb_set_full_name: setting full name Julie Niedzwiecki, was 
>[2015/08/14 19:16:53.240366,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.240391, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir)
>  pdb_set_homedir: setting home dir \\nas\julie, was 
>[2015/08/14 19:16:53.240413, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive , was NULL
>[2015/08/14 19:16:53.240435, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2015/08/14 19:16:53.240458,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.240481, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path \\nas\julie\profile, was 
>[2015/08/14 19:16:53.240504, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2015/08/14 19:16:53.240526,  4, pid=12342, 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
>[2015/08/14 19:16:53.240548,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.240569,  4, pid=12342, 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
>[2015/08/14 19:16:53.240774,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.240805,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.240843, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.240869,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.240892, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2926930320-515016158-3918064283-1001
>[2015/08/14 19:16:53.240916, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2926930320-515016158-3918064283-1001 from rid 1001
>[2015/08/14 19:16:53.240949,  4, pid=12342, 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
>[2015/08/14 19:16:53.240977,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.240998,  4, pid=12342, 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
>[2015/08/14 19:16:53.241019,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.241040,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.241077, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: maximum password age, val: -1
>[2015/08/14 19:16:53.241102,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.241125,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc)
>  Finding user julie
>[2015/08/14 19:16:53.241146,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is julie
>[2015/08/14 19:16:53.241170,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [julie]!
>[2015/08/14 19:16:53.241199,  4, pid=12342, 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
>[2015/08/14 19:16:53.241221,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.241242,  4, pid=12342, 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
>[2015/08/14 19:16:53.241263,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.241283,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.241322,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.241346, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1075(legacy_gid_to_sid)
>  LEGACY: gid 100 -> sid S-1-22-2-100
>[2015/08/14 19:16:53.241374,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1560(get_primary_group_sid)
>  Forcing Primary Group to 'Domain Users' for julie
>[2015/08/14 19:16:53.241397,  4, pid=12342, 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
>[2015/08/14 19:16:53.241419,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.241440,  4, pid=12342, 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
>[2015/08/14 19:16:53.241461,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.241481,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.241515, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.241540,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.241571, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username)
>  pdb_set_username: setting username julie, was 
>[2015/08/14 19:16:53.241594, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain)
>  pdb_set_domain: setting domain NAS, was 
>[2015/08/14 19:16:53.241615, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username , was 
>[2015/08/14 19:16:53.241637, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname)
>  pdb_set_full_name: setting full name Julie Niedzwiecki, was 
>[2015/08/14 19:16:53.241659,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.241684, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir)
>  pdb_set_homedir: setting home dir \\nas\julie, was 
>[2015/08/14 19:16:53.241707, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive , was NULL
>[2015/08/14 19:16:53.241729, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2015/08/14 19:16:53.241751,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.241775, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path \\nas\julie\profile, was 
>[2015/08/14 19:16:53.241797, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2015/08/14 19:16:53.241819,  4, pid=12342, 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
>[2015/08/14 19:16:53.241841,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.241862,  4, pid=12342, 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
>[2015/08/14 19:16:53.241883,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.241904,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.241939, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.241964,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.241987, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2926930320-515016158-3918064283-1001
>[2015/08/14 19:16:53.242010, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2926930320-515016158-3918064283-1001 from rid 1001
>[2015/08/14 19:16:53.242042, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:557(pdb_set_group_sid)
>  pdb_set_group_sid: setting group sid S-1-5-21-2926930320-515016158-3918064283-513
>[2015/08/14 19:16:53.242071,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2015/08/14 19:16:53.242104,  3, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/dom_sid.c:208(dom_sid_parse_endp)
>  string_to_sid: SID psmedley is not in a valid format
>[2015/08/14 19:16:53.242129, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:77(lookup_name)
>  lookup_name: NAS\psmedley => domain=[NAS], name=[psmedley]
>[2015/08/14 19:16:53.242151, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:78(lookup_name)
>  lookup_name: flags = 0x073
>[2015/08/14 19:16:53.242173,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.242195,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2015/08/14 19:16:53.242216,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.242237,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.242257,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.242297, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username)
>  pdb_set_username: setting username psmedley, was 
>[2015/08/14 19:16:53.242321, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain)
>  pdb_set_domain: setting domain NAS, was 
>[2015/08/14 19:16:53.242342, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username , was 
>[2015/08/14 19:16:53.242364, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname)
>  pdb_set_full_name: setting full name Paul Smedley, was 
>[2015/08/14 19:16:53.242386,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.242410, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir)
>  pdb_set_homedir: setting home dir \\nas\psmedley, was 
>[2015/08/14 19:16:53.242432, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive , was NULL
>[2015/08/14 19:16:53.242454, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2015/08/14 19:16:53.242476,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.242499, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path \\nas\psmedley\profile, was 
>[2015/08/14 19:16:53.242522, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2015/08/14 19:16:53.242544,  4, pid=12342, 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
>[2015/08/14 19:16:53.242565,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.242586,  4, pid=12342, 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
>[2015/08/14 19:16:53.242607,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.242632,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.242667, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.242692,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.242715, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2926930320-515016158-3918064283-1000
>[2015/08/14 19:16:53.242738, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2926930320-515016158-3918064283-1000 from rid 1000
>[2015/08/14 19:16:53.242770,  4, pid=12342, 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
>[2015/08/14 19:16:53.242792,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.242813,  4, pid=12342, 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
>[2015/08/14 19:16:53.242834,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.242854,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.242889, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: maximum password age, val: -1
>[2015/08/14 19:16:53.242914,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.242936,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc)
>  Finding user psmedley
>[2015/08/14 19:16:53.242957,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is psmedley
>[2015/08/14 19:16:53.242979,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [psmedley]!
>[2015/08/14 19:16:53.243009,  4, pid=12342, 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
>[2015/08/14 19:16:53.243032,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.243053,  4, pid=12342, 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
>[2015/08/14 19:16:53.243074,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.243094,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.243134,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.243157, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1075(legacy_gid_to_sid)
>  LEGACY: gid 1000 -> sid S-1-22-2-1000
>[2015/08/14 19:16:53.243186,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1560(get_primary_group_sid)
>  Forcing Primary Group to 'Domain Users' for psmedley
>[2015/08/14 19:16:53.243213,  4, pid=12342, 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
>[2015/08/14 19:16:53.243235,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.243256,  4, pid=12342, 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
>[2015/08/14 19:16:53.243277,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.243297,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.243332, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.243356,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.243382, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username)
>  pdb_set_username: setting username psmedley, was 
>[2015/08/14 19:16:53.243404, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain)
>  pdb_set_domain: setting domain NAS, was 
>[2015/08/14 19:16:53.243426, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username , was 
>[2015/08/14 19:16:53.243447, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname)
>  pdb_set_full_name: setting full name Paul Smedley, was 
>[2015/08/14 19:16:53.243469,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.243494, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir)
>  pdb_set_homedir: setting home dir \\nas\psmedley, was 
>[2015/08/14 19:16:53.243515, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive , was NULL
>[2015/08/14 19:16:53.243537, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2015/08/14 19:16:53.243559,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server)
>  Home server: nas
>[2015/08/14 19:16:53.243583, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path \\nas\psmedley\profile, was 
>[2015/08/14 19:16:53.243605, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2015/08/14 19:16:53.243627,  4, pid=12342, 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
>[2015/08/14 19:16:53.243649,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:485(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.243669,  4, pid=12342, 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
>[2015/08/14 19:16:53.243690,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.243711,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.243752, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:354(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2015/08/14 19:16:53.243777,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2015/08/14 19:16:53.243800, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2926930320-515016158-3918064283-1000
>[2015/08/14 19:16:53.243823, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2926930320-515016158-3918064283-1000 from rid 1000
>[2015/08/14 19:16:53.243855, 10, pid=12342, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:557(pdb_set_group_sid)
>  pdb_set_group_sid: setting group sid S-1-5-21-2926930320-515016158-3918064283-513
>[2015/08/14 19:16:53.243885,  4, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:424(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2015/08/14 19:16:53.243911, 10, pid=12342, 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 Public is read-write for unix user nobody
>[2015/08/14 19:16:53.243942, 10, pid=12342, 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
>[2015/08/14 19:16:53.243997,  4, pid=12342, 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
>[2015/08/14 19:16:53.244023,  5, pid=12342, 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-2926930320-515016158-3918064283-501
>    SID[  1]: S-1-5-21-2926930320-515016158-3918064283-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):
>[2015/08/14 19:16:53.244128,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 65534
>  Primary group is 65534 and contains 1 supplementary groups
>  Group[  0]: 65534
>[2015/08/14 19:16:53.244172,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:363(change_to_user_internal)
>  Impersonated user: uid=(65534,65534), gid=(0,65534)
>[2015/08/14 19:16:53.244199,  4, pid=12342, 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
>[2015/08/14 19:16:53.244221,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.244241,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.244275,  5, pid=12342, 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)
>[2015/08/14 19:16:53.244303, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:163(set_conn_connectpath)
>  set_conn_connectpath: service Public, connectpath = /NAS/Public
>[2015/08/14 19:16:53.244345, 10, pid=12342, 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 Public, directory /NAS/Public
>[2015/08/14 19:16:53.244371,  2, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:856(make_connection_snum)
>  thinkpad-t510 (ipv4:192.168.1.83:37338) connect to service Public initially as user nobody (uid=65534, gid=65534) (pid 12342)
>[2015/08/14 19:16:53.244409,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:187(dbwrap_check_lock_order)
>  check lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.244432, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:/var/run/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none>
>[2015/08/14 19:16:53.244457, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 0BCD3490
>[2015/08/14 19:16:53.244482, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f7a4623ba80
>[2015/08/14 19:16:53.244512, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:672(smbXsrv_tcon_global_store)
>[2015/08/14 19:16:53.244526, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:674(smbXsrv_tcon_global_store)
>  smbXsrv_tcon_global_store: key '0BCD3490' stored
>[2015/08/14 19:16:53.244548,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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           : 0x0bcd3490 (197997712)
>                  tcon_wire_id             : 0x0bcd3490 (197997712)
>                  server_id: struct server_id
>                      pid                      : 0x0000000000003036 (12342)
>                      task_id                  : 0x00000000 (0)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                  creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                  share_name               : 'Public'
>                  encryption_required      : 0x00 (0)
>                  session_global_id        : 0x29b8fa1e (699988510)
>[2015/08/14 19:16:53.244772, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 0BCD3490
>[2015/08/14 19:16:53.244796,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:16:53.244818, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2015/08/14 19:16:53.244840, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:849(smbXsrv_tcon_update)
>[2015/08/14 19:16:53.244853, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_tcon.c:857(smbXsrv_tcon_update)
>  smbXsrv_tcon_update: global_id (0x0bcd3490) stored
>[2015/08/14 19:16:53.244874,  1, pid=12342, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:296(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                 : 0x0bcd3490 (197997712)
>                  global                   : *
>                      global: struct smbXsrv_tcon_global0
>                          db_rec                   : NULL
>                          tcon_global_id           : 0x0bcd3490 (197997712)
>                          tcon_wire_id             : 0x0bcd3490 (197997712)
>                          server_id: struct server_id
>                              pid                      : 0x0000000000003036 (12342)
>                              task_id                  : 0x00000000 (0)
>                              vnn                      : 0xffffffff (4294967295)
>                              unique_id                : 0x2f4f23ca02d3a14f (3408982793480544591)
>                          creation_time            : Fri Aug 14 19:16:53 2015 ACST
>                          share_name               : 'Public'
>                          encryption_required      : 0x00 (0)
>                          session_global_id        : 0x29b8fa1e (699988510)
>                  status                   : NT_STATUS_OK
>                  idle_time                : Fri Aug 14 19:16:53 2015 ACST
>                  compat                   : *
>[2015/08/14 19:16:53.245153, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2499(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:163
>[2015/08/14 19:16:53.245179, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit)
>  smb2_set_operation_credit: requested 8064, charge 1, granted 33, current possible/max 384/512, total granted/max/low/range 161/8192/10/161
>[2015/08/14 19:16:53.348082, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3257(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2015/08/14 19:16:53.348137, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:621(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 10 (position 10) from bitmap
>[2015/08/14 19:16:53.348162, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1878(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_KEEPALIVE] mid = 10
>[2015/08/14 19:16:53.348185,  4, pid=12342, 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
>[2015/08/14 19:16:53.348208,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:53.348229,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:53.348267,  5, pid=12342, 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)
>[2015/08/14 19:16:53.348291, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2499(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[4] dyn[no:0] at ../source3/smbd/smb2_keepalive.c:46
>[2015/08/14 19:16:53.348332, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit)
>  smb2_set_operation_credit: requested 8032, charge 1, granted 33, current possible/max 352/512, total granted/max/low/range 193/8192/11/193
>[2015/08/14 19:16:56.749777, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3257(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2015/08/14 19:16:56.749848, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:621(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 11 (position 11) from bitmap
>[2015/08/14 19:16:56.749874, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1878(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 11
>[2015/08/14 19:16:56.749908,  4, pid=12342, 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
>[2015/08/14 19:16:56.749933,  5, pid=12342, 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-2926930320-515016158-3918064283-501
>    SID[  1]: S-1-5-21-2926930320-515016158-3918064283-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):
>[2015/08/14 19:16:56.750052,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 65534
>  Primary group is 65534 and contains 1 supplementary groups
>  Group[  0]: 65534
>[2015/08/14 19:16:56.750106,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/uid.c:363(change_to_user_internal)
>  Impersonated user: uid=(65534,65534), gid=(0,65534)
>[2015/08/14 19:16:56.750133,  4, pid=12342, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:838(vfs_ChDir)
>  vfs_ChDir to /NAS/Public
>[2015/08/14 19:16:56.750172,  4, pid=12342, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:849(vfs_ChDir)
>  vfs_ChDir got /NAS/Public
>[2015/08/14 19:16:56.750218, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:456(smbd_smb2_create_send)
>  smbd_smb2_create: name[desktop]
>[2015/08/14 19:16:56.750250, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_create.c:768(smbd_smb2_create_send)
>  smbd_smb2_create_send: open execution phase
>[2015/08/14 19:16:56.750282,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:258(unix_convert)
>  unix_convert called on file "desktop"
>[2015/08/14 19:16:56.750308,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/filename.c:421(unix_convert)
>  unix_convert begin: name = desktop, dirpath = , start = desktop
>[2015/08/14 19:16:56.750336, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled desktop ?
>[2015/08/14 19:16:56.750358, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component desktop (len 7) ?
>[2015/08/14 19:16:56.750388,  3, pid=12342, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1137(check_reduced_name)
>  check_reduced_name [desktop] [/NAS/Public]
>[2015/08/14 19:16:56.750422, 10, pid=12342, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1197(check_reduced_name)
>  check_reduced_name realpath [desktop] -> [/NAS/Public/desktop]
>[2015/08/14 19:16:56.750449,  3, pid=12342, effective(65534, 65534), real(65534, 0), class=vfs] ../source3/smbd/vfs.c:1267(check_reduced_name)
>  check_reduced_name: desktop reduced to /NAS/Public/desktop
>[2015/08/14 19:16:56.750473, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4270(create_file_default)
>  create_file: access_mask = 0x80 file_attributes = 0x10, share_access = 0x7, create_disposition = 0x1 create_options = 0x1 oplock_request = 0x0 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = desktop
>[2015/08/14 19:16:56.750499, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:3778(create_file_unixpath)
>  create_file_unixpath: access_mask = 0x80 file_attributes = 0x10, share_access = 0x7, create_disposition = 0x1 create_options = 0x1 oplock_request = 0x0 private_flags = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = desktop
>[2015/08/14 19:16:56.750523,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:3055(open_directory)
>  open_directory: opening directory desktop, access_mask = 0x80, share_access = 0x7 create_options = 0x1, create_disposition = 0x1, file_attributes = 0x10
>[2015/08/14 19:16:56.750551, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4094(create_file_unixpath)
>  create_file_unixpath: NT_STATUS_OBJECT_NAME_NOT_FOUND
>[2015/08/14 19:16:56.750574, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/open.c:4367(create_file_default)
>  create_file: NT_STATUS_OBJECT_NAME_NOT_FOUND
>[2015/08/14 19:16:56.750605, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2598(smbd_smb2_request_error_ex)
>  smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../source3/smbd/smb2_create.c:303
>[2015/08/14 19:16:56.750631, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:2499(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] body[8] dyn[yes:1] at ../source3/smbd/smb2_server.c:2651
>[2015/08/14 19:16:56.750656, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit)
>  smb2_set_operation_credit: requested 8000, charge 1, granted 33, current possible/max 320/512, total granted/max/low/range 225/8192/12/225
>[2015/08/14 19:16:57.854738, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:3257(smbd_smb2_io_handler)
>  smbd_smb2_request idx[1] of 5 vectors
>[2015/08/14 19:16:57.854803, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:621(smb2_validate_sequence_number)
>  smb2_validate_sequence_number: clearing id 12 (position 12) from bitmap
>[2015/08/14 19:16:57.854829, 10, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/smbd/smb2_server.c:1878(smbd_smb2_request_dispatch)
>  smbd_smb2_request_dispatch: opcode[SMB2_OP_KEEPALIVE] mid = 12
>[2015/08/14 19:16:57.854854,  4, pid=12342, 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
>[2015/08/14 19:16:57.854878,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:16:57.854900,  5, pid=12342, effective(65534, 65534), real(65534, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:16:57.854944,  5, pid=12342, 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)
>[2015/08/14 19:16:57.854971, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2499(smbd_smb2_request_done_ex)
>  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[4] dyn[no:0] at ../source3/smbd/smb2_keepalive.c:46
>[2015/08/14 19:16:57.855016, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit)
>  smb2_set_operation_credit: requested 7968, charge 1, granted 33, current possible/max 288/512, total granted/max/low/range 257/8192/13/257
>[2015/08/14 19:17:01.987439,  4, pid=12342, 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
>[2015/08/14 19:17:01.987502,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:17:01.987525,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:17:01.987564,  5, pid=12342, 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)
>[2015/08/14 19:17:01.987651,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:187(dbwrap_check_lock_order)
>  check lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
>[2015/08/14 19:17:01.987675, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:/var/run/samba/smbXsrv_session_global.tdb 2:<none> 3:<none>
>[2015/08/14 19:17:01.987700, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 29B8FA1E
>[2015/08/14 19:17:01.987732, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f7a46242a20
>[2015/08/14 19:17:01.987777, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 29B8FA1E
>[2015/08/14 19:17:01.987802,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/run/samba/smbXsrv_session_global.tdb
>[2015/08/14 19:17:01.987824, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2015/08/14 19:17:01.987849,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:187(dbwrap_check_lock_order)
>  check lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:17:01.987871, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:/var/run/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none>
>[2015/08/14 19:17:01.987894, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Locking key 0BCD3490
>[2015/08/14 19:17:01.987917, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:143(db_tdb_fetch_locked_internal)
>  Allocated locked data 0x0x7f7a46242570
>[2015/08/14 19:17:01.987943, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:59(db_tdb_log_key)
>  Unlocking key 0BCD3490
>[2015/08/14 19:17:01.987965,  5, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
>  release lock order 1 for /var/run/samba/smbXsrv_tcon_global.tdb
>[2015/08/14 19:17:01.987987, 10, pid=12342, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order)
>  lock order:  1:<none> 2:<none> 3:<none>
>[2015/08/14 19:17:01.988013,  4, pid=12342, 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
>[2015/08/14 19:17:01.988034,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:17:01.988055,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:17:01.988648,  5, pid=12342, 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)
>[2015/08/14 19:17:01.988679,  1, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/service.c:1130(close_cnum)
>  thinkpad-t510 (ipv4:192.168.1.83:37338) closed connection to service Public
>[2015/08/14 19:17:01.988911,  4, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:838(vfs_ChDir)
>  vfs_ChDir to /
>[2015/08/14 19:17:01.988947,  4, pid=12342, effective(0, 0), real(0, 0), class=vfs] ../source3/smbd/vfs.c:849(vfs_ChDir)
>  vfs_ChDir got /
>[2015/08/14 19:17:01.988971,  4, pid=12342, 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
>[2015/08/14 19:17:01.988993,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:17:01.989013,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:17:01.989046,  5, pid=12342, 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)
>[2015/08/14 19:17:01.989092,  4, pid=12342, effective(0, 0), real(0, 0), class=auth] ../source3/auth/pampass.c:483(smb_pam_start)
>  smb_pam_start: PAM: Init user: nobody
>[2015/08/14 19:17:01.992284,  4, pid=12342, effective(0, 0), real(0, 0), class=auth] ../source3/auth/pampass.c:492(smb_pam_start)
>  smb_pam_start: PAM: setting rhost to: 192.168.1.83
>[2015/08/14 19:17:01.992334,  4, pid=12342, effective(0, 0), real(0, 0), class=auth] ../source3/auth/pampass.c:501(smb_pam_start)
>  smb_pam_start: PAM: setting tty
>[2015/08/14 19:17:01.992367,  4, pid=12342, effective(0, 0), real(0, 0), class=auth] ../source3/auth/pampass.c:509(smb_pam_start)
>  smb_pam_start: PAM: Init passed for user: nobody
>[2015/08/14 19:17:01.992388,  4, pid=12342, effective(0, 0), real(0, 0), class=auth] ../source3/auth/pampass.c:646(smb_internal_pam_session)
>  smb_internal_pam_session: PAM: tty set to: smb/699988510
>[2015/08/14 19:17:01.994678,  4, pid=12342, effective(0, 0), real(0, 0), class=auth] ../source3/auth/pampass.c:465(smb_pam_end)
>  smb_pam_end: PAM: PAM_END OK.
>[2015/08/14 19:17:01.994903,  4, pid=12342, 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
>[2015/08/14 19:17:01.994939,  5, pid=12342, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2015/08/14 19:17:01.995017,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:629(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2015/08/14 19:17:01.995066,  5, pid=12342, 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)
>[2015/08/14 19:17:01.995114,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:340(messaging_deregister)
>  Deregistering messaging pointer for type 1536 - private_data=0x7f7a4623aaf0
>[2015/08/14 19:17:01.995141, 10, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/notify_internal.c:181(notify_context_destructor)
>  notify_context_destructor called
>[2015/08/14 19:17:01.995243,  5, pid=12342, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:340(messaging_deregister)
>  Deregistering messaging pointer for type 784 - private_data=0x7f7a4623f730
>[2015/08/14 19:17:01.995334,  3, pid=12342, effective(0, 0), real(0, 0)] ../source3/smbd/server_exit.c:221(exit_server_common)
>  Server exit (termination signal)

Actions: View

Attachments on bug 11438: 11333 | 11334 | 11336 | 11929 | 12054 | 12064