I'm building a replacement samba 3.5.6 domain controller to replace an
old 3.0 one. Some other things are changing too. Our user accounts are
now in LDAP rather than flat files (although the machine trust accounts
will remain in a flat file), but that should be hidden from samba as
it's going to be done through NSS. The smbpasswd file is a TDB file and
will remain so. Our users don't authenticate with any native services
on the server other than samba and PAM hasn't been configured to use
LDAP. Samba was built with --without-pam as it authenticates using its
own smbpasswd file and nothing else will need to authenticate that way.
Our intention is to move over to an entirely LDAP based system, but
we're doing that a stage at a time.
So far, so good. Samba duly starts and I can join an XP PC to the
domain without an issue. But when I try to log into the domain using my
username I get:
"The system cannot log you on now because the domain KIS2 is not
available"
nmblookup happily returns
querying KIS2 on 160.5.10.3
160.5.10.3 KIS2<1c>
so it looks like its registered as a domain controller happily and
besides, PC's can join the domain. I can mount shares from the server
using my username and I can see the IPC$ share anonymously. I can log
into the PC using a local account and mount shares using my username.
Anonymous login successful
Domain=[KIS2] OS=[Unix] Server=[Samba 3.5.6]
Sharename Type Comment
--------- ---- -------
IPC$ IPC IPC Service (Keele I.T. Services)
Anonymous login successful
Domain=[KIS2] OS=[Unix] Server=[Samba 3.5.6]
Server Comment
--------- -------
OATCAKE Keele I.T. Services
Workgroup Master
--------- -------
KIS2 OATCAKE
Oatcake is the samba server and nmblookup shows it with the right IP
address. Testparm shows the critical options as:
map untrusted to domain = Yes
domain logons = Yes
domain master = Yes
So I can't see an obvious problem there.
So clearly I've made some sort of obvious error somewhere that escapes
me. At the risk of appearing foolish amongst my peers I am posting in
the hope that you can point me in the direction I need to investigate.
I'll include the end of the log.smbd running at debug level 5 which
shows the logon process access the IPC$ share and then the connection
being dropped.
2010/10/22 12:01:55.413644, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.413761, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.413789, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.413810, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.413832, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.413853, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.413896, 5]
passdb/pdb_interface.c:1473(lookup_global_sam_rid)
lookup_global_sam_rid: looking up RID 513.
[2010/10/22 12:01:55.413959, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2010/10/22 12:01:55.413985, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2010/10/22 12:01:55.414007, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2010/10/22 12:01:55.414029, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.414050, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.414460, 5] passdb/pdb_tdb.c:609(tdbsam_getsampwrid)
pdb_getsampwrid (TDB): error looking up RID 513 by key RID_00000201.
[2010/10/22 12:01:55.414652, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.414690, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.414718, 3] auth/auth.c:265(check_ntlm_password)
check_ntlm_password: guest authentication for user [] succeeded
[2010/10/22 12:01:55.414742, 5] auth/auth.c:304(check_ntlm_password)
check_ntlm_password: guest authentication for user [] -> [] ->
[nobody] succeeded
[2010/10/22 12:01:55.414765, 5] auth/auth_util.c:2119(free_user_info)
attempting to free (and zero) a user_info structure
[2010/10/22 12:01:55.414819, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.414846, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.414868, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.414890, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.414911, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.415007, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.415037, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.415060, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.415081, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.415103, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.415124, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.415209, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2010/10/22 12:01:55.415236, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2010/10/22 12:01:55.415258, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2010/10/22 12:01:55.415280, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.415301, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.415379, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.415406, 5]
auth/token_util.c:306(create_builtin_administrators)
create_builtin_administrators: Failed to create Administrators
[2010/10/22 12:01:55.415433, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.415470, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.415494, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.415516, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.415550, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.415573, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.415686, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.415715, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.415739, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.415760, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.415794, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.415816, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.415869, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2010/10/22 12:01:55.415894, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2010/10/22 12:01:55.415916, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2010/10/22 12:01:55.415937, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.415958, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.416036, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.416063, 5] auth/token_util.c:277(create_builtin_users)
create_builtin_users: Failed to create Users
[2010/10/22 12:01:55.416089, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.416113, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.416136, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.416158, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.416180, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.416201, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.416484, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.416568, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID
[S-1-5-21-2471090356-3006052325-2789242325-501]
[2010/10/22 12:01:55.416625, 5]
lib/privileges.c:128(get_privileges_for_sids)
get_privileges_for_sids: sid = S-1-1-0
Privilege set:
SE_PRIV 0x0 0x0 0x0 0x0
[2010/10/22 12:01:55.416667, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID [S-1-5-2]
[2010/10/22 12:01:55.416697, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID [S-1-5-32-546]
[2010/10/22 12:01:55.416735, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.416759, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.416781, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.416805, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.416827, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.416907, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.416947, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.416972, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.416993, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.417016, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.417037, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.417112, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.417153, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.417177, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.417242, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.417266, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.417287, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.417366, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.417430, 3]
libsmb/ntlmssp_sign.c:343(ntlmssp_sign_init)
NTLMSSP Sign/Seal - Initialising with flags:
[2010/10/22 12:01:55.417455, 3] libsmb/ntlmssp.c:65(debug_ntlmssp_flags)
Got NTLMSSP neg_flags=0xe2088215
NTLMSSP_NEGOTIATE_UNICODE
NTLMSSP_REQUEST_TARGET
NTLMSSP_NEGOTIATE_SIGN
NTLMSSP_NEGOTIATE_NTLM
NTLMSSP_NEGOTIATE_ALWAYS_SIGN
NTLMSSP_NEGOTIATE_NTLM2
NTLMSSP_NEGOTIATE_VERSION
NTLMSSP_NEGOTIATE_128
NTLMSSP_NEGOTIATE_KEY_EXCH
NTLMSSP_NEGOTIATE_56
[2010/10/22 12:01:55.417544, 3] smbd/password.c:282(register_existing_vuid)
register_existing_vuid: User name: nobody Real name: Nobody
[2010/10/22 12:01:55.417601, 3] smbd/password.c:292(register_existing_vuid)
register_existing_vuid: UNIX uid 99 is UNIX user nobody, and will be
vuid 100
[2010/10/22 12:01:55.417659, 5] lib/util.c:617(show_msg)
[2010/10/22 12:01:55.417680, 5] lib/util.c:627(show_msg)
size=96
smb_com=0x73
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51203
smb_tid=0
smb_pid=65279
smb_uid=100
smb_mid=128
smt_wct=4
smb_vwv[ 0]= 255 (0xFF)
smb_vwv[ 1]= 0 (0x0)
smb_vwv[ 2]= 1 (0x1)
smb_vwv[ 3]= 9 (0x9)
smb_bcc=53
[2010/10/22 12:01:55.419330, 3] smbd/process.c:1485(process_smb)
Transaction 3 of length 84 (0 toread)
[2010/10/22 12:01:55.419362, 5] lib/util.c:617(show_msg)
[2010/10/22 12:01:55.419380, 5] lib/util.c:627(show_msg)
size=80
smb_com=0x75
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=24
smb_flg2=51207
smb_tid=0
smb_pid=65279
smb_uid=100
smb_mid=192
smt_wct=4
smb_vwv[ 0]= 255 (0xFF)
smb_vwv[ 1]= 80 (0x50)
smb_vwv[ 2]= 8 (0x8)
smb_vwv[ 3]= 1 (0x1)
smb_bcc=37
[2010/10/22 12:01:55.419469, 3] smbd/process.c:1294(switch_message)
switch message SMBtconX (pid 19474) conn 0x0
[2010/10/22 12:01:55.419492, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.419513, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.419542, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.419588, 5] smbd/uid.c:369(change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2010/10/22 12:01:55.419645, 4] smbd/reply.c:786(reply_tcon_and_X)
Client requested device type [?????] for share [IPC$]
[2010/10/22 12:01:55.419726, 5] smbd/service.c:1227(make_connection)
making a connection to 'normal' service ipc$
[2010/10/22 12:01:55.419771, 3] lib/access.c:362(only_ipaddrs_in_list)
only_ipaddrs_in_list: list has non-ip address (160.5.)
[2010/10/22 12:01:55.419794, 3] lib/access.c:396(check_access)
check_access: hostnames in host allow/deny list.
[2010/10/22 12:01:55.419824, 2] lib/access.c:406(check_access)
Allowed connection from pc67.isc.keele.ac.uk (160.5.50.10)
[2010/10/22 12:01:55.419898, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.419926, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.419948, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.419969, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.419990, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.420044, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.420080, 5] lib/username.c:133(Get_Pwnam_alloc)
Finding user nobody
[2010/10/22 12:01:55.420102, 5] lib/username.c:77(Get_Pwnam_internals)
Trying _Get_Pwnam(), username as lowercase is nobody
[2010/10/22 12:01:55.420126, 5] lib/username.c:110(Get_Pwnam_internals)
Get_Pwnam_internals did find user [nobody]!
[2010/10/22 12:01:55.420217, 5] lib/username.c:133(Get_Pwnam_alloc)
Finding user nobody
[2010/10/22 12:01:55.420245, 5] lib/username.c:77(Get_Pwnam_internals)
Trying _Get_Pwnam(), username as lowercase is nobody
[2010/10/22 12:01:55.420268, 5] lib/username.c:110(Get_Pwnam_internals)
Get_Pwnam_internals did find user [nobody]!
[2010/10/22 12:01:55.420352, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.420381, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.420403, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.420425, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.420446, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.420488, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.420520, 5] lib/username.c:133(Get_Pwnam_alloc)
Finding user nobody
[2010/10/22 12:01:55.420547, 5] lib/username.c:77(Get_Pwnam_internals)
Trying _Get_Pwnam(), username as lowercase is nobody
[2010/10/22 12:01:55.420570, 5] lib/username.c:110(Get_Pwnam_internals)
Get_Pwnam_internals did find user [nobody]!
[2010/10/22 12:01:55.420625, 3] smbd/service.c:807(make_connection_snum)
Connect path is '/tmp' for service [IPC$]
[2010/10/22 12:01:55.420734, 3] smbd/vfs.c:97(vfs_init_default)
Initialising default vfs hooks
[2010/10/22 12:01:55.420790, 5] smbd/vfs.c:87(smb_register_vfs)
Successfully added vfs backend '/[Default VFS]/'
[2010/10/22 12:01:55.420813, 3] smbd/vfs.c:122(vfs_init_custom)
Initialising custom vfs hooks from [/[Default VFS]/]
Successfully loaded vfs module [/[Default VFS]/] with the new modules
system
[2010/10/22 12:01:55.420845, 5] smbd/connection.c:142(claim_connection)
claiming [IPC$]
[2010/10/22 12:01:55.420990, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.421018, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.421041, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.421063, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.421084, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.421126, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.421159, 5] lib/username.c:133(Get_Pwnam_alloc)
Finding user nobody
[2010/10/22 12:01:55.421180, 5] lib/username.c:77(Get_Pwnam_internals)
Trying _Get_Pwnam(), username as lowercase is nobody
[2010/10/22 12:01:55.421202, 5] lib/username.c:110(Get_Pwnam_internals)
Get_Pwnam_internals did find user [nobody]!
[2010/10/22 12:01:55.421274, 5] lib/username.c:133(Get_Pwnam_alloc)
Finding user nobody
[2010/10/22 12:01:55.421299, 5] lib/username.c:77(Get_Pwnam_internals)
Trying _Get_Pwnam(), username as lowercase is nobody
[2010/10/22 12:01:55.421322, 5] lib/username.c:110(Get_Pwnam_internals)
Get_Pwnam_internals did find user [nobody]!
[2010/10/22 12:01:55.421389, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.421415, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2010/10/22 12:01:55.421435, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2010/10/22 12:01:55.421466, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.421550, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.421666, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.421705, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (99, 99) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.421728, 5] auth/token_util.c:531(debug_nt_user_token)
NT user token of user S-1-5-21-2471090356-3006052325-2789242325-501
contains 5 SIDs
SID[ 0]: S-1-5-21-2471090356-3006052325-2789242325-501
SID[ 1]: S-1-1-0
SID[ 2]: S-1-5-2
SID[ 3]: S-1-5-32-546
SID[ 4]: S-1-22-1-99
SE_PRIV 0x0 0x0 0x0 0x0
[2010/10/22 12:01:55.421794, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 99
Primary group is 99 and contains 0 supplementary groups
[2010/10/22 12:01:55.421827, 5] smbd/uid.c:354(change_to_user)
change_to_user uid=(0,99) gid=(0,99)
[2010/10/22 12:01:55.421900, 3] smbd/service.c:1070(make_connection_snum)
pc67-isc (160.5.50.10) connect to service IPC$ initially as user
nobody (uid=99, gid=99) (pid 19474)
[2010/10/22 12:01:55.421932, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.421955, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.421976, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.422010, 5] smbd/uid.c:369(change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2010/10/22 12:01:55.422038, 3] smbd/reply.c:865(reply_tcon_and_X)
tconX service=IPC$
[2010/10/22 12:01:55.460116, 5] lib/util_sock.c:462(read_fd_with_timeout)
read_fd_with_timeout: blocking read. EOF from client.
[2010/10/22 12:01:55.460151, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.460176, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.460197, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.460230, 5] smbd/uid.c:369(change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2010/10/22 12:01:55.460273, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /tmp
[2010/10/22 12:01:55.460343, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.460368, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.460390, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.460423, 5] smbd/uid.c:369(change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2010/10/22 12:01:55.460447, 3] smbd/service.c:1251(close_cnum)
pc67-isc (160.5.50.10) closed connection to service IPC$
[2010/10/22 12:01:55.460474, 3] smbd/connection.c:31(yield_connection)
Yielding connection to IPC$
[2010/10/22 12:01:55.460520, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /
[2010/10/22 12:01:55.460547, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2010/10/22 12:01:55.460569, 5] auth/token_util.c:525(debug_nt_user_token)
NT user token: (NULL)
[2010/10/22 12:01:55.460590, 5]
auth/token_util.c:551(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2010/10/22 12:01:55.460620, 5] smbd/uid.c:369(change_to_root_user)
change_to_root_user: now uid=(0,0) gid=(0,0)
[2010/10/22 12:01:55.460677, 3] smbd/connection.c:31(yield_connection)
Yielding connection to
[2010/10/22 12:01:55.460796, 3] smbd/server.c:902(exit_server_common)
Server exit (failed to receive smb request)
[2010/10/22 12:01:55.469789, 3] smbd/server.c:259(remove_child_pid)
smbd/server.c:259 Unclean shutdown of pid 19474
[2010/10/22 12:01:55.469993, 1] smbd/server.c:267(remove_child_pid)
Scheduled cleanup of brl and lock database after unclean shutdown
[2010/10/22 12:02:15.476763, 1] smbd/server.c:240(cleanup_timeout_fn)
Cleaning up brl and lock database after unclean shutdown
Jonathan,
A guess --
I had the same error message and similar log entries because I had set
server signing = auto
The 3.5.x PDC would work only with the default "No".
Dale
On 10/22/2010 6:06 AM, Jonathan Knight wrote:>
> I'm building a replacement samba 3.5.6 domain controller to replace an
> old 3.0 one. Some other things are changing too. Our user accounts
> are now in LDAP rather than flat files (although the machine trust
> accounts will remain in a flat file), but that should be hidden from
> samba as it's going to be done through NSS. The smbpasswd file is a
> TDB file and will remain so. Our users don't authenticate with any
> native services on the server other than samba and PAM hasn't been
> configured to use LDAP. Samba was built with --without-pam as it
> authenticates using its own smbpasswd file and nothing else will need
> to authenticate that way.
>
> Our intention is to move over to an entirely LDAP based system, but
> we're doing that a stage at a time.
>
> So far, so good. Samba duly starts and I can join an XP PC to the
> domain without an issue. But when I try to log into the domain using
> my username I get:
>
> "The system cannot log you on now because the domain KIS2 is not
> available"
>
> nmblookup happily returns
>
> querying KIS2 on 160.5.10.3
> 160.5.10.3 KIS2<1c>
>
> so it looks like its registered as a domain controller happily and
> besides, PC's can join the domain. I can mount shares from the server
> using my username and I can see the IPC$ share anonymously. I can log
> into the PC using a local account and mount shares using my username.
>
>
> Anonymous login successful
> Domain=[KIS2] OS=[Unix] Server=[Samba 3.5.6]
>
> Sharename Type Comment
> --------- ---- -------
> IPC$ IPC IPC Service (Keele I.T. Services)
>
> Anonymous login successful
> Domain=[KIS2] OS=[Unix] Server=[Samba 3.5.6]
>
> Server Comment
> --------- -------
> OATCAKE Keele I.T. Services
>
> Workgroup Master
> --------- -------
> KIS2 OATCAKE
>
>
> Oatcake is the samba server and nmblookup shows it with the right IP
> address. Testparm shows the critical options as:
>
>
> map untrusted to domain = Yes
> domain logons = Yes
> domain master = Yes
>
> So I can't see an obvious problem there.
>
>
> So clearly I've made some sort of obvious error somewhere that escapes
> me. At the risk of appearing foolish amongst my peers I am posting in
> the hope that you can point me in the direction I need to
> investigate. I'll include the end of the log.smbd running at debug
> level 5 which shows the logon process access the IPC$ share and then
> the connection being dropped.
>
> 2010/10/22 12:01:55.413644, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.413761, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.413789, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.413810, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.413832, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.413853, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.413896, 5]
> passdb/pdb_interface.c:1473(lookup_global_sam_rid)
> lookup_global_sam_rid: looking up RID 513.
> [2010/10/22 12:01:55.413959, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
> [2010/10/22 12:01:55.413985, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.414007, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
> [2010/10/22 12:01:55.414029, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.414050, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.414460, 5] passdb/pdb_tdb.c:609(tdbsam_getsampwrid)
> pdb_getsampwrid (TDB): error looking up RID 513 by key RID_00000201.
> [2010/10/22 12:01:55.414652, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.414690, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.414718, 3] auth/auth.c:265(check_ntlm_password)
> check_ntlm_password: guest authentication for user [] succeeded
> [2010/10/22 12:01:55.414742, 5] auth/auth.c:304(check_ntlm_password)
> check_ntlm_password: guest authentication for user [] -> [] ->
> [nobody] succeeded
> [2010/10/22 12:01:55.414765, 5] auth/auth_util.c:2119(free_user_info)
> attempting to free (and zero) a user_info structure
> [2010/10/22 12:01:55.414819, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.414846, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.414868, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.414890, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.414911, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.415007, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.415037, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.415060, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.415081, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.415103, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.415124, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.415209, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
> [2010/10/22 12:01:55.415236, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.415258, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
> [2010/10/22 12:01:55.415280, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.415301, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.415379, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.415406, 5]
> auth/token_util.c:306(create_builtin_administrators)
> create_builtin_administrators: Failed to create Administrators
> [2010/10/22 12:01:55.415433, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.415470, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.415494, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.415516, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.415550, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.415573, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.415686, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.415715, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.415739, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.415760, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.415794, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.415816, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.415869, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
> [2010/10/22 12:01:55.415894, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.415916, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
> [2010/10/22 12:01:55.415937, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.415958, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.416036, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.416063, 5]
> auth/token_util.c:277(create_builtin_users)
> create_builtin_users: Failed to create Users
> [2010/10/22 12:01:55.416089, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.416113, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.416136, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.416158, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.416180, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.416201, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.416484, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.416568, 3] lib/privileges.c:63(get_privileges)
> get_privileges: No privileges assigned to SID
> [S-1-5-21-2471090356-3006052325-2789242325-501]
> [2010/10/22 12:01:55.416625, 5]
> lib/privileges.c:128(get_privileges_for_sids)
> get_privileges_for_sids: sid = S-1-1-0
> Privilege set:
> SE_PRIV 0x0 0x0 0x0 0x0
> [2010/10/22 12:01:55.416667, 3] lib/privileges.c:63(get_privileges)
> get_privileges: No privileges assigned to SID [S-1-5-2]
> [2010/10/22 12:01:55.416697, 3] lib/privileges.c:63(get_privileges)
> get_privileges: No privileges assigned to SID [S-1-5-32-546]
> [2010/10/22 12:01:55.416735, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.416759, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.416781, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.416805, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.416827, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.416907, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.416947, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.416972, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.416993, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.417016, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.417037, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.417112, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.417153, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.417177, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.417242, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.417266, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.417287, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.417366, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.417430, 3]
> libsmb/ntlmssp_sign.c:343(ntlmssp_sign_init)
> NTLMSSP Sign/Seal - Initialising with flags:
> [2010/10/22 12:01:55.417455, 3] libsmb/ntlmssp.c:65(debug_ntlmssp_flags)
> Got NTLMSSP neg_flags=0xe2088215
> NTLMSSP_NEGOTIATE_UNICODE
> NTLMSSP_REQUEST_TARGET
> NTLMSSP_NEGOTIATE_SIGN
> NTLMSSP_NEGOTIATE_NTLM
> NTLMSSP_NEGOTIATE_ALWAYS_SIGN
> NTLMSSP_NEGOTIATE_NTLM2
> NTLMSSP_NEGOTIATE_VERSION
> NTLMSSP_NEGOTIATE_128
> NTLMSSP_NEGOTIATE_KEY_EXCH
> NTLMSSP_NEGOTIATE_56
> [2010/10/22 12:01:55.417544, 3]
> smbd/password.c:282(register_existing_vuid)
> register_existing_vuid: User name: nobody Real name: Nobody
> [2010/10/22 12:01:55.417601, 3]
> smbd/password.c:292(register_existing_vuid)
> register_existing_vuid: UNIX uid 99 is UNIX user nobody, and will be
> vuid 100
> [2010/10/22 12:01:55.417659, 5] lib/util.c:617(show_msg)
> [2010/10/22 12:01:55.417680, 5] lib/util.c:627(show_msg)
> size=96
> smb_com=0x73
> smb_rcls=0
> smb_reh=0
> smb_err=0
> smb_flg=136
> smb_flg2=51203
> smb_tid=0
> smb_pid=65279
> smb_uid=100
> smb_mid=128
> smt_wct=4
> smb_vwv[ 0]= 255 (0xFF)
> smb_vwv[ 1]= 0 (0x0)
> smb_vwv[ 2]= 1 (0x1)
> smb_vwv[ 3]= 9 (0x9)
> smb_bcc=53
> [2010/10/22 12:01:55.419330, 3] smbd/process.c:1485(process_smb)
> Transaction 3 of length 84 (0 toread)
> [2010/10/22 12:01:55.419362, 5] lib/util.c:617(show_msg)
> [2010/10/22 12:01:55.419380, 5] lib/util.c:627(show_msg)
> size=80
> smb_com=0x75
> smb_rcls=0
> smb_reh=0
> smb_err=0
> smb_flg=24
> smb_flg2=51207
> smb_tid=0
> smb_pid=65279
> smb_uid=100
> smb_mid=192
> smt_wct=4
> smb_vwv[ 0]= 255 (0xFF)
> smb_vwv[ 1]= 80 (0x50)
> smb_vwv[ 2]= 8 (0x8)
> smb_vwv[ 3]= 1 (0x1)
> smb_bcc=37
> [2010/10/22 12:01:55.419469, 3] smbd/process.c:1294(switch_message)
> switch message SMBtconX (pid 19474) conn 0x0
> [2010/10/22 12:01:55.419492, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.419513, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.419542, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.419588, 5] smbd/uid.c:369(change_to_root_user)
> change_to_root_user: now uid=(0,0) gid=(0,0)
> [2010/10/22 12:01:55.419645, 4] smbd/reply.c:786(reply_tcon_and_X)
> Client requested device type [?????] for share [IPC$]
> [2010/10/22 12:01:55.419726, 5] smbd/service.c:1227(make_connection)
> making a connection to 'normal' service ipc$
> [2010/10/22 12:01:55.419771, 3] lib/access.c:362(only_ipaddrs_in_list)
> only_ipaddrs_in_list: list has non-ip address (160.5.)
> [2010/10/22 12:01:55.419794, 3] lib/access.c:396(check_access)
> check_access: hostnames in host allow/deny list.
> [2010/10/22 12:01:55.419824, 2] lib/access.c:406(check_access)
> Allowed connection from pc67.isc.keele.ac.uk (160.5.50.10)
> [2010/10/22 12:01:55.419898, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.419926, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.419948, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.419969, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.419990, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.420044, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.420080, 5] lib/username.c:133(Get_Pwnam_alloc)
> Finding user nobody
> [2010/10/22 12:01:55.420102, 5] lib/username.c:77(Get_Pwnam_internals)
> Trying _Get_Pwnam(), username as lowercase is nobody
> [2010/10/22 12:01:55.420126, 5] lib/username.c:110(Get_Pwnam_internals)
> Get_Pwnam_internals did find user [nobody]!
> [2010/10/22 12:01:55.420217, 5] lib/username.c:133(Get_Pwnam_alloc)
> Finding user nobody
> [2010/10/22 12:01:55.420245, 5] lib/username.c:77(Get_Pwnam_internals)
> Trying _Get_Pwnam(), username as lowercase is nobody
> [2010/10/22 12:01:55.420268, 5] lib/username.c:110(Get_Pwnam_internals)
> Get_Pwnam_internals did find user [nobody]!
> [2010/10/22 12:01:55.420352, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.420381, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.420403, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.420425, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.420446, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.420488, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.420520, 5] lib/username.c:133(Get_Pwnam_alloc)
> Finding user nobody
> [2010/10/22 12:01:55.420547, 5] lib/username.c:77(Get_Pwnam_internals)
> Trying _Get_Pwnam(), username as lowercase is nobody
> [2010/10/22 12:01:55.420570, 5] lib/username.c:110(Get_Pwnam_internals)
> Get_Pwnam_internals did find user [nobody]!
> [2010/10/22 12:01:55.420625, 3] smbd/service.c:807(make_connection_snum)
> Connect path is '/tmp' for service [IPC$]
> [2010/10/22 12:01:55.420734, 3] smbd/vfs.c:97(vfs_init_default)
> Initialising default vfs hooks
> [2010/10/22 12:01:55.420790, 5] smbd/vfs.c:87(smb_register_vfs)
> Successfully added vfs backend '/[Default VFS]/'
> [2010/10/22 12:01:55.420813, 3] smbd/vfs.c:122(vfs_init_custom)
> Initialising custom vfs hooks from [/[Default VFS]/]
> Successfully loaded vfs module [/[Default VFS]/] with the new
> modules system
> [2010/10/22 12:01:55.420845, 5] smbd/connection.c:142(claim_connection)
> claiming [IPC$]
> [2010/10/22 12:01:55.420990, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.421018, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.421041, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.421063, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.421084, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.421126, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.421159, 5] lib/username.c:133(Get_Pwnam_alloc)
> Finding user nobody
> [2010/10/22 12:01:55.421180, 5] lib/username.c:77(Get_Pwnam_internals)
> Trying _Get_Pwnam(), username as lowercase is nobody
> [2010/10/22 12:01:55.421202, 5] lib/username.c:110(Get_Pwnam_internals)
> Get_Pwnam_internals did find user [nobody]!
> [2010/10/22 12:01:55.421274, 5] lib/username.c:133(Get_Pwnam_alloc)
> Finding user nobody
> [2010/10/22 12:01:55.421299, 5] lib/username.c:77(Get_Pwnam_internals)
> Trying _Get_Pwnam(), username as lowercase is nobody
> [2010/10/22 12:01:55.421322, 5] lib/username.c:110(Get_Pwnam_internals)
> Get_Pwnam_internals did find user [nobody]!
> [2010/10/22 12:01:55.421389, 3] smbd/sec_ctx.c:210(push_sec_ctx)
> push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.421415, 3] smbd/uid.c:429(push_conn_ctx)
> push_conn_ctx(0) : conn_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.421435, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
> [2010/10/22 12:01:55.421466, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.421550, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.421666, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
> pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.421705, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (99, 99) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.421728, 5]
> auth/token_util.c:531(debug_nt_user_token)
> NT user token of user S-1-5-21-2471090356-3006052325-2789242325-501
> contains 5 SIDs
> SID[ 0]: S-1-5-21-2471090356-3006052325-2789242325-501
> SID[ 1]: S-1-1-0
> SID[ 2]: S-1-5-2
> SID[ 3]: S-1-5-32-546
> SID[ 4]: S-1-22-1-99
> SE_PRIV 0x0 0x0 0x0 0x0
> [2010/10/22 12:01:55.421794, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 99
> Primary group is 99 and contains 0 supplementary groups
> [2010/10/22 12:01:55.421827, 5] smbd/uid.c:354(change_to_user)
> change_to_user uid=(0,99) gid=(0,99)
> [2010/10/22 12:01:55.421900, 3]
> smbd/service.c:1070(make_connection_snum)
> pc67-isc (160.5.50.10) connect to service IPC$ initially as user
> nobody (uid=99, gid=99) (pid 19474)
> [2010/10/22 12:01:55.421932, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.421955, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.421976, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.422010, 5] smbd/uid.c:369(change_to_root_user)
> change_to_root_user: now uid=(0,0) gid=(0,0)
> [2010/10/22 12:01:55.422038, 3] smbd/reply.c:865(reply_tcon_and_X)
> tconX service=IPC$
> [2010/10/22 12:01:55.460116, 5]
> lib/util_sock.c:462(read_fd_with_timeout)
> read_fd_with_timeout: blocking read. EOF from client.
> [2010/10/22 12:01:55.460151, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.460176, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.460197, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.460230, 5] smbd/uid.c:369(change_to_root_user)
> change_to_root_user: now uid=(0,0) gid=(0,0)
> [2010/10/22 12:01:55.460273, 4] smbd/vfs.c:721(vfs_ChDir)
> vfs_ChDir to /tmp
> [2010/10/22 12:01:55.460343, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.460368, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.460390, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.460423, 5] smbd/uid.c:369(change_to_root_user)
> change_to_root_user: now uid=(0,0) gid=(0,0)
> [2010/10/22 12:01:55.460447, 3] smbd/service.c:1251(close_cnum)
> pc67-isc (160.5.50.10) closed connection to service IPC$
> [2010/10/22 12:01:55.460474, 3] smbd/connection.c:31(yield_connection)
> Yielding connection to IPC$
> [2010/10/22 12:01:55.460520, 4] smbd/vfs.c:721(vfs_ChDir)
> vfs_ChDir to /
> [2010/10/22 12:01:55.460547, 3] smbd/sec_ctx.c:310(set_sec_ctx)
> setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2010/10/22 12:01:55.460569, 5]
> auth/token_util.c:525(debug_nt_user_token)
> NT user token: (NULL)
> [2010/10/22 12:01:55.460590, 5]
> auth/token_util.c:551(debug_unix_user_token)
> UNIX token of user 0
> Primary group is 0 and contains 0 supplementary groups
> [2010/10/22 12:01:55.460620, 5] smbd/uid.c:369(change_to_root_user)
> change_to_root_user: now uid=(0,0) gid=(0,0)
> [2010/10/22 12:01:55.460677, 3] smbd/connection.c:31(yield_connection)
> Yielding connection to
> [2010/10/22 12:01:55.460796, 3] smbd/server.c:902(exit_server_common)
> Server exit (failed to receive smb request)
> [2010/10/22 12:01:55.469789, 3] smbd/server.c:259(remove_child_pid)
> smbd/server.c:259 Unclean shutdown of pid 19474
> [2010/10/22 12:01:55.469993, 1] smbd/server.c:267(remove_child_pid)
> Scheduled cleanup of brl and lock database after unclean shutdown
> [2010/10/22 12:02:15.476763, 1] smbd/server.c:240(cleanup_timeout_fn)
> Cleaning up brl and lock database after unclean shutdown
>