Attachment 7210 Details for Bug 8660 – samba log - file upload by debian smbclient 3.6.1

samba log - file upload by debian smbclient 3.6.1

smbclient_debian_create_new_file.log (text/x-log), 119.15 KB, created by sven friedmann on 2011-12-21 09:24:05 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: sven friedmann

Created: 2011-12-21 09:24:05 UTC

Size: 119.15 KB

patch

obsolete

>[2011/12/21 10:13:52.156264,  6, pid=4175] param/loadparm.c:7490(lp_file_list_changed)
>  lp_file_list_changed()
>  file /etc/samba/smb.conf -> /etc/samba/smb.conf  last mod_time: Wed Dec 14 12:19:53 2011
>  
>[2011/12/21 10:13:52.156346,  5, pid=4175] auth/auth_util.c:110(make_user_info_map)
>  Mapping user [CIRCINT]\[adtest] from workstation [DEBIAN]
>[2011/12/21 10:13:52.156377,  4, pid=4175] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.156415,  4, pid=4175] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.156444,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.156469,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.156492,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.156532,  5, pid=4175] auth/auth_util.c:1338(is_trusted_domain)
>  is_trusted_domain: Checking for domain trust with [CIRCINT]
>[2011/12/21 10:13:52.156590, 10, pid=4175] passdb/pdb_ldap.c:6172(ldapsam_get_trusteddom_pw)
>  ldapsam_get_trusteddom_pw called for domain CIRCINT
>[2011/12/21 10:13:52.156635,  5, pid=4175] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [sambaDomainName=CIRCINT,sambaDomainName=CIRCULAR,dc=circular,dc=de], filter => [(&(objectClass=sambaTrustedDomainPassword)(sambaDomainName=CIRCINT))], scope => [2]
>[2011/12/21 10:13:52.156688,  5, pid=4175] lib/smbldap.c:1341(smbldap_close)
>  The connection to the LDAP server was closed
>[2011/12/21 10:13:52.156717, 10, pid=4175] lib/smbldap.c:819(smb_ldap_setup_conn)
>  smb_ldap_setup_connection: ldap://127.0.0.1/
>[2011/12/21 10:13:52.156851,  2, pid=4175] lib/smbldap.c:1018(smbldap_open_connection)
>  smbldap_open_connection: connection opened
>[2011/12/21 10:13:52.156885, 10, pid=4175] lib/smbldap.c:1194(smbldap_connect_system)
>  ldap_connect_system: Binding to ldap server ldap://127.0.0.1/ as "cn=root,dc=circular,dc=de"
>[2011/12/21 10:13:52.158704,  3, pid=4175] lib/smbldap.c:1240(smbldap_connect_system)
>  ldap_connect_system: successful connection to the LDAP server
>  ldap_connect_system: LDAP server does support paged results
>[2011/12/21 10:13:52.158760,  4, pid=4175] lib/smbldap.c:1319(smbldap_open)
>  The LDAP server is successfully connected
>[2011/12/21 10:13:52.159607, 10, pid=4175] lib/smbldap.c:1504(smbldap_search_ext)
>  Failed search for base: sambaDomainName=CIRCINT,sambaDomainName=CIRCULAR,dc=circular,dc=de, error: 32 (No such object) ()
>[2011/12/21 10:13:52.159755,  4, pid=4175] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.159834,  5, pid=4175] libsmb/trustdom_cache.c:160(trustdom_cache_fetch)
>  no entry for trusted domain CIRCINT found.
>[2011/12/21 10:13:52.159871,  5, pid=4175] auth/auth_util.c:131(make_user_info_map)
>  Mapped domain from [CIRCINT] to [CIRCULAR] for user [adtest] from workstation [DEBIAN]
>[2011/12/21 10:13:52.159903,  5, pid=4175] auth/user_info.c:59(make_user_info)
>  attempting to make a user_info for adtest (adtest)
>[2011/12/21 10:13:52.159929,  5, pid=4175] auth/user_info.c:70(make_user_info)
>  making strings for adtest's user_info struct
>[2011/12/21 10:13:52.159955,  5, pid=4175] auth/user_info.c:87(make_user_info)
>  making blobs for adtest's user_info struct
>[2011/12/21 10:13:52.160016, 10, pid=4175] auth/user_info.c:123(make_user_info)
>  made a user_info for adtest (adtest)
>[2011/12/21 10:13:52.160053,  3, pid=4175] auth/auth.c:219(check_ntlm_password)
>  check_ntlm_password:  Checking password for unmapped user [CIRCINT]\[adtest]@[DEBIAN] with the new password interface
>[2011/12/21 10:13:52.160079,  3, pid=4175] auth/auth.c:222(check_ntlm_password)
>  check_ntlm_password:  mapped user is: [CIRCULAR]\[adtest]@[DEBIAN]
>[2011/12/21 10:13:52.160103, 10, pid=4175] auth/auth.c:231(check_ntlm_password)
>  check_ntlm_password: auth_context challenge created by random
>[2011/12/21 10:13:52.160140, 10, pid=4175] auth/auth.c:233(check_ntlm_password)
>  challenge is: 
>[2011/12/21 10:13:52.160165,  5, pid=4175] ../lib/util/util.c:415(dump_data)
>  [0000] 2E 9E 97 9F EA 96 8A 00                            ........ 
>[2011/12/21 10:13:52.160200, 10, pid=4175] auth/auth_builtin.c:44(check_guest_security)
>  Check auth for: [adtest]
>[2011/12/21 10:13:52.160223, 10, pid=4175] auth/auth.c:259(check_ntlm_password)
>  check_ntlm_password: guest had nothing to say
>[2011/12/21 10:13:52.160249, 10, pid=4175] auth/auth_sam.c:75(auth_samstrict_auth)
>  Check auth for: [adtest]
>[2011/12/21 10:13:52.160277,  8, pid=4175] lib/util.c:1521(is_myname)
>  is_myname("CIRCULAR") returns 0
>[2011/12/21 10:13:52.160306,  4, pid=4175] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.160331,  4, pid=4175] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.160355,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.160382,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.160406,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.160493,  5, pid=4175] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(uid=adtest)(objectclass=sambaSamAccount))], scope => [2]
>[2011/12/21 10:13:52.177750,  2, pid=4175] passdb/pdb_ldap.c:553(init_sam_from_ldap)
>  init_sam_from_ldap: Entry found for user: adtest
>[2011/12/21 10:13:52.177801, 10, pid=4175] passdb/pdb_get_set.c:545(pdb_set_username)
>  pdb_set_username: setting username adtest, was 
>[2011/12/21 10:13:52.177840, 10, pid=4175] passdb/pdb_get_set.c:568(pdb_set_domain)
>  pdb_set_domain: setting domain CIRCULAR, was 
>[2011/12/21 10:13:52.177869, 10, pid=4175] passdb/pdb_get_set.c:591(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username adtest, was 
>[2011/12/21 10:13:52.177912, 10, pid=4175] passdb/pdb_get_set.c:483(pdb_set_user_sid_from_string)
>  pdb_set_user_sid_from_string: setting user sid S-1-5-21-2132208240-841620863-785830102-3258
>[2011/12/21 10:13:52.177950, 10, pid=4175] passdb/pdb_get_set.c:470(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2132208240-841620863-785830102-3258
>[2011/12/21 10:13:52.178026, 10, pid=4175] passdb/pdb_get_set.c:614(pdb_set_fullname)
>  pdb_set_full_name: setting full name adtest, was 
>[2011/12/21 10:13:52.178068, 10, pid=4175] passdb/pdb_get_set.c:683(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive H:, was NULL
>[2011/12/21 10:13:52.178106, 10, pid=4175] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaHomePath does not exist
>[2011/12/21 10:13:52.178133, 10, pid=4175] passdb/pdb_get_set.c:707(pdb_set_homedir)
>  pdb_set_homedir: setting home dir , was 
>[2011/12/21 10:13:52.178166, 10, pid=4175] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaLogonScript does not exist
>[2011/12/21 10:13:52.178199, 10, pid=4175] passdb/pdb_get_set.c:637(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2011/12/21 10:13:52.178233, 10, pid=4175] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaProfilePath does not exist
>[2011/12/21 10:13:52.178258, 10, pid=4175] passdb/pdb_get_set.c:660(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path , was 
>[2011/12/21 10:13:52.178297, 10, pid=4175] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute description does not exist
>[2011/12/21 10:13:52.178331, 10, pid=4175] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaUserWorkstations does not exist
>[2011/12/21 10:13:52.178363, 10, pid=4175] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaMungedDial does not exist
>[2011/12/21 10:13:52.178411,  4, pid=4175] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:13:52.178443,  4, pid=4175] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.178467,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:13:52.178491,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.178514,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.178610,  4, pid=4175] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.178660, 10, pid=4175] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaBadPasswordCount does not exist
>[2011/12/21 10:13:52.178695, 10, pid=4175] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaBadPasswordTime does not exist
>[2011/12/21 10:13:52.178730, 10, pid=4175] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaLogonHours does not exist
>[2011/12/21 10:13:52.178779,  7, pid=4175] passdb/login_cache.c:91(login_cache_read)
>  Looking up login cache for user adtest
>[2011/12/21 10:13:52.178818,  7, pid=4175] passdb/login_cache.c:102(login_cache_read)
>  No cache entry found
>[2011/12/21 10:13:52.178844,  9, pid=4175] passdb/pdb_ldap.c:1107(init_sam_from_ldap)
>  No cache entry, bad count = 0, bad time = 0
>[2011/12/21 10:13:52.178886,  5, pid=4175] lib/username.c:171(Get_Pwnam_alloc)
>  Finding user adtest
>[2011/12/21 10:13:52.178921,  5, pid=4175] lib/username.c:116(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is adtest
>[2011/12/21 10:13:52.179006,  5, pid=4175] lib/username.c:149(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [adtest]!
>[2011/12/21 10:13:52.179046,  4, pid=4175] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:13:52.179072,  4, pid=4175] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.179102,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:13:52.179126,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.179149,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.179206,  4, pid=4175] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.179258, 10, pid=4175] passdb/pdb_get_set.c:545(pdb_set_username)
>  pdb_set_username: setting username adtest, was 
>[2011/12/21 10:13:52.179285, 10, pid=4175] passdb/pdb_get_set.c:568(pdb_set_domain)
>  pdb_set_domain: setting domain CIRCULAR, was 
>[2011/12/21 10:13:52.179309, 10, pid=4175] passdb/pdb_get_set.c:591(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username adtest, was 
>[2011/12/21 10:13:52.179333, 10, pid=4175] passdb/pdb_get_set.c:614(pdb_set_fullname)
>  pdb_set_full_name: setting full name adtest, was 
>[2011/12/21 10:13:52.179367, 10, pid=4175] passdb/pdb_get_set.c:707(pdb_set_homedir)
>  pdb_set_homedir: setting home dir , was 
>[2011/12/21 10:13:52.179393, 10, pid=4175] passdb/pdb_get_set.c:683(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive H:, was NULL
>[2011/12/21 10:13:52.179418, 10, pid=4175] passdb/pdb_get_set.c:637(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2011/12/21 10:13:52.179443, 10, pid=4175] passdb/pdb_get_set.c:660(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path , was 
>[2011/12/21 10:13:52.179472, 10, pid=4175] passdb/pdb_get_set.c:750(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2011/12/21 10:13:52.179499,  4, pid=4175] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:13:52.179524,  4, pid=4175] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.179553,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:13:52.179580,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.179603,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.179659,  4, pid=4175] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.179693, 10, pid=4175] passdb/pdb_get_set.c:470(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2132208240-841620863-785830102-3258
>[2011/12/21 10:13:52.179721, 10, pid=4175] passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2132208240-841620863-785830102-3258 from rid 3258
>[2011/12/21 10:13:52.179766, 10, pid=4175] passdb/pdb_get_set.c:532(pdb_set_group_sid)
>  pdb_set_group_sid: setting group sid S-1-5-21-2132208240-841620863-785830102-513
>[2011/12/21 10:13:52.179809,  4, pid=4175] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.179847,  4, pid=4175] ../libcli/auth/ntlm_check.c:351(ntlm_password_check)
>  ntlm_password_check: Checking NTLMv2 password with domain [CIRCINT]
>[2011/12/21 10:13:52.179898,  4, pid=4175] ../libcli/auth/ntlm_check.c:365(ntlm_password_check)
>  ntlm_password_check: Checking NTLMv2 password with uppercased version of domain [CIRCINT]
>[2011/12/21 10:13:52.179942,  4, pid=4175] ../libcli/auth/ntlm_check.c:379(ntlm_password_check)
>  ntlm_password_check: Checking NTLMv2 password without a domain
>[2011/12/21 10:13:52.180011,  3, pid=4175] ../libcli/auth/ntlm_check.c:392(ntlm_password_check)
>  ntlm_password_check: NTLMv2 password check failed
>[2011/12/21 10:13:52.180046,  3, pid=4175] ../libcli/auth/ntlm_check.c:437(ntlm_password_check)
>  ntlm_password_check: Lanman passwords NOT PERMITTED for user adtest
>[2011/12/21 10:13:52.180071,  4, pid=4175] ../libcli/auth/ntlm_check.c:473(ntlm_password_check)
>  ntlm_password_check: Checking LMv2 password with domain CIRCINT
>[2011/12/21 10:13:52.180114,  4, pid=4175] ../libcli/auth/ntlm_check.c:503(ntlm_password_check)
>  ntlm_password_check: Checking LMv2 password with upper-cased version of domain CIRCINT
>[2011/12/21 10:13:52.180150,  4, pid=4175] ../libcli/auth/ntlm_check.c:533(ntlm_password_check)
>  ntlm_password_check: Checking LMv2 password without a domain
>[2011/12/21 10:13:52.180185,  4, pid=4175] ../libcli/auth/ntlm_check.c:566(ntlm_password_check)
>  ntlm_password_check: Checking NT MD4 password in LM field
>[2011/12/21 10:13:52.180345,  3, pid=4175] ../libcli/auth/ntlm_check.c:585(ntlm_password_check)
>  ntlm_password_check: LM password, NT MD4 password in LM field and LMv2 failed for user adtest
>[2011/12/21 10:13:52.180373,  4, pid=4175] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.180398,  4, pid=4175] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.180427,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.180450,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.180474,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.180532,  4, pid=4175] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.180567,  4, pid=4175] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.180592,  4, pid=4175] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.180616,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.180639,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.180674,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.180715,  4, pid=4175] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:13:52.180739,  4, pid=4175] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.180762,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:13:52.180792,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.180816,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.180866, 10, pid=4175] lib/gencache.c:183(gencache_set_data_blob)
>  Adding cache entry with key = ACCT_POL/bad lockout attempt and timeout = Thu Jan  1 01:00:00 1970
>   (-1324458832 seconds in the past)
>[2011/12/21 10:13:52.180955, 10, pid=4175] passdb/pdb_ldap.c:3965(ldapsam_get_account_policy_from_ldap)
>  ldapsam_get_account_policy_from_ldap
>[2011/12/21 10:13:52.180988,  5, pid=4175] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [sambaDomainName=CIRCULAR,dc=circular,dc=de], filter => [(objectClass=sambaDomain)], scope => [0]
>[2011/12/21 10:13:52.181857, 10, pid=4175] passdb/account_pol.c:402(cache_account_policy_set)
>  cache_account_policy_set: updating account pol cache
>[2011/12/21 10:13:52.181905, 10, pid=4175] lib/gencache.c:183(gencache_set_data_blob)
>  Adding cache entry with key = ACCT_POL/bad lockout attempt and timeout = Wed Dec 21 10:14:52 2011
>   (60 seconds ahead)
>[2011/12/21 10:13:52.181964,  4, pid=4175] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.181997,  4, pid=4175] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.182027,  9, pid=4175] passdb/passdb.c:2253(pdb_increment_bad_password_count)
>  No lockout policy, don't track bad passwords
>[2011/12/21 10:13:52.182053,  4, pid=4175] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.182077,  4, pid=4175] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.182100,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:13:52.182128,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.182152,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.182222,  4, pid=4175] passdb/pdb_ldap.c:1997(ldapsam_update_sam_account)
>  ldapsam_update_sam_account: user adtest to be modified has dn: uid=adtest,ou=people,dc=circular,dc=de
>[2011/12/21 10:13:52.182256,  2, pid=4175] passdb/pdb_ldap.c:1180(init_ldap_from_sam)
>  init_ldap_from_sam: Setting entry for user: adtest
>[2011/12/21 10:13:52.182294,  4, pid=4175] passdb/pdb_ldap.c:2011(ldapsam_update_sam_account)
>  ldapsam_update_sam_account: mods is empty: nothing to update for user: adtest
>[2011/12/21 10:13:52.182326,  4, pid=4175] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.182355,  5, pid=4175] auth/auth.c:271(check_ntlm_password)
>  check_ntlm_password: sam authentication for user [adtest] FAILED with error NT_STATUS_WRONG_PASSWORD
>[2011/12/21 10:13:52.182403, 10, pid=4175] auth/auth_winbind.c:50(check_winbind_security)
>  Check auth for: [adtest]
>[2011/12/21 10:13:52.182428,  3, pid=4175] auth/auth_winbind.c:60(check_winbind_security)
>  check_winbind_security: Not using winbind, requested domain [CIRCULAR] was for this SAM.
>[2011/12/21 10:13:52.182455, 10, pid=4175] auth/auth.c:259(check_ntlm_password)
>  check_ntlm_password: winbind had nothing to say
>[2011/12/21 10:13:52.182486,  2, pid=4175] auth/auth.c:319(check_ntlm_password)
>  check_ntlm_password:  Authentication for user [adtest] -> [adtest] FAILED with error NT_STATUS_WRONG_PASSWORD
>[2011/12/21 10:13:52.182527,  3, pid=4175] smbd/error.c:81(error_packet_set)
>  error packet at smbd/sesssetup.c(124) cmd=115 (SMBsesssetupX) NT_STATUS_LOGON_FAILURE
>[2011/12/21 10:13:52.182562,  5, pid=4175] lib/util.c:332(show_msg)
>[2011/12/21 10:13:52.182578,  5, pid=4175] lib/util.c:342(show_msg)
>  size=35
>  smb_com=0x73
>  smb_rcls=109
>  smb_reh=0
>  smb_err=49152
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=65535
>  smb_pid=13820
>  smb_uid=100
>  smb_mid=3
>  smt_wct=0
>  smb_bcc=0
>[2011/12/21 10:13:52.182716, 10, pid=4175] ../lib/util/util.c:415(dump_data)
>[2011/12/21 10:13:52.183510,  5, pid=4175] lib/util_sock.c:316(read_fd_with_timeout)
>  read_fd_with_timeout: blocking read. EOF from client.
>[2011/12/21 10:13:52.183549,  1, pid=4175] smbd/process.c:456(receive_smb_talloc)
>  read_smb_length_return_keepalive failed for client 10.1.3.49 read error = NT_STATUS_END_OF_FILE.
>[2011/12/21 10:13:52.183589,  4, pid=4175] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:13:52.183615,  5, pid=4175] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:13:52.183639,  5, pid=4175] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:13:52.183678,  5, pid=4175] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:13:52.183822,  3, pid=4175] smbd/server_exit.c:180(exit_server_common)
>  Server exit (failed to receive smb request)
>[2011/12/21 10:14:02.932559,  6, pid=4176] param/loadparm.c:7490(lp_file_list_changed)
>  lp_file_list_changed()
>  file /etc/samba/smb.conf -> /etc/samba/smb.conf  last mod_time: Wed Dec 14 12:19:53 2011
>  
>[2011/12/21 10:14:02.932636,  5, pid=4176] auth/auth_util.c:110(make_user_info_map)
>  Mapping user [CIRCINT]\[adtest] from workstation [DEBIAN]
>[2011/12/21 10:14:02.932678,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.932716,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:02.932742,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.932766,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.932795,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.932835,  5, pid=4176] auth/auth_util.c:1338(is_trusted_domain)
>  is_trusted_domain: Checking for domain trust with [CIRCINT]
>[2011/12/21 10:14:02.932890, 10, pid=4176] passdb/pdb_ldap.c:6172(ldapsam_get_trusteddom_pw)
>  ldapsam_get_trusteddom_pw called for domain CIRCINT
>[2011/12/21 10:14:02.932934,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [sambaDomainName=CIRCINT,sambaDomainName=CIRCULAR,dc=circular,dc=de], filter => [(&(objectClass=sambaTrustedDomainPassword)(sambaDomainName=CIRCINT))], scope => [2]
>[2011/12/21 10:14:02.932991,  5, pid=4176] lib/smbldap.c:1341(smbldap_close)
>  The connection to the LDAP server was closed
>[2011/12/21 10:14:02.933019, 10, pid=4176] lib/smbldap.c:819(smb_ldap_setup_conn)
>  smb_ldap_setup_connection: ldap://127.0.0.1/
>[2011/12/21 10:14:02.933156,  2, pid=4176] lib/smbldap.c:1018(smbldap_open_connection)
>  smbldap_open_connection: connection opened
>[2011/12/21 10:14:02.933189, 10, pid=4176] lib/smbldap.c:1194(smbldap_connect_system)
>  ldap_connect_system: Binding to ldap server ldap://127.0.0.1/ as "cn=root,dc=circular,dc=de"
>[2011/12/21 10:14:02.934957,  3, pid=4176] lib/smbldap.c:1240(smbldap_connect_system)
>  ldap_connect_system: successful connection to the LDAP server
>  ldap_connect_system: LDAP server does support paged results
>[2011/12/21 10:14:02.935022,  4, pid=4176] lib/smbldap.c:1319(smbldap_open)
>  The LDAP server is successfully connected
>[2011/12/21 10:14:02.935803, 10, pid=4176] lib/smbldap.c:1504(smbldap_search_ext)
>  Failed search for base: sambaDomainName=CIRCINT,sambaDomainName=CIRCULAR,dc=circular,dc=de, error: 32 (No such object) ()
>[2011/12/21 10:14:02.935939,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:02.936014,  5, pid=4176] libsmb/trustdom_cache.c:160(trustdom_cache_fetch)
>  no entry for trusted domain CIRCINT found.
>[2011/12/21 10:14:02.936060,  5, pid=4176] auth/auth_util.c:131(make_user_info_map)
>  Mapped domain from [CIRCINT] to [CIRCULAR] for user [adtest] from workstation [DEBIAN]
>[2011/12/21 10:14:02.936088,  5, pid=4176] auth/user_info.c:59(make_user_info)
>  attempting to make a user_info for adtest (adtest)
>[2011/12/21 10:14:02.936113,  5, pid=4176] auth/user_info.c:70(make_user_info)
>  making strings for adtest's user_info struct
>[2011/12/21 10:14:02.936144,  5, pid=4176] auth/user_info.c:87(make_user_info)
>  making blobs for adtest's user_info struct
>[2011/12/21 10:14:02.936170, 10, pid=4176] auth/user_info.c:123(make_user_info)
>  made a user_info for adtest (adtest)
>[2011/12/21 10:14:02.936194,  3, pid=4176] auth/auth.c:219(check_ntlm_password)
>  check_ntlm_password:  Checking password for unmapped user [CIRCINT]\[adtest]@[DEBIAN] with the new password interface
>[2011/12/21 10:14:02.936218,  3, pid=4176] auth/auth.c:222(check_ntlm_password)
>  check_ntlm_password:  mapped user is: [CIRCULAR]\[adtest]@[DEBIAN]
>[2011/12/21 10:14:02.936248, 10, pid=4176] auth/auth.c:231(check_ntlm_password)
>  check_ntlm_password: auth_context challenge created by random
>[2011/12/21 10:14:02.936272, 10, pid=4176] auth/auth.c:233(check_ntlm_password)
>  challenge is: 
>[2011/12/21 10:14:02.936295,  5, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] C0 98 BB 3F 84 4E 11 3B                            ...?.N.; 
>[2011/12/21 10:14:02.936329, 10, pid=4176] auth/auth_builtin.c:44(check_guest_security)
>  Check auth for: [adtest]
>[2011/12/21 10:14:02.936358, 10, pid=4176] auth/auth.c:259(check_ntlm_password)
>  check_ntlm_password: guest had nothing to say
>[2011/12/21 10:14:02.936384, 10, pid=4176] auth/auth_sam.c:75(auth_samstrict_auth)
>  Check auth for: [adtest]
>[2011/12/21 10:14:02.936408,  8, pid=4176] lib/util.c:1521(is_myname)
>  is_myname("CIRCULAR") returns 0
>[2011/12/21 10:14:02.936436,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.936466,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:02.936490,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.936514,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.936537,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.936629,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(uid=adtest)(objectclass=sambaSamAccount))], scope => [2]
>[2011/12/21 10:14:02.954111,  2, pid=4176] passdb/pdb_ldap.c:553(init_sam_from_ldap)
>  init_sam_from_ldap: Entry found for user: adtest
>[2011/12/21 10:14:02.954161, 10, pid=4176] passdb/pdb_get_set.c:545(pdb_set_username)
>  pdb_set_username: setting username adtest, was 
>[2011/12/21 10:14:02.954206, 10, pid=4176] passdb/pdb_get_set.c:568(pdb_set_domain)
>  pdb_set_domain: setting domain CIRCULAR, was 
>[2011/12/21 10:14:02.954233, 10, pid=4176] passdb/pdb_get_set.c:591(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username adtest, was 
>[2011/12/21 10:14:02.954267, 10, pid=4176] passdb/pdb_get_set.c:483(pdb_set_user_sid_from_string)
>  pdb_set_user_sid_from_string: setting user sid S-1-5-21-2132208240-841620863-785830102-3258
>[2011/12/21 10:14:02.954303, 10, pid=4176] passdb/pdb_get_set.c:470(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2132208240-841620863-785830102-3258
>[2011/12/21 10:14:02.954390, 10, pid=4176] passdb/pdb_get_set.c:614(pdb_set_fullname)
>  pdb_set_full_name: setting full name adtest, was 
>[2011/12/21 10:14:02.954428, 10, pid=4176] passdb/pdb_get_set.c:683(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive H:, was NULL
>[2011/12/21 10:14:02.954462, 10, pid=4176] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaHomePath does not exist
>[2011/12/21 10:14:02.954498, 10, pid=4176] passdb/pdb_get_set.c:707(pdb_set_homedir)
>  pdb_set_homedir: setting home dir , was 
>[2011/12/21 10:14:02.954531, 10, pid=4176] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaLogonScript does not exist
>[2011/12/21 10:14:02.954557, 10, pid=4176] passdb/pdb_get_set.c:637(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2011/12/21 10:14:02.954589, 10, pid=4176] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaProfilePath does not exist
>[2011/12/21 10:14:02.954622, 10, pid=4176] passdb/pdb_get_set.c:660(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path , was 
>[2011/12/21 10:14:02.954654, 10, pid=4176] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute description does not exist
>[2011/12/21 10:14:02.954686, 10, pid=4176] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaUserWorkstations does not exist
>[2011/12/21 10:14:02.954717, 10, pid=4176] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaMungedDial does not exist
>[2011/12/21 10:14:02.954773,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.954800,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.954823,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.954847,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.954878,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.954956,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.955005, 10, pid=4176] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaBadPasswordCount does not exist
>[2011/12/21 10:14:02.955044, 10, pid=4176] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaBadPasswordTime does not exist
>[2011/12/21 10:14:02.955078, 10, pid=4176] lib/smbldap.c:308(smbldap_talloc_single_attribute)
>  attribute sambaLogonHours does not exist
>[2011/12/21 10:14:02.955121,  7, pid=4176] passdb/login_cache.c:91(login_cache_read)
>  Looking up login cache for user adtest
>[2011/12/21 10:14:02.955159,  7, pid=4176] passdb/login_cache.c:102(login_cache_read)
>  No cache entry found
>[2011/12/21 10:14:02.955192,  9, pid=4176] passdb/pdb_ldap.c:1107(init_sam_from_ldap)
>  No cache entry, bad count = 0, bad time = 0
>[2011/12/21 10:14:02.955236,  5, pid=4176] lib/username.c:171(Get_Pwnam_alloc)
>  Finding user adtest
>[2011/12/21 10:14:02.955263,  5, pid=4176] lib/username.c:116(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is adtest
>[2011/12/21 10:14:02.955343,  5, pid=4176] lib/username.c:149(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [adtest]!
>[2011/12/21 10:14:02.955391,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.955418,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.955442,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.955466,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.955489,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.955557,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.955604, 10, pid=4176] passdb/pdb_get_set.c:545(pdb_set_username)
>  pdb_set_username: setting username adtest, was 
>[2011/12/21 10:14:02.955630, 10, pid=4176] passdb/pdb_get_set.c:568(pdb_set_domain)
>  pdb_set_domain: setting domain CIRCULAR, was 
>[2011/12/21 10:14:02.955664, 10, pid=4176] passdb/pdb_get_set.c:591(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username adtest, was 
>[2011/12/21 10:14:02.955689, 10, pid=4176] passdb/pdb_get_set.c:614(pdb_set_fullname)
>  pdb_set_full_name: setting full name adtest, was 
>[2011/12/21 10:14:02.955715, 10, pid=4176] passdb/pdb_get_set.c:707(pdb_set_homedir)
>  pdb_set_homedir: setting home dir , was 
>[2011/12/21 10:14:02.955739, 10, pid=4176] passdb/pdb_get_set.c:683(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive H:, was NULL
>[2011/12/21 10:14:02.955772, 10, pid=4176] passdb/pdb_get_set.c:637(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2011/12/21 10:14:02.955797, 10, pid=4176] passdb/pdb_get_set.c:660(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path , was 
>[2011/12/21 10:14:02.955822, 10, pid=4176] passdb/pdb_get_set.c:750(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2011/12/21 10:14:02.955848,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.955880,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.955904,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.955927,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.955950,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.956012,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.956041, 10, pid=4176] passdb/pdb_get_set.c:470(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-2132208240-841620863-785830102-3258
>[2011/12/21 10:14:02.956069, 10, pid=4176] passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-2132208240-841620863-785830102-3258 from rid 3258
>[2011/12/21 10:14:02.956116, 10, pid=4176] passdb/pdb_get_set.c:532(pdb_set_group_sid)
>  pdb_set_group_sid: setting group sid S-1-5-21-2132208240-841620863-785830102-513
>[2011/12/21 10:14:02.956152,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:02.956187,  4, pid=4176] ../libcli/auth/ntlm_check.c:351(ntlm_password_check)
>  ntlm_password_check: Checking NTLMv2 password with domain [CIRCINT]
>[2011/12/21 10:14:02.956250,  4, pid=4176] auth/check_samsec.c:183(sam_account_ok)
>  sam_account_ok: Checking SMB password for user adtest
>[2011/12/21 10:14:02.956290,  5, pid=4176] auth/check_samsec.c:165(logon_hours_ok)
>  logon_hours_ok: user adtest allowed to logon at this time (Wed Dec 21 09:14:02 2011
>  )
>[2011/12/21 10:14:02.956328,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.956353,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:02.956385,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.956409,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.956433,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.956484,  5, pid=4176] lib/username.c:171(Get_Pwnam_alloc)
>  Finding user adtest
>[2011/12/21 10:14:02.956509,  5, pid=4176] lib/username.c:116(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is adtest
>[2011/12/21 10:14:02.956536,  5, pid=4176] lib/username.c:149(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [adtest]!
>[2011/12/21 10:14:02.956566,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.956591,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.956626,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.956650,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.956673,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.956736,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.956768,  5, pid=4176] lib/username.c:171(Get_Pwnam_alloc)
>  Finding user adtest
>[2011/12/21 10:14:02.956792,  5, pid=4176] lib/username.c:116(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is adtest
>[2011/12/21 10:14:02.956818,  5, pid=4176] lib/username.c:149(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [adtest]!
>[2011/12/21 10:14:02.956851, 10, pid=4176] lib/system_smbd.c:175(sys_getgrouplist)
>  sys_getgrouplist: user [adtest]
>[2011/12/21 10:14:02.956887,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.956912,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.956935,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.956958,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.956989,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.957195,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.958108,  5, pid=4176] passdb/lookup_sid.c:1384(gid_to_sid)
>  gid_to_sid: winbind failed to find a sid for gid 6666
>[2011/12/21 10:14:02.958148,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.958183,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.958207,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.958231,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.958254,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.958312,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(gidNumber=6666))], scope => [2]
>[2011/12/21 10:14:02.974679,  2, pid=4176] passdb/pdb_ldap.c:2427(init_group_from_ldap)
>  init_group_from_ldap: Entry found for group: 6666
>[2011/12/21 10:14:02.974747,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.974786, 10, pid=4176] passdb/lookup_sid.c:1181(legacy_gid_to_sid)
>  LEGACY: gid 6666 -> sid S-1-5-21-2132208240-841620863-785830102-6666
>[2011/12/21 10:14:02.975133,  5, pid=4176] passdb/lookup_sid.c:1384(gid_to_sid)
>  gid_to_sid: winbind failed to find a sid for gid 2000
>[2011/12/21 10:14:02.975172,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.975224,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.975251,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.975275,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.975299,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.975358,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(gidNumber=2000))], scope => [2]
>[2011/12/21 10:14:02.985680,  2, pid=4176] passdb/pdb_ldap.c:2427(init_group_from_ldap)
>  init_group_from_ldap: Entry found for group: 2000
>[2011/12/21 10:14:02.985746,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.985775, 10, pid=4176] passdb/lookup_sid.c:1181(legacy_gid_to_sid)
>  LEGACY: gid 2000 -> sid S-1-5-21-2132208240-841620863-785830102-2000
>[2011/12/21 10:14:02.986188,  5, pid=4176] passdb/lookup_sid.c:1384(gid_to_sid)
>  gid_to_sid: winbind failed to find a sid for gid 3000
>[2011/12/21 10:14:02.986227,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.986252,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.986284,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:02.986309,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.986333,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.986381,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(gidNumber=3000))], scope => [2]
>[2011/12/21 10:14:02.996949,  2, pid=4176] passdb/pdb_ldap.c:2427(init_group_from_ldap)
>  init_group_from_ldap: Entry found for group: 3000
>[2011/12/21 10:14:02.997014,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.997044, 10, pid=4176] passdb/lookup_sid.c:1181(legacy_gid_to_sid)
>  LEGACY: gid 3000 -> sid S-1-5-21-2132208240-841620863-785830102-3000
>[2011/12/21 10:14:02.997087,  5, pid=4176] auth/server_info_sam.c:120(make_server_info_sam)
>  make_server_info_sam: made server info for user adtest -> adtest
>[2011/12/21 10:14:02.997120,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:02.997151,  3, pid=4176] auth/auth.c:268(check_ntlm_password)
>  check_ntlm_password: sam authentication for user [adtest] succeeded
>[2011/12/21 10:14:02.997180,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.997214,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:02.997238,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.997262,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.997285,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.997345,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:02.997374,  5, pid=4176] auth/auth.c:296(check_ntlm_password)
>  check_ntlm_password:  PAM Account for user [adtest] succeeded
>[2011/12/21 10:14:02.997397,  2, pid=4176] auth/auth.c:309(check_ntlm_password)
>  check_ntlm_password:  authentication for user [adtest] -> [adtest] -> [adtest] succeeded
>[2011/12/21 10:14:02.997435, 10, pid=4176] auth/token_util.c:223(create_local_nt_token_from_info3)
>  Create local NT token for adtest
>[2011/12/21 10:14:02.997487,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.997523,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:02.997559,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:02.997607,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:02.997633,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:02.997682,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544))], scope => [2]
>[2011/12/21 10:14:03.008162,  4, pid=4176] passdb/pdb_ldap.c:2543(ldapsam_getgroup)
>  ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544))
>[2011/12/21 10:14:03.008212,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.008239, 10, pid=4176] passdb/lookup_sid.c:1253(legacy_sid_to_gid)
>  LEGACY: mapping failed for sid S-1-5-32-544
>[2011/12/21 10:14:03.008266,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.008302,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.008326,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.008350,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.008373,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.008469,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:03.008501,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.008525,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:03.008548,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.008581,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.008629,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544))], scope => [2]
>[2011/12/21 10:14:03.018778,  4, pid=4176] passdb/pdb_ldap.c:2543(ldapsam_getgroup)
>  ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-544))
>[2011/12/21 10:14:03.018837,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.018865, 10, pid=4176] passdb/lookup_sid.c:1253(legacy_sid_to_gid)
>  LEGACY: mapping failed for sid S-1-5-32-544
>[2011/12/21 10:14:03.018989, 10, pid=4176] groupdb/mapping.c:751(pdb_create_builtin_alias)
>  Trying to create builtin alias 544
>[2011/12/21 10:14:03.019027, 10, pid=4176] passdb/lookup_sid.c:964(lookup_sid)
>  lookup_sid called for SID 'S-1-5-32-544'
>[2011/12/21 10:14:03.019085, 10, pid=4176] passdb/lookup_sid.c:721(check_dom_sid_to_level)
>  Accepting SID S-1-5-32 in level 1
>[2011/12/21 10:14:03.019118, 10, pid=4176] passdb/lookup_sid.c:482(lookup_rids)
>  lookup_rids called for domain sid 'S-1-5-32'
>[2011/12/21 10:14:03.019148, 10, pid=4176] passdb/lookup_sid.c:999(lookup_sid)
>  Sid S-1-5-32-544 -> BUILTIN\Administrators(4)
>[2011/12/21 10:14:03.019410,  3, pid=4176] groupdb/mapping.c:772(pdb_create_builtin_alias)
>  pdb_create_builtin_alias: Could not get a gid out of winbind
>[2011/12/21 10:14:03.019473,  5, pid=4176] passdb/pdb_util.c:128(create_builtin_administrators)
>  create_builtin_administrators: Failed to create Administrators
>[2011/12/21 10:14:03.019505,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.019531,  2, pid=4176] auth/token_util.c:455(finalize_local_nt_token)
>  WARNING: Failed to create BUILTIN\Administrators group!  Can Winbind allocate gids?
>[2011/12/21 10:14:03.019604,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.019632,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.019656,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.019679,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.019712,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.019761,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-545))], scope => [2]
>[2011/12/21 10:14:03.030046,  4, pid=4176] passdb/pdb_ldap.c:2543(ldapsam_getgroup)
>  ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-545))
>[2011/12/21 10:14:03.030106,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.030134, 10, pid=4176] passdb/lookup_sid.c:1253(legacy_sid_to_gid)
>  LEGACY: mapping failed for sid S-1-5-32-545
>[2011/12/21 10:14:03.030161,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.030186,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.030218,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.030243,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.030267,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.030340,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:03.030370,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.030394,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2011/12/21 10:14:03.030418,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.030441,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.030498,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-545))], scope => [2]
>[2011/12/21 10:14:03.040648,  4, pid=4176] passdb/pdb_ldap.c:2543(ldapsam_getgroup)
>  ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-545))
>[2011/12/21 10:14:03.040708,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.040736, 10, pid=4176] passdb/lookup_sid.c:1253(legacy_sid_to_gid)
>  LEGACY: mapping failed for sid S-1-5-32-545
>[2011/12/21 10:14:03.040852, 10, pid=4176] groupdb/mapping.c:751(pdb_create_builtin_alias)
>  Trying to create builtin alias 545
>[2011/12/21 10:14:03.040888, 10, pid=4176] passdb/lookup_sid.c:964(lookup_sid)
>  lookup_sid called for SID 'S-1-5-32-545'
>[2011/12/21 10:14:03.040933, 10, pid=4176] passdb/lookup_sid.c:721(check_dom_sid_to_level)
>  Accepting SID S-1-5-32 in level 1
>[2011/12/21 10:14:03.040962, 10, pid=4176] passdb/lookup_sid.c:482(lookup_rids)
>  lookup_rids called for domain sid 'S-1-5-32'
>[2011/12/21 10:14:03.040991, 10, pid=4176] passdb/lookup_sid.c:999(lookup_sid)
>  Sid S-1-5-32-545 -> BUILTIN\Users(4)
>[2011/12/21 10:14:03.041249,  3, pid=4176] groupdb/mapping.c:772(pdb_create_builtin_alias)
>  pdb_create_builtin_alias: Could not get a gid out of winbind
>[2011/12/21 10:14:03.041302,  5, pid=4176] passdb/pdb_util.c:99(create_builtin_users)
>  create_builtin_users: Failed to create Users
>[2011/12/21 10:14:03.041334,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.041359,  2, pid=4176] auth/token_util.c:479(finalize_local_nt_token)
>  WARNING: Failed to create BUILTIN\Users group! Can Winbind allocate gids?
>[2011/12/21 10:14:03.041385,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.041418,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.041443,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.041467,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.041490,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.041574,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectclass=sambaGroupMapping)(sambaGroupType=4)(|(sambaSIDList=S-1-5-21-2132208240-841620863-785830102-3258)(sambaSIDList=S-1-5-21-2132208240-841620863-785830102-513)(sambaSIDList=S-1-5-21-2132208240-841620863-785830102-6666)(sambaSIDList=S-1-5-21-2132208240-841620863-785830102-2000)(sambaSIDList=S-1-5-21-2132208240-841620863-785830102-3000)(sambaSIDList=S-1-1-0)(sambaSIDList=S-1-5-2)(sambaSIDList=S-1-5-11)))], scope => [2]
>[2011/12/21 10:14:03.052212,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.052281,  4, pid=4176] lib/privileges.c:97(get_privileges)
>  get_privileges: No privileges assigned to SID [S-1-5-21-2132208240-841620863-785830102-3258]
>[2011/12/21 10:14:03.052320,  4, pid=4176] lib/privileges.c:97(get_privileges)
>  get_privileges: No privileges assigned to SID [S-1-5-21-2132208240-841620863-785830102-513]
>[2011/12/21 10:14:03.052368,  4, pid=4176] lib/privileges.c:97(get_privileges)
>  get_privileges: No privileges assigned to SID [S-1-5-21-2132208240-841620863-785830102-6666]
>[2011/12/21 10:14:03.052403,  4, pid=4176] lib/privileges.c:97(get_privileges)
>  get_privileges: No privileges assigned to SID [S-1-5-21-2132208240-841620863-785830102-2000]
>[2011/12/21 10:14:03.052436,  4, pid=4176] lib/privileges.c:97(get_privileges)
>  get_privileges: No privileges assigned to SID [S-1-5-21-2132208240-841620863-785830102-3000]
>[2011/12/21 10:14:03.052480,  5, pid=4176] lib/privileges.c:175(get_privileges_for_sids)
>  get_privileges_for_sids: sid = S-1-1-0
>  Privilege set: 0x0
>[2011/12/21 10:14:03.052522,  4, pid=4176] lib/privileges.c:97(get_privileges)
>  get_privileges: No privileges assigned to SID [S-1-5-2]
>[2011/12/21 10:14:03.052553,  4, pid=4176] lib/privileges.c:97(get_privileges)
>  get_privileges: No privileges assigned to SID [S-1-5-11]
>[2011/12/21 10:14:03.053069,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.053107,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.053132,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.053155,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.053196,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.053246,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-1-0))], scope => [2]
>[2011/12/21 10:14:03.063490,  4, pid=4176] passdb/pdb_ldap.c:2543(ldapsam_getgroup)
>  ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-1-0))
>[2011/12/21 10:14:03.063554,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.063583, 10, pid=4176] passdb/lookup_sid.c:1253(legacy_sid_to_gid)
>  LEGACY: mapping failed for sid S-1-1-0
>[2011/12/21 10:14:03.063609, 10, pid=4176] passdb/lookup_sid.c:1218(legacy_sid_to_uid)
>  LEGACY: mapping failed for sid S-1-1-0
>[2011/12/21 10:14:03.063637,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.063672,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.063697,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.063721,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.063744,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.063801,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-2))], scope => [2]
>[2011/12/21 10:14:03.073993,  4, pid=4176] passdb/pdb_ldap.c:2543(ldapsam_getgroup)
>  ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-2))
>[2011/12/21 10:14:03.074053,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.074082, 10, pid=4176] passdb/lookup_sid.c:1253(legacy_sid_to_gid)
>  LEGACY: mapping failed for sid S-1-5-2
>[2011/12/21 10:14:03.074108, 10, pid=4176] passdb/lookup_sid.c:1218(legacy_sid_to_uid)
>  LEGACY: mapping failed for sid S-1-5-2
>[2011/12/21 10:14:03.074137,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.074161,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.074196,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.074221,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.074244,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.074301,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-11))], scope => [2]
>[2011/12/21 10:14:03.084478,  4, pid=4176] passdb/pdb_ldap.c:2543(ldapsam_getgroup)
>  ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-11))
>[2011/12/21 10:14:03.084527,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.084566, 10, pid=4176] passdb/lookup_sid.c:1253(legacy_sid_to_gid)
>  LEGACY: mapping failed for sid S-1-5-11
>[2011/12/21 10:14:03.084594, 10, pid=4176] passdb/lookup_sid.c:1218(legacy_sid_to_uid)
>  LEGACY: mapping failed for sid S-1-5-11
>[2011/12/21 10:14:03.084621, 10, pid=4176] auth/auth_util.c:505(create_local_token)
>  Could not convert SID S-1-1-0 to gid, ignoring it
>[2011/12/21 10:14:03.084646, 10, pid=4176] auth/auth_util.c:505(create_local_token)
>  Could not convert SID S-1-5-2 to gid, ignoring it
>[2011/12/21 10:14:03.084686, 10, pid=4176] auth/auth_util.c:505(create_local_token)
>  Could not convert SID S-1-5-11 to gid, ignoring it
>[2011/12/21 10:14:03.084718, 10, pid=4176] ../libcli/security/security_token.c:63(security_token_debug)
>  Security token SIDs (13):
>    SID[  0]: S-1-5-21-2132208240-841620863-785830102-3258
>    SID[  1]: S-1-5-21-2132208240-841620863-785830102-513
>    SID[  2]: S-1-5-21-2132208240-841620863-785830102-6666
>    SID[  3]: S-1-5-21-2132208240-841620863-785830102-2000
>    SID[  4]: S-1-5-21-2132208240-841620863-785830102-3000
>    SID[  5]: S-1-1-0
>    SID[  6]: S-1-5-2
>    SID[  7]: S-1-5-11
>    SID[  8]: S-1-22-1-1129
>    SID[  9]: S-1-22-2-513
>    SID[ 10]: S-1-22-2-6666
>    SID[ 11]: S-1-22-2-2000
>    SID[ 12]: S-1-22-2-3000
>   Privileges (0x               0):
>   Rights (0x               0):
>[2011/12/21 10:14:03.084938, 10, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 1129
>  Primary group is 513 and contains 4 supplementary groups
>  Group[  0]: 513
>  Group[  1]: 6666
>  Group[  2]: 2000
>  Group[  3]: 3000
>[2011/12/21 10:14:03.085028, 10, pid=4176] auth/auth_ntlmssp.c:174(auth_ntlmssp_check_password)
>  Got NT session key of length 16
>[2011/12/21 10:14:03.085061, 10, pid=4176] auth/auth_ntlmssp.c:181(auth_ntlmssp_check_password)
>  Got LM session key of length 8
>[2011/12/21 10:14:03.085086, 10, pid=4176] ../libcli/auth/ntlmssp_server.c:462(ntlmssp_server_postauth)
>  ntlmssp_server_auth: Using unmodified nt session key.
>[2011/12/21 10:14:03.085125,  3, pid=4176] ../libcli/auth/ntlmssp_sign.c:535(ntlmssp_sign_init)
>  NTLMSSP Sign/Seal - Initialising with flags:
>[2011/12/21 10:14:03.085151,  3, pid=4176] ../libcli/auth/ntlmssp.c:34(debug_ntlmssp_flags)
>  Got NTLMSSP neg_flags=0x60088215
>    NTLMSSP_NEGOTIATE_UNICODE
>    NTLMSSP_REQUEST_TARGET
>    NTLMSSP_NEGOTIATE_SIGN
>    NTLMSSP_NEGOTIATE_NTLM
>    NTLMSSP_NEGOTIATE_ALWAYS_SIGN
>    NTLMSSP_NEGOTIATE_NTLM2
>    NTLMSSP_NEGOTIATE_128
>    NTLMSSP_NEGOTIATE_KEY_EXCH
>[2011/12/21 10:14:03.085269, 10, pid=4176] smbd/password.c:293(register_existing_vuid)
>  register_existing_vuid: (1129,513) adtest adtest CIRCULAR guest=0
>[2011/12/21 10:14:03.085306,  3, pid=4176] smbd/password.c:297(register_existing_vuid)
>  register_existing_vuid: User name: adtest	Real name: adtest
>[2011/12/21 10:14:03.085331,  3, pid=4176] smbd/password.c:307(register_existing_vuid)
>  register_existing_vuid: UNIX uid 1129 is UNIX user adtest, and will be vuid 100
>[2011/12/21 10:14:03.085367, 10, pid=4176] lib/dbwrap_tdb.c:102(db_tdb_fetch_locked)
>  Locking key 49442F343137362F3130
>[2011/12/21 10:14:03.085417, 10, pid=4176] lib/dbwrap_tdb.c:131(db_tdb_fetch_locked)
>  Allocated locked data 0x8bbaa88
>[2011/12/21 10:14:03.085486, 10, pid=4176] lib/dbwrap_tdb.c:44(db_tdb_record_destr)
>  Unlocking key 49442F343137362F3130
>[2011/12/21 10:14:03.085526,  7, pid=4176] param/loadparm.c:9830(lp_servicenumber)
>  lp_servicenumber: couldn't find adtest
>[2011/12/21 10:14:03.085553,  5, pid=4176] lib/username.c:171(Get_Pwnam_alloc)
>  Finding user adtest
>[2011/12/21 10:14:03.085589,  5, pid=4176] lib/username.c:116(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is adtest
>[2011/12/21 10:14:03.085616,  5, pid=4176] lib/username.c:149(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [adtest]!
>[2011/12/21 10:14:03.085640,  3, pid=4176] smbd/password.c:238(register_homes_share)
>  Adding homes service for user 'adtest' using home directory: '/dev/dell'
>[2011/12/21 10:14:03.085675,  7, pid=4176] param/loadparm.c:9830(lp_servicenumber)
>  lp_servicenumber: couldn't find homes
>[2011/12/21 10:14:03.085741,  6, pid=4176] param/loadparm.c:7490(lp_file_list_changed)
>  lp_file_list_changed()
>  file /etc/samba/smb.conf -> /etc/samba/smb.conf  last mod_time: Wed Dec 14 12:19:53 2011
>  
>[2011/12/21 10:14:03.085816,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:03.085835,  5, pid=4176] lib/util.c:342(show_msg)
>  size=104
>  smb_com=0x73
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=65535
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=3
>  smt_wct=4
>  smb_vwv[ 0]=  255 (0xFF)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    9 (0x9)
>  smb_bcc=61
>[2011/12/21 10:14:03.086020, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] A1 07 30 05 A0 03 0A 01   00 55 00 6E 00 69 00 78   ..0..... .U.n.i.x
>  [0010] 00 00 00 53 00 61 00 6D   00 62 00 61 00 20 00 33   ...S.a.m .b.a. .3
>  [0020] 00 2E 00 36 00 2E 00 31   00 00 00 43 00 49 00 52   ...6...1 ...C.I.R
>  [0030] 00 43 00 55 00 4C 00 41   00 52 00 00 00           .C.U.L.A .R...
>[2011/12/21 10:14:03.090821, 10, pid=4176] lib/util_sock.c:516(read_smb_length_return_keepalive)
>  got smb length of 84
>[2011/12/21 10:14:03.090867,  6, pid=4176] smbd/process.c:1659(process_smb)
>  got message type 0x0 of len 0x54
>[2011/12/21 10:14:03.090894,  3, pid=4176] smbd/process.c:1661(process_smb)
>  Transaction 3 of length 88 (0 toread)
>[2011/12/21 10:14:03.090919,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:03.090933,  5, pid=4176] lib/util.c:342(show_msg)
>  size=84
>  smb_com=0x75
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=8
>  smb_flg2=51201
>  smb_tid=65535
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=4
>  smt_wct=4
>  smb_vwv[ 0]=  255 (0xFF)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    8 (0x8)
>  smb_vwv[ 3]=    1 (0x1)
>  smb_bcc=41
>[2011/12/21 10:14:03.091114, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] 00 5C 00 5C 00 31 00 30   00 2E 00 31 00 2E 00 30   .\.\.1.0 ...1...0
>  [0010] 00 2E 00 31 00 30 00 32   00 5C 00 49 00 50 00 43   ...1.0.2 .\.I.P.C
>  [0020] 00 24 00 00 00 49 50 43   00                       .$...IPC .
>[2011/12/21 10:14:03.091203,  3, pid=4176] smbd/process.c:1466(switch_message)
>  switch message SMBtconX (pid 4176) conn 0x0
>[2011/12/21 10:14:03.091230,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.091255,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.091279,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.091330,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:03.091371,  4, pid=4176] smbd/reply.c:794(reply_tcon_and_X)
>  Client requested device type [IPC] for share [IPC$]
>[2011/12/21 10:14:03.091419,  5, pid=4176] smbd/service.c:1267(make_connection)
>  making a connection to 'normal' service ipc$
>[2011/12/21 10:14:03.091528,  3, pid=4176] lib/access.c:338(allow_access)
>  Allowed connection from 10.1.3.49 (10.1.3.49)
>[2011/12/21 10:14:03.091569, 10, pid=4176] smbd/share_access.c:241(user_ok_token)
>  user_ok_token: share IPC$ is ok for unix user adtest
>[2011/12/21 10:14:03.091617,  5, pid=4176] lib/username.c:171(Get_Pwnam_alloc)
>  Finding user adtest
>[2011/12/21 10:14:03.091645,  5, pid=4176] lib/username.c:116(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is adtest
>[2011/12/21 10:14:03.091671,  5, pid=4176] lib/username.c:149(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [adtest]!
>[2011/12/21 10:14:03.091720, 10, pid=4176] smbd/service.c:162(set_conn_connectpath)
>  set_conn_connectpath: service IPC$, connectpath = /tmp
>[2011/12/21 10:14:03.091748,  3, pid=4176] smbd/service.c:845(make_connection_snum)
>  Connect path is '/tmp' for service [IPC$]
>[2011/12/21 10:14:03.091804, 10, pid=4176] ../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0x10000000 to 0x001f01ff
>[2011/12/21 10:14:03.091848, 10, pid=4176] ../libcli/security/access_check.c:177(se_access_check)
>  se_access_check: MAX desired = 0x2000000, granted = 0x101f01ff, remaining = 0x101f01ff
>[2011/12/21 10:14:03.091879,  3, pid=4176] smbd/vfs.c:102(vfs_init_default)
>  Initialising default vfs hooks
>[2011/12/21 10:14:03.091918, 10, pid=4176] smbd/vfs.c:53(vfs_find_backend_entry)
>  vfs_find_backend_entry called for /[Default VFS]/
>[2011/12/21 10:14:03.091946,  5, pid=4176] smbd/vfs.c:92(smb_register_vfs)
>  Successfully added vfs backend '/[Default VFS]/'
>[2011/12/21 10:14:03.091994, 10, pid=4176] smbd/vfs.c:53(vfs_find_backend_entry)
>  vfs_find_backend_entry called for solarisacl
>[2011/12/21 10:14:03.092021,  5, pid=4176] smbd/vfs.c:92(smb_register_vfs)
>  Successfully added vfs backend 'solarisacl'
>[2011/12/21 10:14:03.092044,  3, pid=4176] smbd/vfs.c:128(vfs_init_custom)
>  Initialising custom vfs hooks from [/[Default VFS]/]
>[2011/12/21 10:14:03.092069, 10, pid=4176] smbd/vfs.c:53(vfs_find_backend_entry)
>  vfs_find_backend_entry called for /[Default VFS]/
>  Successfully loaded vfs module [/[Default VFS]/] with the new modules system
>[2011/12/21 10:14:03.092122,  3, pid=4176] smbd/vfs.c:128(vfs_init_custom)
>  Initialising custom vfs hooks from [zfsacl]
>[2011/12/21 10:14:03.092147, 10, pid=4176] smbd/vfs.c:53(vfs_find_backend_entry)
>  vfs_find_backend_entry called for zfsacl
>[2011/12/21 10:14:03.092170,  5, pid=4176] smbd/vfs.c:168(vfs_init_custom)
>  vfs module [zfsacl] not loaded - trying to load...
>[2011/12/21 10:14:03.092204,  5, pid=4176] lib/module.c:111(smb_probe_module)
>  Probing module 'zfsacl'
>[2011/12/21 10:14:03.092232,  5, pid=4176] lib/module.c:130(smb_probe_module)
>  Probing module 'zfsacl': Trying to load from /usr/sfw/lib/vfs/zfsacl.so
>[2011/12/21 10:14:03.092650,  2, pid=4176] lib/module.c:64(do_smb_load_module)
>  Module '/usr/sfw/lib/vfs/zfsacl.so' loaded
>[2011/12/21 10:14:03.092698, 10, pid=4176] smbd/vfs.c:53(vfs_find_backend_entry)
>  vfs_find_backend_entry called for zfsacl
>[2011/12/21 10:14:03.092738,  5, pid=4176] smbd/vfs.c:92(smb_register_vfs)
>  Successfully added vfs backend 'zfsacl'
>[2011/12/21 10:14:03.092764, 10, pid=4176] smbd/vfs.c:53(vfs_find_backend_entry)
>  vfs_find_backend_entry called for zfsacl
>  Successfully loaded vfs module [zfsacl] with the new modules system
>[2011/12/21 10:14:03.092805,  5, pid=4176] smbd/connection.c:134(claim_connection)
>  claiming [IPC$]
>[2011/12/21 10:14:03.092860, 10, pid=4176] lib/dbwrap_tdb.c:102(db_tdb_fetch_locked)
>  Locking key 50100000FFFFFFFFDB13
>[2011/12/21 10:14:03.092909, 10, pid=4176] lib/dbwrap_tdb.c:131(db_tdb_fetch_locked)
>  Allocated locked data 0x8bbb618
>[2011/12/21 10:14:03.092974, 10, pid=4176] lib/dbwrap_tdb.c:44(db_tdb_record_destr)
>  Unlocking key 50100000FFFFFFFFDB13
>[2011/12/21 10:14:03.093065, 10, pid=4176] smbd/service.c:162(set_conn_connectpath)
>  set_conn_connectpath: service IPC$, connectpath = /tmp
>[2011/12/21 10:14:03.093109, 10, pid=4176] smbd/share_access.c:241(user_ok_token)
>  user_ok_token: share IPC$ is ok for unix user adtest
>[2011/12/21 10:14:03.093151, 10, pid=4176] smbd/share_access.c:286(is_share_read_only_for_token)
>  is_share_read_only_for_user: share IPC$ is read-only for unix user adtest
>[2011/12/21 10:14:03.093189, 10, pid=4176] ../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0x10000000 to 0x001f01ff
>[2011/12/21 10:14:03.093232,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (1129, 513) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.093260,  5, pid=4176] ../libcli/security/security_token.c:63(security_token_debug)
>  Security token SIDs (13):
>    SID[  0]: S-1-5-21-2132208240-841620863-785830102-3258
>    SID[  1]: S-1-5-21-2132208240-841620863-785830102-513
>    SID[  2]: S-1-5-21-2132208240-841620863-785830102-6666
>    SID[  3]: S-1-5-21-2132208240-841620863-785830102-2000
>    SID[  4]: S-1-5-21-2132208240-841620863-785830102-3000
>    SID[  5]: S-1-1-0
>    SID[  6]: S-1-5-2
>    SID[  7]: S-1-5-11
>    SID[  8]: S-1-22-1-1129
>    SID[  9]: S-1-22-2-513
>    SID[ 10]: S-1-22-2-6666
>    SID[ 11]: S-1-22-2-2000
>    SID[ 12]: S-1-22-2-3000
>   Privileges (0x               0):
>   Rights (0x               0):
>[2011/12/21 10:14:03.093489,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 1129
>  Primary group is 513 and contains 4 supplementary groups
>  Group[  0]: 513
>  Group[  1]: 6666
>  Group[  2]: 2000
>  Group[  3]: 3000
>[2011/12/21 10:14:03.093573,  5, pid=4176] smbd/uid.c:317(change_to_user_internal)
>  Impersonated user: uid=(0,1129), gid=(0,513)
>[2011/12/21 10:14:03.093622,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.093648,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.093672,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.093714,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:03.093764, 10, pid=4176] smbd/service.c:162(set_conn_connectpath)
>  set_conn_connectpath: service IPC$, connectpath = /tmp
>[2011/12/21 10:14:03.093803, 10, pid=4176] modules/vfs_default.c:160(vfswrap_fs_capabilities)
>  vfswrap_fs_capabilities: timestamp resolution of sec available on share IPC$, directory /tmp
>[2011/12/21 10:14:03.093832,  3, pid=4176] smbd/service.c:1089(make_connection_snum)
>  debian (10.1.3.49) connect to service IPC$ initially as user adtest (uid=1129, gid=513) (pid 4176)
>[2011/12/21 10:14:03.093876,  3, pid=4176] smbd/reply.c:871(reply_tcon_and_X)
>  tconX service=IPC$ 
>[2011/12/21 10:14:03.100734, 10, pid=4176] lib/util_sock.c:516(read_smb_length_return_keepalive)
>  got smb length of 104
>[2011/12/21 10:14:03.100778,  6, pid=4176] smbd/process.c:1659(process_smb)
>  got message type 0x0 of len 0x68
>[2011/12/21 10:14:03.100803,  3, pid=4176] smbd/process.c:1661(process_smb)
>  Transaction 4 of length 108 (0 toread)
>[2011/12/21 10:14:03.100841,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:03.100857,  5, pid=4176] lib/util.c:342(show_msg)
>  size=104
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=8
>  smb_flg2=51201
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=5
>  smt_wct=15
>  smb_vwv[ 0]=   34 (0x22)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=16644 (0x4104)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=   34 (0x22)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=  104 (0x68)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=   16 (0x10)
>  smb_bcc=39
>[2011/12/21 10:14:03.101138, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] 00 44 20 03 00 5C 00 31   00 30 00 2E 00 31 00 2E   .D ..\.1 .0...1..
>  [0010] 00 30 00 2E 00 31 00 30   00 32 00 5C 00 6E 00 66   .0...1.0 .2.\.n.f
>  [0020] 00 73 00 00 00 00 00                              .s..... 
>[2011/12/21 10:14:03.101216,  3, pid=4176] smbd/process.c:1466(switch_message)
>  switch message SMBtrans2 (pid 4176) conn 0x8bc82e0
>[2011/12/21 10:14:03.101257,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (1129, 513) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.101284,  5, pid=4176] ../libcli/security/security_token.c:63(security_token_debug)
>  Security token SIDs (13):
>    SID[  0]: S-1-5-21-2132208240-841620863-785830102-3258
>    SID[  1]: S-1-5-21-2132208240-841620863-785830102-513
>    SID[  2]: S-1-5-21-2132208240-841620863-785830102-6666
>    SID[  3]: S-1-5-21-2132208240-841620863-785830102-2000
>    SID[  4]: S-1-5-21-2132208240-841620863-785830102-3000
>    SID[  5]: S-1-1-0
>    SID[  6]: S-1-5-2
>    SID[  7]: S-1-5-11
>    SID[  8]: S-1-22-1-1129
>    SID[  9]: S-1-22-2-513
>    SID[ 10]: S-1-22-2-6666
>    SID[ 11]: S-1-22-2-2000
>    SID[ 12]: S-1-22-2-3000
>   Privileges (0x               0):
>   Rights (0x               0):
>[2011/12/21 10:14:03.101482,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 1129
>  Primary group is 513 and contains 4 supplementary groups
>  Group[  0]: 513
>  Group[  1]: 6666
>  Group[  2]: 2000
>  Group[  3]: 3000
>[2011/12/21 10:14:03.101576,  5, pid=4176] smbd/uid.c:317(change_to_user_internal)
>  Impersonated user: uid=(0,1129), gid=(0,513)
>[2011/12/21 10:14:03.101606,  4, pid=4176] smbd/vfs.c:780(vfs_ChDir)
>  vfs_ChDir to /tmp
>[2011/12/21 10:14:03.101659, 10, pid=4176] smbd/trans2.c:8307(call_trans2getdfsreferral)
>  call_trans2getdfsreferral
>[2011/12/21 10:14:03.101730, 10, pid=4176] smbd/msdfs.c:113(parse_dfs_path)
>  parse_dfs_path: temp = |10.1.0.102\nfs| after trimming \'s
>[2011/12/21 10:14:03.101761, 10, pid=4176] smbd/msdfs.c:138(parse_dfs_path)
>  parse_dfs_path: hostname: 10.1.0.102
>[2011/12/21 10:14:03.101785, 10, pid=4176] smbd/msdfs.c:180(parse_dfs_path)
>  parse_dfs_path: servicename: nfs
>[2011/12/21 10:14:03.101814,  3, pid=4176] smbd/msdfs.c:891(get_referred_path)
>  get_referred_path: |nfs| in dfs path \10.1.0.102\nfs is not a dfs root.
>[2011/12/21 10:14:03.101861,  3, pid=4176] smbd/error.c:81(error_packet_set)
>  error packet at smbd/trans2.c(8329) cmd=50 (SMBtrans2) NT_STATUS_NOT_FOUND
>[2011/12/21 10:14:03.101903,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:03.101917,  5, pid=4176] lib/util.c:342(show_msg)
>  size=35
>  smb_com=0x32
>  smb_rcls=37
>  smb_reh=2
>  smb_err=49152
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=5
>  smt_wct=0
>  smb_bcc=0
>[2011/12/21 10:14:03.102047, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>[2011/12/21 10:14:03.102706, 10, pid=4176] lib/util_sock.c:516(read_smb_length_return_keepalive)
>  got smb length of 35
>[2011/12/21 10:14:03.102747,  6, pid=4176] smbd/process.c:1659(process_smb)
>  got message type 0x0 of len 0x23
>[2011/12/21 10:14:03.102772,  3, pid=4176] smbd/process.c:1661(process_smb)
>  Transaction 5 of length 39 (0 toread)
>[2011/12/21 10:14:03.102796,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:03.102810,  5, pid=4176] lib/util.c:342(show_msg)
>  size=35
>  smb_com=0x71
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=8
>  smb_flg2=51201
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=6
>  smt_wct=0
>  smb_bcc=0
>[2011/12/21 10:14:03.102953, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>[2011/12/21 10:14:03.102970,  3, pid=4176] smbd/process.c:1466(switch_message)
>  switch message SMBtdis (pid 4176) conn 0x8bc82e0
>[2011/12/21 10:14:03.102995,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.103019,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.103056,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.103101,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:03.103138,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.103175,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.103201,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.103241,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:03.103267,  3, pid=4176] smbd/service.c:1291(close_cnum)
>  debian (10.1.3.49) closed connection to service IPC$
>[2011/12/21 10:14:03.103309,  3, pid=4176] smbd/connection.c:35(yield_connection)
>  Yielding connection to IPC$
>[2011/12/21 10:14:03.103372, 10, pid=4176] lib/dbwrap_tdb.c:102(db_tdb_fetch_locked)
>  Locking key 50100000FFFFFFFFDB13
>[2011/12/21 10:14:03.103414, 10, pid=4176] lib/dbwrap_tdb.c:131(db_tdb_fetch_locked)
>  Allocated locked data 0x8bbb098
>[2011/12/21 10:14:03.103449, 10, pid=4176] lib/dbwrap_tdb.c:44(db_tdb_record_destr)
>  Unlocking key 50100000FFFFFFFFDB13
>[2011/12/21 10:14:03.103518,  4, pid=4176] smbd/vfs.c:780(vfs_ChDir)
>  vfs_ChDir to /
>[2011/12/21 10:14:03.103552,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.103578,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.103602,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.103661,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:03.103697,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:03.103715,  5, pid=4176] lib/util.c:342(show_msg)
>  size=35
>  smb_com=0x71
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=6
>  smt_wct=0
>  smb_bcc=0
>[2011/12/21 10:14:03.103845, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>[2011/12/21 10:14:03.108650, 10, pid=4176] lib/util_sock.c:516(read_smb_length_return_keepalive)
>  got smb length of 84
>[2011/12/21 10:14:03.108694,  6, pid=4176] smbd/process.c:1659(process_smb)
>  got message type 0x0 of len 0x54
>[2011/12/21 10:14:03.108720,  3, pid=4176] smbd/process.c:1661(process_smb)
>  Transaction 6 of length 88 (0 toread)
>[2011/12/21 10:14:03.108744,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:03.108758,  5, pid=4176] lib/util.c:342(show_msg)
>  size=84
>  smb_com=0x75
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=8
>  smb_flg2=51201
>  smb_tid=65535
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=7
>  smt_wct=4
>  smb_vwv[ 0]=  255 (0xFF)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    8 (0x8)
>  smb_vwv[ 3]=    1 (0x1)
>  smb_bcc=41
>[2011/12/21 10:14:03.108940, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] 00 5C 00 5C 00 31 00 30   00 2E 00 31 00 2E 00 30   .\.\.1.0 ...1...0
>  [0010] 00 2E 00 31 00 30 00 32   00 5C 00 4E 00 46 00 53   ...1.0.2 .\.N.F.S
>  [0020] 00 00 00 3F 3F 3F 3F 3F   00                       ...????? .
>[2011/12/21 10:14:03.109030,  3, pid=4176] smbd/process.c:1466(switch_message)
>  switch message SMBtconX (pid 4176) conn 0x0
>[2011/12/21 10:14:03.109059,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.109084,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.109108,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.109160,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:03.109192,  4, pid=4176] smbd/reply.c:794(reply_tcon_and_X)
>  Client requested device type [?????] for share [NFS]
>[2011/12/21 10:14:03.109225,  5, pid=4176] smbd/service.c:1267(make_connection)
>  making a connection to 'normal' service nfs
>[2011/12/21 10:14:03.109273,  3, pid=4176] lib/access.c:338(allow_access)
>  Allowed connection from 10.1.3.49 (10.1.3.49)
>[2011/12/21 10:14:03.109324,  3, pid=4176] ../libcli/security/dom_sid.c:208(dom_sid_parse_endp)
>  string_to_sid: SID @technik is not in a valid format
>[2011/12/21 10:14:03.109389,  5, pid=4176] auth/user_util.c:152(user_in_netgroup)
>  looking for user adtest of domain circular.de in netgroup technik
>[2011/12/21 10:14:03.110963, 10, pid=4176] passdb/lookup_sid.c:76(lookup_name)
>  lookup_name: CIRCULAR\technik => domain=[CIRCULAR], name=[technik]
>[2011/12/21 10:14:03.111017, 10, pid=4176] passdb/lookup_sid.c:77(lookup_name)
>  lookup_name: flags = 0x077
>[2011/12/21 10:14:03.111046,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.111072,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.111096,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.111120,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.111157,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.111208,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(|(displayName=technik)(cn=technik)))], scope => [2]
>[2011/12/21 10:14:03.121982,  2, pid=4176] passdb/pdb_ldap.c:2427(init_group_from_ldap)
>  init_group_from_ldap: Entry found for group: 3000
>[2011/12/21 10:14:03.122048,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.122082, 10, pid=4176] smbd/share_access.c:241(user_ok_token)
>  user_ok_token: share nfs is ok for unix user adtest
>[2011/12/21 10:14:03.122118,  5, pid=4176] lib/username.c:171(Get_Pwnam_alloc)
>  Finding user adtest
>[2011/12/21 10:14:03.122144,  5, pid=4176] lib/username.c:116(Get_Pwnam_internals)
>  Trying _Get_Pwnam(), username as lowercase is adtest
>[2011/12/21 10:14:03.122193,  5, pid=4176] lib/username.c:149(Get_Pwnam_internals)
>  Get_Pwnam_internals did find user [adtest]!
>[2011/12/21 10:14:03.122227, 10, pid=4176] smbd/service.c:162(set_conn_connectpath)
>  set_conn_connectpath: service nfs, connectpath = /space/groups/nfs
>[2011/12/21 10:14:03.122255,  3, pid=4176] smbd/service.c:845(make_connection_snum)
>  Connect path is '/space/groups/nfs' for service [nfs]
>[2011/12/21 10:14:03.122304, 10, pid=4176] ../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0x10000000 to 0x001f01ff
>[2011/12/21 10:14:03.122336, 10, pid=4176] ../libcli/security/access_check.c:177(se_access_check)
>  se_access_check: MAX desired = 0x2000000, granted = 0x101f01ff, remaining = 0x101f01ff
>[2011/12/21 10:14:03.122362,  3, pid=4176] smbd/vfs.c:102(vfs_init_default)
>  Initialising default vfs hooks
>[2011/12/21 10:14:03.122386,  3, pid=4176] smbd/vfs.c:128(vfs_init_custom)
>  Initialising custom vfs hooks from [/[Default VFS]/]
>[2011/12/21 10:14:03.122425, 10, pid=4176] smbd/vfs.c:53(vfs_find_backend_entry)
>  vfs_find_backend_entry called for /[Default VFS]/
>  Successfully loaded vfs module [/[Default VFS]/] with the new modules system
>[2011/12/21 10:14:03.122460,  3, pid=4176] smbd/vfs.c:128(vfs_init_custom)
>  Initialising custom vfs hooks from [zfsacl]
>[2011/12/21 10:14:03.122484, 10, pid=4176] smbd/vfs.c:53(vfs_find_backend_entry)
>  vfs_find_backend_entry called for zfsacl
>  Successfully loaded vfs module [zfsacl] with the new modules system
>[2011/12/21 10:14:03.122533,  5, pid=4176] smbd/connection.c:134(claim_connection)
>  claiming [nfs]
>[2011/12/21 10:14:03.122586, 10, pid=4176] lib/dbwrap_tdb.c:102(db_tdb_fetch_locked)
>  Locking key 50100000FFFFFFFFDB13
>[2011/12/21 10:14:03.122617, 10, pid=4176] lib/dbwrap_tdb.c:131(db_tdb_fetch_locked)
>  Allocated locked data 0x8bbb718
>[2011/12/21 10:14:03.122654, 10, pid=4176] lib/dbwrap_tdb.c:44(db_tdb_record_destr)
>  Unlocking key 50100000FFFFFFFFDB13
>[2011/12/21 10:14:03.122777, 10, pid=4176] smbd/service.c:162(set_conn_connectpath)
>  set_conn_connectpath: service nfs, connectpath = /space/groups/nfs
>[2011/12/21 10:14:03.122816,  3, pid=4176] ../libcli/security/dom_sid.c:208(dom_sid_parse_endp)
>  string_to_sid: SID @technik is not in a valid format
>[2011/12/21 10:14:03.122842,  5, pid=4176] auth/user_util.c:152(user_in_netgroup)
>  looking for user adtest of domain circular.de in netgroup technik
>[2011/12/21 10:14:03.124244, 10, pid=4176] passdb/lookup_sid.c:76(lookup_name)
>  lookup_name: CIRCULAR\technik => domain=[CIRCULAR], name=[technik]
>[2011/12/21 10:14:03.124283, 10, pid=4176] passdb/lookup_sid.c:77(lookup_name)
>  lookup_name: flags = 0x077
>[2011/12/21 10:14:03.124309,  4, pid=4176] smbd/sec_ctx.c:214(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.124334,  4, pid=4176] smbd/uid.c:460(push_conn_ctx)
>  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.124358,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2011/12/21 10:14:03.124398,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.124423,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.124472,  5, pid=4176] lib/smbldap.c:1439(smbldap_search_ext)
>  smbldap_search_ext: base => [dc=circular,dc=de], filter => [(&(objectClass=sambaGroupMapping)(|(displayName=technik)(cn=technik)))], scope => [2]
>[2011/12/21 10:14:03.140885,  2, pid=4176] passdb/pdb_ldap.c:2427(init_group_from_ldap)
>  init_group_from_ldap: Entry found for group: 3000
>[2011/12/21 10:14:03.140950,  4, pid=4176] smbd/sec_ctx.c:422(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.140983, 10, pid=4176] smbd/share_access.c:241(user_ok_token)
>  user_ok_token: share nfs is ok for unix user adtest
>[2011/12/21 10:14:03.141033, 10, pid=4176] smbd/share_access.c:286(is_share_read_only_for_token)
>  is_share_read_only_for_user: share nfs is read-write for unix user adtest
>[2011/12/21 10:14:03.141073, 10, pid=4176] ../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0x10000000 to 0x001f01ff
>[2011/12/21 10:14:03.141109, 10, pid=4176] ../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0x10000000 to 0x001f01ff
>[2011/12/21 10:14:03.141150,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (1129, 513) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.141193,  5, pid=4176] ../libcli/security/security_token.c:63(security_token_debug)
>  Security token SIDs (13):
>    SID[  0]: S-1-5-21-2132208240-841620863-785830102-3258
>    SID[  1]: S-1-5-21-2132208240-841620863-785830102-513
>    SID[  2]: S-1-5-21-2132208240-841620863-785830102-6666
>    SID[  3]: S-1-5-21-2132208240-841620863-785830102-2000
>    SID[  4]: S-1-5-21-2132208240-841620863-785830102-3000
>    SID[  5]: S-1-1-0
>    SID[  6]: S-1-5-2
>    SID[  7]: S-1-5-11
>    SID[  8]: S-1-22-1-1129
>    SID[  9]: S-1-22-2-513
>    SID[ 10]: S-1-22-2-6666
>    SID[ 11]: S-1-22-2-2000
>    SID[ 12]: S-1-22-2-3000
>   Privileges (0x               0):
>   Rights (0x               0):
>[2011/12/21 10:14:03.141396,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 1129
>  Primary group is 513 and contains 4 supplementary groups
>  Group[  0]: 513
>  Group[  1]: 6666
>  Group[  2]: 2000
>  Group[  3]: 3000
>[2011/12/21 10:14:03.141492,  5, pid=4176] smbd/uid.c:317(change_to_user_internal)
>  Impersonated user: uid=(0,1129), gid=(0,513)
>[2011/12/21 10:14:03.141523,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.141548,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.141571,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.141628,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:03.141666, 10, pid=4176] smbd/service.c:162(set_conn_connectpath)
>  set_conn_connectpath: service nfs, connectpath = /space/groups/nfs
>[2011/12/21 10:14:03.141723, 10, pid=4176] modules/vfs_default.c:160(vfswrap_fs_capabilities)
>  vfswrap_fs_capabilities: timestamp resolution of sec available on share nfs, directory /space/groups/nfs
>[2011/12/21 10:14:03.141768,  1, pid=4176] smbd/service.c:1089(make_connection_snum)
>  debian (10.1.3.49) connect to service nfs initially as user adtest (uid=1129, gid=513) (pid 4176)
>[2011/12/21 10:14:03.141805,  3, pid=4176] smbd/reply.c:871(reply_tcon_and_X)
>  tconX service=NFS 
>[2011/12/21 10:14:03.243726, 10, pid=4176] lib/util_sock.c:516(read_smb_length_return_keepalive)
>  got smb length of 53
>[2011/12/21 10:14:03.243780,  6, pid=4176] smbd/process.c:1659(process_smb)
>  got message type 0x0 of len 0x35
>[2011/12/21 10:14:03.243826,  3, pid=4176] smbd/process.c:1661(process_smb)
>  Transaction 7 of length 57 (0 toread)
>[2011/12/21 10:14:03.243853,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:03.243867,  5, pid=4176] lib/util.c:342(show_msg)
>  size=53
>  smb_com=0x2b
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=8
>  smb_flg2=51201
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=8
>  smt_wct=1
>  smb_vwv[ 0]=    1 (0x1)
>  smb_bcc=16
>[2011/12/21 10:14:03.244006, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] F0 F0 F0 F0 F0 F0 F0 F0   F0 F0 F0 F0 F0 F0 F0 F0   ........ ........
>[2011/12/21 10:14:03.244068,  3, pid=4176] smbd/process.c:1466(switch_message)
>  switch message SMBecho (pid 4176) conn 0x8bc82e0
>[2011/12/21 10:14:03.244095,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:03.244119,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:03.244163,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:03.244208,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:03.244236,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:03.244250,  5, pid=4176] lib/util.c:342(show_msg)
>  size=53
>  smb_com=0x2b
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=8
>  smt_wct=1
>  smb_vwv[ 0]=    1 (0x1)
>  smb_bcc=16
>[2011/12/21 10:14:03.244403, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] F0 F0 F0 F0 F0 F0 F0 F0   F0 F0 F0 F0 F0 F0 F0 F0   ........ ........
>[2011/12/21 10:14:03.244453,  3, pid=4176] smbd/reply.c:5176(reply_echo)
>  echo 1 times
>[2011/12/21 10:14:08.089595, 10, pid=4176] lib/util_sock.c:516(read_smb_length_return_keepalive)
>  got smb length of 53
>[2011/12/21 10:14:08.089686,  6, pid=4176] smbd/process.c:1659(process_smb)
>  got message type 0x0 of len 0x35
>[2011/12/21 10:14:08.089752,  3, pid=4176] smbd/process.c:1661(process_smb)
>  Transaction 8 of length 57 (0 toread)
>[2011/12/21 10:14:08.089779,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:08.089794,  5, pid=4176] lib/util.c:342(show_msg)
>  size=53
>  smb_com=0x2b
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=8
>  smb_flg2=51201
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=9
>  smt_wct=1
>  smb_vwv[ 0]=    1 (0x1)
>  smb_bcc=16
>[2011/12/21 10:14:08.089948, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] F0 F0 F0 F0 F0 F0 F0 F0   F0 F0 F0 F0 F0 F0 F0 F0   ........ ........
>[2011/12/21 10:14:08.090033,  3, pid=4176] smbd/process.c:1466(switch_message)
>  switch message SMBecho (pid 4176) conn 0x8bc82e0
>[2011/12/21 10:14:08.090064,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:08.090089,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:08.090130,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:08.090176,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:08.090206,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:08.090220,  5, pid=4176] lib/util.c:342(show_msg)
>  size=53
>  smb_com=0x2b
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=9
>  smt_wct=1
>  smb_vwv[ 0]=    1 (0x1)
>  smb_bcc=16
>[2011/12/21 10:14:08.090413, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] F0 F0 F0 F0 F0 F0 F0 F0   F0 F0 F0 F0 F0 F0 F0 F0   ........ ........
>[2011/12/21 10:14:08.090497,  3, pid=4176] smbd/reply.c:5176(reply_echo)
>  echo 1 times
>[2011/12/21 10:14:08.138775, 10, pid=4176] lib/util_sock.c:516(read_smb_length_return_keepalive)
>  got smb length of 92
>[2011/12/21 10:14:08.138841,  6, pid=4176] smbd/process.c:1659(process_smb)
>  got message type 0x0 of len 0x5c
>[2011/12/21 10:14:08.138870,  3, pid=4176] smbd/process.c:1661(process_smb)
>  Transaction 9 of length 96 (0 toread)
>[2011/12/21 10:14:08.138895,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:08.138909,  5, pid=4176] lib/util.c:342(show_msg)
>  size=92
>  smb_com=0x2d
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=8
>  smb_flg2=51201
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=10
>  smt_wct=15
>  smb_vwv[ 0]=  255 (0xFF)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=   66 (0x42)
>  smb_vwv[ 4]=    6 (0x6)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=   18 (0x12)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_vwv[10]=    0 (0x0)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    0 (0x0)
>  smb_vwv[14]=    0 (0x0)
>  smb_bcc=27
>[2011/12/21 10:14:08.139205, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>  [0000] 00 5C 00 6E 00 65 00 77   00 66 00 69 00 6C 00 65   .\.n.e.w .f.i.l.e
>  [0010] 00 2E 00 74 00 78 00 74   00 00 00                 ...t.x.t ...
>[2011/12/21 10:14:08.139288,  3, pid=4176] smbd/process.c:1466(switch_message)
>  switch message SMBopenX (pid 4176) conn 0x8bc82e0
>[2011/12/21 10:14:08.139322,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (1129, 513) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:08.139348,  5, pid=4176] ../libcli/security/security_token.c:63(security_token_debug)
>  Security token SIDs (13):
>    SID[  0]: S-1-5-21-2132208240-841620863-785830102-3258
>    SID[  1]: S-1-5-21-2132208240-841620863-785830102-513
>    SID[  2]: S-1-5-21-2132208240-841620863-785830102-6666
>    SID[  3]: S-1-5-21-2132208240-841620863-785830102-2000
>    SID[  4]: S-1-5-21-2132208240-841620863-785830102-3000
>    SID[  5]: S-1-1-0
>    SID[  6]: S-1-5-2
>    SID[  7]: S-1-5-11
>    SID[  8]: S-1-22-1-1129
>    SID[  9]: S-1-22-2-513
>    SID[ 10]: S-1-22-2-6666
>    SID[ 11]: S-1-22-2-2000
>    SID[ 12]: S-1-22-2-3000
>   Privileges (0x               0):
>   Rights (0x               0):
>[2011/12/21 10:14:08.139571,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 1129
>  Primary group is 513 and contains 4 supplementary groups
>  Group[  0]: 513
>  Group[  1]: 6666
>  Group[  2]: 2000
>  Group[  3]: 3000
>[2011/12/21 10:14:08.139655,  5, pid=4176] smbd/uid.c:317(change_to_user_internal)
>  Impersonated user: uid=(0,1129), gid=(0,513)
>[2011/12/21 10:14:08.139684,  4, pid=4176] smbd/vfs.c:780(vfs_ChDir)
>  vfs_ChDir to /space/groups/nfs
>[2011/12/21 10:14:08.139789,  5, pid=4176] smbd/filename.c:257(unix_convert)
>  unix_convert called on file "newfile.txt"
>[2011/12/21 10:14:08.139829, 10, pid=4176] smbd/statcache.c:241(stat_cache_lookup)
>  stat_cache_lookup: lookup failed for name [NEWFILE.TXT]
>[2011/12/21 10:14:08.139855,  5, pid=4176] smbd/filename.c:416(unix_convert)
>  unix_convert begin: name = newfile.txt, dirpath = , start = newfile.txt
>[2011/12/21 10:14:08.140792, 10, pid=4176] smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled newfile.txt ?
>[2011/12/21 10:14:08.140851, 10, pid=4176] smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component newfile.txt (len 11) ?
>[2011/12/21 10:14:08.141413, 10, pid=4176] smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled newfile.txt ?
>[2011/12/21 10:14:08.141452, 10, pid=4176] smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component newfile.txt (len 11) ?
>[2011/12/21 10:14:08.142463, 10, pid=4176] smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled newfile.txt ?
>[2011/12/21 10:14:08.142522, 10, pid=4176] smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component newfile.txt (len 11) ?
>[2011/12/21 10:14:08.142548,  5, pid=4176] smbd/filename.c:781(unix_convert)
>  New file newfile.txt
>[2011/12/21 10:14:08.142574,  3, pid=4176] smbd/vfs.c:905(check_reduced_name)
>  check_reduced_name [newfile.txt] [/space/groups/nfs]
>[2011/12/21 10:14:08.144426, 10, pid=4176] smbd/vfs.c:969(check_reduced_name)
>  check_reduced_name realpath [newfile.txt] -> [/space/groups/nfs/newfile.txt]
>[2011/12/21 10:14:08.144481,  3, pid=4176] smbd/vfs.c:1039(check_reduced_name)
>  check_reduced_name: newfile.txt reduced to /space/groups/nfs/newfile.txt
>[2011/12/21 10:14:08.144510, 10, pid=4176] lib/util.c:2765(map_open_params_to_ntcreate)
>  map_open_params_to_ntcreate: fname = newfile.txt, deny_mode = 0x42, open_func = 0x12
>[2011/12/21 10:14:08.144535, 10, pid=4176] lib/util.c:2869(map_open_params_to_ntcreate)
>  map_open_params_to_ntcreate: file newfile.txt, access_mask = 0x12019f, share_mode = 0x3, create_disposition = 0x5, create_options = 0x40 private_flags = 0x0
>[2011/12/21 10:14:08.144596, 10, pid=4176] smbd/open.c:3596(create_file_default)
>  create_file: access_mask = 0x12019f file_attributes = 0x0, share_access = 0x3, create_disposition = 0x5 create_options = 0x40 oplock_request = 0x0 private_flags = 0x0 root_dir_fid = 0x0, ea_list = 0x0, sd = 0x0, fname = newfile.txt
>[2011/12/21 10:14:08.144633,  3, pid=4176] smbd/vfs.c:905(check_reduced_name)
>  check_reduced_name [newfile.txt] [/space/groups/nfs]
>[2011/12/21 10:14:08.144930, 10, pid=4176] smbd/vfs.c:969(check_reduced_name)
>  check_reduced_name realpath [newfile.txt] -> [/space/groups/nfs/newfile.txt]
>[2011/12/21 10:14:08.144968,  3, pid=4176] smbd/vfs.c:1039(check_reduced_name)
>  check_reduced_name: newfile.txt reduced to /space/groups/nfs/newfile.txt
>[2011/12/21 10:14:08.144999, 10, pid=4176] smbd/open.c:3116(create_file_unixpath)
>  create_file_unixpath: access_mask = 0x12019f file_attributes = 0x0, share_access = 0x3, create_disposition = 0x5 create_options = 0x40 oplock_request = 0x0 private_flags = 0x0 ea_list = 0x0, sd = 0x0, fname = newfile.txt
>[2011/12/21 10:14:08.145052,  5, pid=4176] smbd/files.c:126(file_new)
>  allocated file structure 13104, fnum = 17200 (1 used)
>[2011/12/21 10:14:08.145084, 10, pid=4176] smbd/files.c:618(file_name_hash)
>  file_name_hash: /space/groups/nfs/newfile.txt hash 0xe721e3bd
>[2011/12/21 10:14:08.145123,  3, pid=4176] smbd/dosmode.c:159(unix_mode)
>  unix_mode(newfile.txt) returning 0644
>[2011/12/21 10:14:08.145165, 10, pid=4176] smbd/open.c:1595(open_file_ntcreate)
>  open_file_ntcreate: fname=newfile.txt, dos_attrs=0x0 access_mask=0x12019f share_access=0x3 create_disposition = 0x5 create_options=0x40 unix mode=0644 oplock_request=0 private_flags = 0x0
>[2011/12/21 10:14:08.145199,  3, pid=4176] smbd/vfs.c:905(check_reduced_name)
>  check_reduced_name [newfile.txt] [/space/groups/nfs]
>[2011/12/21 10:14:08.145473, 10, pid=4176] smbd/vfs.c:969(check_reduced_name)
>  check_reduced_name realpath [newfile.txt] -> [/space/groups/nfs/newfile.txt]
>[2011/12/21 10:14:08.145528,  3, pid=4176] smbd/vfs.c:1039(check_reduced_name)
>  check_reduced_name: newfile.txt reduced to /space/groups/nfs/newfile.txt
>[2011/12/21 10:14:08.145556,  8, pid=4176] lib/util.c:1320(is_in_path)
>  is_in_path: newfile.txt
>[2011/12/21 10:14:08.145681,  8, pid=4176] lib/util.c:1344(is_in_path)
>  is_in_path: match not found
>[2011/12/21 10:14:08.145717, 10, pid=4176] smbd/open.c:1773(open_file_ntcreate)
>  open_file_ntcreate: fname=newfile.txt, after mapping access_mask=0x12019f
>[2011/12/21 10:14:08.145760,  4, pid=4176] smbd/open.c:2064(open_file_ntcreate)
>  calling open_file with flags=0x2 flags2=0x300 mode=0644, access_mask = 0x12019f, open_access_mask = 0x12019f
>[2011/12/21 10:14:08.161811, 10, pid=4176] smbd/open.c:179(fd_open)
>  fd_open: name newfile.txt, flags = 0402 mode = 0644, fd = 31. 
>[2011/12/21 10:14:08.161931, 10, pid=4176] smbd/notify_internal.c:865(notify_onelevel)
>  notify_onelevel:
>[2011/12/21 10:14:08.161962,  1, pid=4176] ../librpc/ndr/ndr.c:247(ndr_print_debug)
>       array: struct notify_entry_array
>          num_entries              : 0x00000002 (2)
>          entries: ARRAY(2)
>              entries: struct notify_entry
>                  server: struct server_id
>                      pid                      : 0x00001003 (4099)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x527fadc63a4c486e (5944661100045551726)
>                  filter                   : 0x00000017 (23)
>                  subdir_filter            : 0x00000000 (0)
>                  dir_fd                   : 0x00000024 (36)
>                  dir_id: struct file_id
>                      devid                    : 0x0000000008880001 (143130625)
>                      inode                    : 0x000000000001b419 (111641)
>                      extid                    : 0x0000000000000000 (0)
>                  path                     : '/space/groups/nfs'
>                  path_len                 : 0x00000000 (0)
>                  private_data             : 8bca2f0
>              entries: struct notify_entry
>                  server: struct server_id
>                      pid                      : 0x00001022 (4130)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x4fc2e81d160c3042 (5747411286099767362)
>                  filter                   : 0x00000017 (23)
>                  subdir_filter            : 0x00000000 (0)
>                  dir_fd                   : 0x00000024 (36)
>                  dir_id: struct file_id
>                      devid                    : 0x0000000008880001 (143130625)
>                      inode                    : 0x000000000001b419 (111641)
>                      extid                    : 0x0000000000000000 (0)
>                  path                     : '/space/groups/nfs'
>                  path_len                 : 0x00000000 (0)
>                  private_data             : 8bcd3d0
>[2011/12/21 10:14:08.162501, 10, pid=4176] lib/messages_local.c:255(messaging_tdb_store)
>  messaging_tdb_store:
>[2011/12/21 10:14:08.162534,  1, pid=4176] ../librpc/ndr/ndr.c:247(ndr_print_debug)
>       array: struct messaging_array
>          num_messages             : 0x00000001 (1)
>          messages: ARRAY(1)
>              messages: struct messaging_rec
>                  msg_version              : 0x00000002 (2)
>                  msg_type                 : MSG_PVFS_NOTIFY (784)
>                  dest: struct server_id
>                      pid                      : 0x00001003 (4099)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x527fadc63a4c486e (5944661100045551726)
>                  src: struct server_id
>                      pid                      : 0x00001050 (4176)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x748dc9918fd213db (8398590507136193499)
>                  buf                      : DATA_BLOB length=20
>  [0000] 01 00 00 00 6E 65 77 66   69 6C 65 2E 74 78 74 00   ....newf ile.txt.
>  [0010] F0 A2 BC 08                                       .... 
>[2011/12/21 10:14:08.163847, 10, pid=4176] lib/messages_local.c:255(messaging_tdb_store)
>  messaging_tdb_store:
>[2011/12/21 10:14:08.163881,  1, pid=4176] ../librpc/ndr/ndr.c:247(ndr_print_debug)
>       array: struct messaging_array
>          num_messages             : 0x00000001 (1)
>          messages: ARRAY(1)
>              messages: struct messaging_rec
>                  msg_version              : 0x00000002 (2)
>                  msg_type                 : MSG_PVFS_NOTIFY (784)
>                  dest: struct server_id
>                      pid                      : 0x00001022 (4130)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x4fc2e81d160c3042 (5747411286099767362)
>                  src: struct server_id
>                      pid                      : 0x00001050 (4176)
>                      vnn                      : 0xffffffff (4294967295)
>                      unique_id                : 0x748dc9918fd213db (8398590507136193499)
>                  buf                      : DATA_BLOB length=20
>  [0000] 01 00 00 00 6E 65 77 66   69 6C 65 2E 74 78 74 00   ....newf ile.txt.
>  [0010] D0 D3 BC 08                                       .... 
>[2011/12/21 10:14:08.165119, 10, pid=4176] smbd/notify_internal.c:930(notify_trigger)
>  notify_trigger called action=0x1, filter=0x1, path=/space/groups/nfs/newfile.txt
>[2011/12/21 10:14:08.165182,  2, pid=4176] smbd/open.c:694(open_file)
>  adtest opened file newfile.txt read=Yes write=Yes (numopen=1)
>[2011/12/21 10:14:08.165226, 10, pid=4176] lib/dbwrap_tdb.c:102(db_tdb_fetch_locked)
>  Locking key 01008808000000009711
>[2011/12/21 10:14:08.165269, 10, pid=4176] lib/dbwrap_tdb.c:131(db_tdb_fetch_locked)
>  Allocated locked data 0x8bbc978
>[2011/12/21 10:14:08.165301, 10, pid=4176] locking/brlock.c:1814(brl_get_locks_internal)
>  brl_get_locks_internal: 0 current locks on file_id 8880001:21197:0
>[2011/12/21 10:14:08.165362, 10, pid=4176] lib/dbwrap_tdb.c:44(db_tdb_record_destr)
>  Unlocking key 01008808000000009711
>[2011/12/21 10:14:08.165415, 10, pid=4176] lib/dbwrap_tdb.c:102(db_tdb_fetch_locked)
>  Locking key 01008808000000009711
>[2011/12/21 10:14:08.165463, 10, pid=4176] lib/dbwrap_tdb.c:131(db_tdb_fetch_locked)
>  Allocated locked data 0x8bbcae8
>[2011/12/21 10:14:08.165498, 10, pid=4176] smbd/open.c:1153(grant_fsp_oplock_type)
>  grant_fsp_oplock_type: oplock type 0x10 on file newfile.txt
>[2011/12/21 10:14:08.165567,  5, pid=4176] smbd/oplock.c:92(set_file_oplock)
>  set_file_oplock: granted oplock on file newfile.txt, 8880001:21197:0/1, tv_sec = 4ef1a360, tv_usec = 23699
>[2011/12/21 10:14:08.165604, 10, pid=4176] smbd/dosmode.c:707(file_set_dosmode)
>  file_set_dosmode: setting dos mode 0x20 on file newfile.txt
>[2011/12/21 10:14:08.165637,  8, pid=4176] smbd/dosmode.c:621(dos_mode)
>  dos_mode: newfile.txt
>[2011/12/21 10:14:08.169497, 10, pid=4176] lib/system.c:2426(solaris_attropen)
>  attropen FAILED: path: newfile.txt, name: user.DOSATTRIB, errno: No such file or directory
>[2011/12/21 10:14:08.169542, 10, pid=4176] smbd/file_access.c:205(can_access_file_data)
>  can_access_file_data: requesting 0x2 on file newfile.txt
>[2011/12/21 10:14:08.169569,  8, pid=4176] smbd/dosmode.c:199(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2011/12/21 10:14:08.169595,  8, pid=4176] smbd/dosmode.c:672(dos_mode)
>  dos_mode returning 
>[2011/12/21 10:14:08.169639, 10, pid=4176] smbd/dosmode.c:369(set_ea_dos_attribute)
>  set_ea_dos_attributes: set attribute 0x20, btime = Wed Dec 21 10:15:40 2011
>   on file newfile.txt
>[2011/12/21 10:14:08.173127, 10, pid=4176] smbd/dosmode.c:436(set_ea_dos_attribute)
>  set_ea_dos_attribute: set EA 0x20 on file newfile.txt
>[2011/12/21 10:14:08.173175, 10, pid=4176] locking/locking.c:806(unparse_share_modes)
>  unparse_share_modes: owrt: Wed Dec 21 10:15:40 2011 CET cwrt: Thu Jan  1 01:00:00 1970 CET, ntok: 0, num: 1
>[2011/12/21 10:14:08.173243, 10, pid=4176] locking/locking.c:535(print_share_mode_table)
>  print_share_mode_table: share_mode_entry[0]:  pid = 4176, share_access = 0x3, private_options = 0x0, access_mask = 0x12019f, mid = 0xa, type= 0x10, gen_id = 1, uid = 1129, flags = 0, file_id 8880001:21197:0, name_hash = 0xe721e3bd
>[2011/12/21 10:14:08.173325, 10, pid=4176] lib/dbwrap_tdb.c:44(db_tdb_record_destr)
>  Unlocking key 01008808000000009711
>[2011/12/21 10:14:08.173364, 10, pid=4176] smbd/open.c:3408(create_file_unixpath)
>  create_file_unixpath: info=2
>[2011/12/21 10:14:08.173408, 10, pid=4176] smbd/open.c:3691(create_file_default)
>  create_file: info=2
>[2011/12/21 10:14:08.173434,  8, pid=4176] smbd/dosmode.c:621(dos_mode)
>  dos_mode: newfile.txt
>[2011/12/21 10:14:08.174400, 10, pid=4176] smbd/dosmode.c:268(get_ea_dos_attribute)
>  get_ea_dos_attribute: newfile.txt attr = 0x20
>[2011/12/21 10:14:08.174440, 10, pid=4176] smbd/dosmode.c:310(get_ea_dos_attribute)
>  get_ea_dos_attribute: file newfile.txt case 3 set btime Wed Dec 21 10:15:40 2011
>  
>[2011/12/21 10:14:08.174497,  8, pid=4176] smbd/dosmode.c:326(get_ea_dos_attribute)
>  get_ea_dos_attribute returning (0x20)a
>[2011/12/21 10:14:08.174524,  8, pid=4176] smbd/dosmode.c:672(dos_mode)
>  dos_mode returning a
>[2011/12/21 10:14:08.175341, 10, pid=4176] lib/util_sock.c:516(read_smb_length_return_keepalive)
>  got smb length of 41
>[2011/12/21 10:14:08.175382,  6, pid=4176] smbd/process.c:1659(process_smb)
>  got message type 0x0 of len 0x29
>[2011/12/21 10:14:08.175425,  3, pid=4176] smbd/process.c:1661(process_smb)
>  Transaction 10 of length 45 (0 toread)
>[2011/12/21 10:14:08.175453,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:08.175467,  5, pid=4176] lib/util.c:342(show_msg)
>  size=41
>  smb_com=0x4
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=8
>  smb_flg2=51201
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=11
>  smt_wct=3
>  smb_vwv[ 0]=17200 (0x4330)
>  smb_vwv[ 1]=65535 (0xFFFF)
>  smb_vwv[ 2]=65535 (0xFFFF)
>  smb_bcc=0
>[2011/12/21 10:14:08.175658, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>[2011/12/21 10:14:08.175675,  3, pid=4176] smbd/process.c:1466(switch_message)
>  switch message SMBclose (pid 4176) conn 0x8bc82e0
>[2011/12/21 10:14:08.175701,  4, pid=4176] smbd/uid.c:351(change_to_user)
>  Skipping user change - already user
>[2011/12/21 10:14:08.175734,  3, pid=4176] smbd/reply.c:4851(reply_close)
>  close fd=31 fnum=17200 (numopen=1)
>[2011/12/21 10:14:08.175761,  6, pid=4176] smbd/close.c:527(set_close_write_time)
>  close_write_time: Thu Jan  1 00:59:59 1970
>[2011/12/21 10:14:08.175834, 10, pid=4176] lib/dbwrap_tdb.c:102(db_tdb_fetch_locked)
>  Locking key 01008808000000009711
>[2011/12/21 10:14:08.175869, 10, pid=4176] lib/dbwrap_tdb.c:131(db_tdb_fetch_locked)
>  Allocated locked data 0x8bd6cd0
>[2011/12/21 10:14:08.175895, 10, pid=4176] locking/locking.c:666(parse_share_modes)
>  parse_share_modes: owrt: Wed Dec 21 10:15:40 2011 CET, cwrt: Thu Jan  1 01:00:00 1970 CET, ntok: 0, num_share_modes: 1
>[2011/12/21 10:14:08.175948, 10, pid=4176] locking/locking.c:728(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 4176, share_access = 0x3, private_options = 0x0, access_mask = 0x12019f, mid = 0xa, type= 0x10, gen_id = 1, uid = 1129, flags = 0, file_id 8880001:21197:0, name_hash = 0xe721e3bd
>[2011/12/21 10:14:08.175981, 10, pid=4176] locking/locking.c:1618(get_delete_on_close_token)
>  get_delete_on_close_token: name_hash = 0xe721e3bd
>[2011/12/21 10:14:08.176010, 10, pid=4176] lib/dbwrap_tdb.c:44(db_tdb_record_destr)
>  Unlocking key 01008808000000009711
>[2011/12/21 10:14:08.176344,  2, pid=4176] smbd/close.c:691(close_normal_file)
>  adtest closed file newfile.txt (numopen=0) NT_STATUS_OK
>[2011/12/21 10:14:08.176383,  5, pid=4176] smbd/files.c:464(file_free)
>  freed files structure 17200 (0 used)
>[2011/12/21 10:14:08.176410,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:08.176425,  5, pid=4176] lib/util.c:342(show_msg)
>  size=35
>  smb_com=0x4
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=11
>  smt_wct=0
>  smb_bcc=0
>[2011/12/21 10:14:08.176574, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>[2011/12/21 10:14:09.497020, 10, pid=4176] lib/util_sock.c:516(read_smb_length_return_keepalive)
>  got smb length of 35
>[2011/12/21 10:14:09.497079,  6, pid=4176] smbd/process.c:1659(process_smb)
>  got message type 0x0 of len 0x23
>[2011/12/21 10:14:09.497106,  3, pid=4176] smbd/process.c:1661(process_smb)
>  Transaction 11 of length 39 (0 toread)
>[2011/12/21 10:14:09.497173,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:09.497190,  5, pid=4176] lib/util.c:342(show_msg)
>  size=35
>  smb_com=0x71
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=8
>  smb_flg2=51201
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=12
>  smt_wct=0
>  smb_bcc=0
>[2011/12/21 10:14:09.497320, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>[2011/12/21 10:14:09.497336,  3, pid=4176] smbd/process.c:1466(switch_message)
>  switch message SMBtdis (pid 4176) conn 0x8bc82e0
>[2011/12/21 10:14:09.497378,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:09.497406,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:09.497430,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:09.497478,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:09.497527,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:09.497552,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:09.497576,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:09.497615,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:09.497670,  1, pid=4176] smbd/service.c:1291(close_cnum)
>  debian (10.1.3.49) closed connection to service nfs
>[2011/12/21 10:14:09.497701,  3, pid=4176] smbd/connection.c:35(yield_connection)
>  Yielding connection to nfs
>[2011/12/21 10:14:09.497754, 10, pid=4176] lib/dbwrap_tdb.c:102(db_tdb_fetch_locked)
>  Locking key 50100000FFFFFFFFDB13
>[2011/12/21 10:14:09.497791, 10, pid=4176] lib/dbwrap_tdb.c:131(db_tdb_fetch_locked)
>  Allocated locked data 0x8bd6cd0
>[2011/12/21 10:14:09.497873, 10, pid=4176] lib/dbwrap_tdb.c:44(db_tdb_record_destr)
>  Unlocking key 50100000FFFFFFFFDB13
>[2011/12/21 10:14:09.497932,  4, pid=4176] smbd/vfs.c:780(vfs_ChDir)
>  vfs_ChDir to /
>[2011/12/21 10:14:09.497966,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:09.497992,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:09.498032,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:09.498076,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:09.498126,  5, pid=4176] lib/messages.c:332(messaging_deregister)
>  Deregistering messaging pointer for type 784 - private_data=8bc5478
>[2011/12/21 10:14:09.498170,  5, pid=4176] lib/util.c:332(show_msg)
>[2011/12/21 10:14:09.498204,  5, pid=4176] lib/util.c:342(show_msg)
>  size=35
>  smb_com=0x71
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=13837
>  smb_uid=100
>  smb_mid=12
>  smt_wct=0
>  smb_bcc=0
>[2011/12/21 10:14:09.498340, 10, pid=4176] ../lib/util/util.c:415(dump_data)
>[2011/12/21 10:14:09.499046,  5, pid=4176] lib/util_sock.c:316(read_fd_with_timeout)
>  read_fd_with_timeout: blocking read. EOF from client.
>[2011/12/21 10:14:09.499089,  1, pid=4176] smbd/process.c:456(receive_smb_talloc)
>  read_smb_length_return_keepalive failed for client 10.1.3.49 read error = NT_STATUS_END_OF_FILE.
>[2011/12/21 10:14:09.499147,  4, pid=4176] smbd/sec_ctx.c:314(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2011/12/21 10:14:09.499173,  5, pid=4176] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2011/12/21 10:14:09.499201,  5, pid=4176] auth/token_util.c:527(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2011/12/21 10:14:09.499258,  5, pid=4176] smbd/uid.c:400(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2011/12/21 10:14:09.499293, 10, pid=4176] lib/dbwrap_tdb.c:102(db_tdb_fetch_locked)
>  Locking key 49442F343137362F3130
>[2011/12/21 10:14:09.499328, 10, pid=4176] lib/dbwrap_tdb.c:131(db_tdb_fetch_locked)
>  Allocated locked data 0x8bc89a8
>[2011/12/21 10:14:09.499374, 10, pid=4176] lib/dbwrap_tdb.c:44(db_tdb_record_destr)
>  Unlocking key 49442F343137362F3130
>[2011/12/21 10:14:09.499593,  3, pid=4176] smbd/server_exit.c:180(exit_server_common)
>  Server exit (failed to receive smb request)

Actions: View

Attachments on bug 8660: 7179 | 7180 | 7181 | 7182 | 7190 | 7191 | 7192 | 7210 | 7235