Hello everyone!
After running Samba on several machines for some years, I just came
accross a rather strange problem. The short story is that the special
user home shares are readable, but not writeable.
Here's the long story: The system is a freshly set-up Debian Squeeze,
right out of the box. This is the Samba config:
-------------------------------- 8< --------------------------------
[global]
workgroup = HST
server string = %h server
dns proxy = no
log file = /var/log/samba/log.%m
max log size = 1000
syslog = 0
log level = 4
panic action = /usr/share/samba/panic-action %d
encrypt passwords = true
passdb backend = tdbsam
obey pam restrictions = yes
unix password sync = yes
passwd program = /usr/bin/passwd %u
passwd chat = *Enter\snew\s*\spassword:* %n\n
*Retype\snew\s*\spassword:* %n\n *password\supdated\ssuccessfully* .
pam password change = yes
[homes]
comment = Home Directories
browseable = no
read only = yes
create mask = 0700
directory mask = 0700
valid users = %S
-------------------------------- 8< --------------------------------
(Aside from the added log level line and the removed printer shares,
this is exactly the config file as delivered by Debian.)
I've added a linux user "testuser" including a home directory and
set a
Samba password by using "smbpasswd -a testuser".
-------------------------------- 8< --------------------------------
tux:/home# ls -la
...
drwxr-xr-x 2 testuser testuser 4096 23. Jun 14:01 testuser
-------------------------------- 8< --------------------------------
And this is what happens when I try to connect to the share and do a
write operation, for instance creating a directoy:
-------------------------------- 8< --------------------------------
tux:/home# smbclient -U testuser \\\\localhost\\testuser
Enter testuser's password:
Domain=[HST] OS=[Unix] Server=[Samba 3.5.6]
smb: \> mkdir test
NT_STATUS_MEDIA_WRITE_PROTECTED making remote directory \test
smb: \>
-------------------------------- 8< --------------------------------
As you can see from the directory listing above, the directory of course
is not write protected. (BTW: chmod-ing testuser's home directory to 777
didn't change anything.)
Here's an excerpt from /var/log/samba/log.tux. I've removed several
lines that seemed irrelevant to me in order to keep this mail short. Of
course I can supply the skipped lines if needed.
-------------------------------- 8< --------------------------------
[2012/06/23 14:07:02.437822, 3] auth/auth.c:216(check_ntlm_password)
check_ntlm_password: Checking password for unmapped user
[HST]\[testuser]@[TUX] with the new password interface
[2012/06/23 14:07:02.437836, 3] auth/auth.c:219(check_ntlm_password)
check_ntlm_password: mapped user is: [TUX]\[testuser]@[TUX]
[2012/06/23 14:07:02.437849, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.437858, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2012/06/23 14:07:02.437865, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.437895, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.437907, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.438168, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.438178, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.438345, 4]
../libcli/auth/ntlm_check.c:399(ntlm_password_check)
ntlm_password_check: Checking NT MD4 password
[2012/06/23 14:07:02.438388, 4] auth/auth_sam.c:180(sam_account_ok)
sam_account_ok: Checking SMB password for user testuser
...
[2012/06/23 14:07:02.438505, 3] auth/auth.c:265(check_ntlm_password)
check_ntlm_password: sam authentication for user [testuser] succeeded
[2012/06/23 14:07:02.438513, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.438520, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2012/06/23 14:07:02.438527, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.438537, 4] auth/pampass.c:472(smb_pam_start)
smb_pam_start: PAM: Init user: testuser
[2012/06/23 14:07:02.439100, 4] auth/pampass.c:489(smb_pam_start)
smb_pam_start: PAM: setting rhost to: ::ffff:127.0.0.1
[2012/06/23 14:07:02.439113, 4] auth/pampass.c:498(smb_pam_start)
smb_pam_start: PAM: setting tty
[2012/06/23 14:07:02.439121, 4] auth/pampass.c:506(smb_pam_start)
smb_pam_start: PAM: Init passed for user: testuser
[2012/06/23 14:07:02.439128, 4] auth/pampass.c:564(smb_pam_account)
smb_pam_account: PAM: Account Management for User: testuser
[2012/06/23 14:07:02.439189, 4] auth/pampass.c:583(smb_pam_account)
smb_pam_account: PAM: Account OK for User: testuser
[2012/06/23 14:07:02.439242, 4] auth/pampass.c:450(smb_pam_end)
smb_pam_end: PAM: PAM_END OK.
[2012/06/23 14:07:02.439255, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.439262, 2] auth/auth.c:304(check_ntlm_password)
check_ntlm_password: authentication for user [testuser] ->
[testuser] -> [testuser] succeeded
...
[2012/06/23 14:07:02.439363, 3]
auth/token_util.c:436(create_local_nt_token)
Failed to fetch domain sid for HST
...
[2012/06/23 14:07:02.439464, 3]
auth/token_util.c:467(create_local_nt_token)
Failed to fetch domain sid for HST
...
[2012/06/23 14:07:02.439596, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID
[S-1-5-21-759687158-2201287895-1803905152-1000]
[2012/06/23 14:07:02.439607, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID [S-1-22-2-1001]
[2012/06/23 14:07:02.439619, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID [S-1-5-2]
[2012/06/23 14:07:02.439629, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID [S-1-5-11]
...
[2012/06/23 14:07:02.439802, 3]
libsmb/ntlmssp_sign.c:343(ntlmssp_sign_init)
NTLMSSP Sign/Seal - Initialising with flags:
[2012/06/23 14:07:02.439810, 3] libsmb/ntlmssp.c:65(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
[2012/06/23 14:07:02.439842, 3] smbd/password.c:282(register_existing_vuid)
register_existing_vuid: User name: testuser Real name: Test-User
[2012/06/23 14:07:02.439851, 3] smbd/password.c:292(register_existing_vuid)
register_existing_vuid: UNIX uid 1001 is UNIX user testuser, and will
be vuid 100
[2012/06/23 14:07:02.439869, 4] auth/pampass.c:472(smb_pam_start)
smb_pam_start: PAM: Init user: testuser
[2012/06/23 14:07:02.440321, 4] auth/pampass.c:489(smb_pam_start)
smb_pam_start: PAM: setting rhost to: ::ffff:127.0.0.1
[2012/06/23 14:07:02.440332, 4] auth/pampass.c:498(smb_pam_start)
smb_pam_start: PAM: setting tty
[2012/06/23 14:07:02.440343, 4] auth/pampass.c:506(smb_pam_start)
smb_pam_start: PAM: Init passed for user: testuser
[2012/06/23 14:07:02.440350, 4]
auth/pampass.c:643(smb_internal_pam_session)
smb_internal_pam_session: PAM: tty set to: smb/1838/100
[2012/06/23 14:07:02.440432, 4] auth/pampass.c:450(smb_pam_end)
smb_pam_end: PAM: PAM_END OK.
[2012/06/23 14:07:02.440569, 3] smbd/password.c:223(register_homes_share)
Adding homes service for user 'testuser' using home directory:
'/home/testuser'
[2012/06/23 14:07:02.440604, 3] param/loadparm.c:6265(lp_add_home)
adding home's share [testuser] for user 'testuser' at
'/home/testuser'
[2012/06/23 14:07:02.440729, 3] smbd/process.c:1485(process_smb)
Transaction 3 of length 86 (0 toread)
[2012/06/23 14:07:02.440751, 3] smbd/process.c:1294(switch_message)
switch message SMBtconX (pid 1838) conn 0x0
...
[2012/06/23 14:07:02.440879, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.440889, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.441062, 3] smbd/vfs.c:97(vfs_init_default)
Initialising default vfs hooks
[2012/06/23 14:07:02.441074, 3] smbd/vfs.c:122(vfs_init_custom)
Initialising custom vfs hooks from [/[Default VFS]/]
...
[2012/06/23 14:07:02.441182, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.441193, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.441353, 3] smbd/service.c:1070(make_connection_snum)
tux (::ffff:127.0.0.1) connect to service IPC$ initially as user
testuser (uid=1001, gid=1001) (pid 1838)
[2012/06/23 14:07:02.441364, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441375, 3] smbd/reply.c:865(reply_tcon_and_X)
tconX service=IPC$
[2012/06/23 14:07:02.441478, 3] smbd/process.c:1485(process_smb)
Transaction 4 of length 114 (0 toread)
[2012/06/23 14:07:02.441499, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans2 (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:02.441512, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (1001, 1001) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441529, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /tmp
[2012/06/23 14:07:02.441555, 3] smbd/msdfs.c:848(get_referred_path)
get_referred_path: |testuser| in dfs path \localhost\testuser is not
a dfs root.
[2012/06/23 14:07:02.441566, 3] smbd/error.c:80(error_packet_set)
error packet at smbd/trans2.c(8018) cmd=50 (SMBtrans2)
NT_STATUS_NOT_FOUND
[2012/06/23 14:07:02.441651, 3] smbd/process.c:1485(process_smb)
Transaction 5 of length 39 (0 toread)
[2012/06/23 14:07:02.441664, 3] smbd/process.c:1294(switch_message)
switch message SMBtdis (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:02.441674, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441689, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441703, 3] smbd/service.c:1251(close_cnum)
tux (::ffff:127.0.0.1) closed connection to service IPC$
[2012/06/23 14:07:02.441716, 3] smbd/connection.c:31(yield_connection)
Yielding connection to IPC$
[2012/06/23 14:07:02.441740, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /
[2012/06/23 14:07:02.441749, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441835, 3] smbd/process.c:1485(process_smb)
Transaction 6 of length 96 (0 toread)
[2012/06/23 14:07:02.441845, 3] smbd/process.c:1294(switch_message)
switch message SMBtconX (pid 1838) conn 0x0
[2012/06/23 14:07:02.441853, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441864, 4] smbd/reply.c:786(reply_tcon_and_X)
Client requested device type [?????] for share [TESTUSER]
[2012/06/23 14:07:02.441876, 3] lib/util_sid.c:228(string_to_sid)
string_to_sid: Sid testuser does not start with 'S-'.
[2012/06/23 14:07:02.441889, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.441897, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441903, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.441918, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.441929, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442061, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.442070, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442299, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.442309, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442453, 3] smbd/service.c:807(make_connection_snum)
Connect path is '/home/testuser' for service [testuser]
[2012/06/23 14:07:02.442466, 3] smbd/vfs.c:97(vfs_init_default)
Initialising default vfs hooks
[2012/06/23 14:07:02.442474, 3] smbd/vfs.c:122(vfs_init_custom)
Initialising custom vfs hooks from [/[Default VFS]/]
[2012/06/23 14:07:02.442571, 3] lib/util_sid.c:228(string_to_sid)
string_to_sid: Sid testuser does not start with 'S-'.
[2012/06/23 14:07:02.442583, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.442590, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2012/06/23 14:07:02.442597, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.442611, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.442623, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442755, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.442764, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442992, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.443002, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.443161, 1] smbd/service.c:1070(make_connection_snum)
tux (::ffff:127.0.0.1) connect to service testuser initially as user
testuser (uid=1001, gid=1001) (pid 1838)
[2012/06/23 14:07:02.443172, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.443184, 3] smbd/reply.c:865(reply_tcon_and_X)
tconX service=TESTUSER
[2012/06/23 14:07:02.443521, 3] smbd/process.c:1485(process_smb)
Transaction 7 of length 57 (0 toread)
[2012/06/23 14:07:02.443532, 3] smbd/process.c:1294(switch_message)
switch message SMBecho (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:02.443539, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.443555, 3] smbd/reply.c:4978(reply_echo)
echo 1 times
[2012/06/23 14:07:05.484171, 3] smbd/process.c:1485(process_smb)
Transaction 8 of length 52 (0 toread)
[2012/06/23 14:07:05.484194, 3] smbd/process.c:1294(switch_message)
switch message SMBmkdir (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:05.484206, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (1001, 1001) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:05.484222, 3] smbd/error.c:80(error_packet_set)
error packet at smbd/process.c(1354) cmd=0 (SMBmkdir)
NT_STATUS_MEDIA_WRITE_PROTECTED
[2012/06/23 14:07:07.068152, 3] smbd/process.c:1485(process_smb)
Transaction 9 of length 57 (0 toread)
[2012/06/23 14:07:07.068173, 3] smbd/process.c:1294(switch_message)
switch message SMBecho (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:07.068185, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.068215, 3] smbd/reply.c:4978(reply_echo)
echo 1 times
[2012/06/23 14:07:07.644148, 3] smbd/process.c:1485(process_smb)
Transaction 10 of length 39 (0 toread)
[2012/06/23 14:07:07.644170, 3] smbd/process.c:1294(switch_message)
switch message SMBtdis (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:07.644181, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.644195, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /home/testuser
[2012/06/23 14:07:07.644209, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.644219, 1] smbd/service.c:1251(close_cnum)
tux (::ffff:127.0.0.1) closed connection to service testuser
[2012/06/23 14:07:07.644228, 3] smbd/connection.c:31(yield_connection)
Yielding connection to testuser
[2012/06/23 14:07:07.644245, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /
[2012/06/23 14:07:07.644253, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.659571, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.659600, 4] auth/pampass.c:472(smb_pam_start)
smb_pam_start: PAM: Init user: testuser
[2012/06/23 14:07:07.660099, 4] auth/pampass.c:489(smb_pam_start)
smb_pam_start: PAM: setting rhost to: ::ffff:127.0.0.1
[2012/06/23 14:07:07.660112, 4] auth/pampass.c:498(smb_pam_start)
smb_pam_start: PAM: setting tty
[2012/06/23 14:07:07.660119, 4] auth/pampass.c:506(smb_pam_start)
smb_pam_start: PAM: Init passed for user: testuser
[2012/06/23 14:07:07.660125, 4]
auth/pampass.c:643(smb_internal_pam_session)
smb_internal_pam_session: PAM: tty set to: smb/1838/100
[2012/06/23 14:07:07.660200, 4] auth/pampass.c:450(smb_pam_end)
smb_pam_end: PAM: PAM_END OK.
[2012/06/23 14:07:07.660221, 3] smbd/connection.c:31(yield_connection)
Yielding connection to
[2012/06/23 14:07:07.660268, 3] smbd/server.c:906(exit_server_common)
Server exit (failed to receive smb request)
-------------------------------- 8< --------------------------------
Unfortunately, I'm not particularly good at reading Samba logs...
So does anyone know what exactly is going on here and how to fix it?
Best regards,
Sebastian
Hello everyone!
After running Samba on several machines for some years, I just came
accross a rather strange problem. The short story is that the special
user home shares are readable, but not writeable.
Here's the long story: The system is a freshly set-up Debian Squeeze,
right out of the box. This is the Samba config:
-------------------------------- 8< --------------------------------
[global]
workgroup = HST
server string = %h server
dns proxy = no
log file = /var/log/samba/log.%m
max log size = 1000
syslog = 0
log level = 4
panic action = /usr/share/samba/panic-action %d
encrypt passwords = true
passdb backend = tdbsam
obey pam restrictions = yes
unix password sync = yes
passwd program = /usr/bin/passwd %u
passwd chat = *Enter\snew\s*\spassword:* %n\n
*Retype\snew\s*\spassword:* %n\n *password\supdated\ssuccessfully* .
pam password change = yes
[homes]
comment = Home Directories
browseable = no
read only = yes
create mask = 0700
directory mask = 0700
valid users = %S
-------------------------------- 8< --------------------------------
(Aside from the added log level line and the removed printer shares,
this is exactly the config file as delivered by Debian.)
I've added a linux user "testuser" including a home directory and
set a
Samba password by using "smbpasswd -a testuser".
-------------------------------- 8< --------------------------------
tux:/home# ls -la
...
drwxr-xr-x 2 testuser testuser 4096 23. Jun 14:01 testuser
-------------------------------- 8< --------------------------------
And this is what happens when I try to connect to the share and do a
write operation, for instance creating a directoy:
-------------------------------- 8< --------------------------------
tux:/home# smbclient -U testuser \\\\localhost\\testuser
Enter testuser's password:
Domain=[HST] OS=[Unix] Server=[Samba 3.5.6]
smb: \> mkdir test
NT_STATUS_MEDIA_WRITE_PROTECTED making remote directory \test
smb: \>
-------------------------------- 8< --------------------------------
As you can see from the directory listing above, the directory of course
is not write protected. (BTW: chmod-ing testuser's home directory to 777
didn't change anything.)
Here's an excerpt from /var/log/samba/log.tux. I've removed several
lines that seemed irrelevant to me in order to keep this mail short. Of
course I can supply the skipped lines if needed.
-------------------------------- 8< --------------------------------
[2012/06/23 14:07:02.437822, 3] auth/auth.c:216(check_ntlm_password)
check_ntlm_password: Checking password for unmapped user
[HST]\[testuser]@[TUX] with the new password interface
[2012/06/23 14:07:02.437836, 3] auth/auth.c:219(check_ntlm_password)
check_ntlm_password: mapped user is: [TUX]\[testuser]@[TUX]
[2012/06/23 14:07:02.437849, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.437858, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2012/06/23 14:07:02.437865, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.437895, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.437907, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.438168, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.438178, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.438345, 4]
../libcli/auth/ntlm_check.c:399(ntlm_password_check)
ntlm_password_check: Checking NT MD4 password
[2012/06/23 14:07:02.438388, 4] auth/auth_sam.c:180(sam_account_ok)
sam_account_ok: Checking SMB password for user testuser
...
[2012/06/23 14:07:02.438505, 3] auth/auth.c:265(check_ntlm_password)
check_ntlm_password: sam authentication for user [testuser] succeeded
[2012/06/23 14:07:02.438513, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.438520, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2012/06/23 14:07:02.438527, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.438537, 4] auth/pampass.c:472(smb_pam_start)
smb_pam_start: PAM: Init user: testuser
[2012/06/23 14:07:02.439100, 4] auth/pampass.c:489(smb_pam_start)
smb_pam_start: PAM: setting rhost to: ::ffff:127.0.0.1
[2012/06/23 14:07:02.439113, 4] auth/pampass.c:498(smb_pam_start)
smb_pam_start: PAM: setting tty
[2012/06/23 14:07:02.439121, 4] auth/pampass.c:506(smb_pam_start)
smb_pam_start: PAM: Init passed for user: testuser
[2012/06/23 14:07:02.439128, 4] auth/pampass.c:564(smb_pam_account)
smb_pam_account: PAM: Account Management for User: testuser
[2012/06/23 14:07:02.439189, 4] auth/pampass.c:583(smb_pam_account)
smb_pam_account: PAM: Account OK for User: testuser
[2012/06/23 14:07:02.439242, 4] auth/pampass.c:450(smb_pam_end)
smb_pam_end: PAM: PAM_END OK.
[2012/06/23 14:07:02.439255, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.439262, 2] auth/auth.c:304(check_ntlm_password)
check_ntlm_password: authentication for user [testuser] ->
[testuser] -> [testuser] succeeded
...
[2012/06/23 14:07:02.439363, 3]
auth/token_util.c:436(create_local_nt_token)
Failed to fetch domain sid for HST
...
[2012/06/23 14:07:02.439464, 3]
auth/token_util.c:467(create_local_nt_token)
Failed to fetch domain sid for HST
...
[2012/06/23 14:07:02.439596, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID
[S-1-5-21-759687158-2201287895-1803905152-1000]
[2012/06/23 14:07:02.439607, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID [S-1-22-2-1001]
[2012/06/23 14:07:02.439619, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID [S-1-5-2]
[2012/06/23 14:07:02.439629, 3] lib/privileges.c:63(get_privileges)
get_privileges: No privileges assigned to SID [S-1-5-11]
...
[2012/06/23 14:07:02.439802, 3]
libsmb/ntlmssp_sign.c:343(ntlmssp_sign_init)
NTLMSSP Sign/Seal - Initialising with flags:
[2012/06/23 14:07:02.439810, 3] libsmb/ntlmssp.c:65(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
[2012/06/23 14:07:02.439842, 3] smbd/password.c:282(register_existing_vuid)
register_existing_vuid: User name: testuser Real name: Test-User
[2012/06/23 14:07:02.439851, 3] smbd/password.c:292(register_existing_vuid)
register_existing_vuid: UNIX uid 1001 is UNIX user testuser, and
will be vuid 100
[2012/06/23 14:07:02.439869, 4] auth/pampass.c:472(smb_pam_start)
smb_pam_start: PAM: Init user: testuser
[2012/06/23 14:07:02.440321, 4] auth/pampass.c:489(smb_pam_start)
smb_pam_start: PAM: setting rhost to: ::ffff:127.0.0.1
[2012/06/23 14:07:02.440332, 4] auth/pampass.c:498(smb_pam_start)
smb_pam_start: PAM: setting tty
[2012/06/23 14:07:02.440343, 4] auth/pampass.c:506(smb_pam_start)
smb_pam_start: PAM: Init passed for user: testuser
[2012/06/23 14:07:02.440350, 4]
auth/pampass.c:643(smb_internal_pam_session)
smb_internal_pam_session: PAM: tty set to: smb/1838/100
[2012/06/23 14:07:02.440432, 4] auth/pampass.c:450(smb_pam_end)
smb_pam_end: PAM: PAM_END OK.
[2012/06/23 14:07:02.440569, 3] smbd/password.c:223(register_homes_share)
Adding homes service for user 'testuser' using home directory:
'/home/testuser'
[2012/06/23 14:07:02.440604, 3] param/loadparm.c:6265(lp_add_home)
adding home's share [testuser] for user 'testuser' at
'/home/testuser'
[2012/06/23 14:07:02.440729, 3] smbd/process.c:1485(process_smb)
Transaction 3 of length 86 (0 toread)
[2012/06/23 14:07:02.440751, 3] smbd/process.c:1294(switch_message)
switch message SMBtconX (pid 1838) conn 0x0
...
[2012/06/23 14:07:02.440879, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.440889, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.441062, 3] smbd/vfs.c:97(vfs_init_default)
Initialising default vfs hooks
[2012/06/23 14:07:02.441074, 3] smbd/vfs.c:122(vfs_init_custom)
Initialising custom vfs hooks from [/[Default VFS]/]
...
[2012/06/23 14:07:02.441182, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.441193, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.441353, 3] smbd/service.c:1070(make_connection_snum)
tux (::ffff:127.0.0.1) connect to service IPC$ initially as user
testuser (uid=1001, gid=1001) (pid 1838)
[2012/06/23 14:07:02.441364, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441375, 3] smbd/reply.c:865(reply_tcon_and_X)
tconX service=IPC$
[2012/06/23 14:07:02.441478, 3] smbd/process.c:1485(process_smb)
Transaction 4 of length 114 (0 toread)
[2012/06/23 14:07:02.441499, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans2 (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:02.441512, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (1001, 1001) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441529, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /tmp
[2012/06/23 14:07:02.441555, 3] smbd/msdfs.c:848(get_referred_path)
get_referred_path: |testuser| in dfs path \localhost\testuser is not
a dfs root.
[2012/06/23 14:07:02.441566, 3] smbd/error.c:80(error_packet_set)
error packet at smbd/trans2.c(8018) cmd=50 (SMBtrans2)
NT_STATUS_NOT_FOUND
[2012/06/23 14:07:02.441651, 3] smbd/process.c:1485(process_smb)
Transaction 5 of length 39 (0 toread)
[2012/06/23 14:07:02.441664, 3] smbd/process.c:1294(switch_message)
switch message SMBtdis (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:02.441674, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441689, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441703, 3] smbd/service.c:1251(close_cnum)
tux (::ffff:127.0.0.1) closed connection to service IPC$
[2012/06/23 14:07:02.441716, 3] smbd/connection.c:31(yield_connection)
Yielding connection to IPC$
[2012/06/23 14:07:02.441740, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /
[2012/06/23 14:07:02.441749, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441835, 3] smbd/process.c:1485(process_smb)
Transaction 6 of length 96 (0 toread)
[2012/06/23 14:07:02.441845, 3] smbd/process.c:1294(switch_message)
switch message SMBtconX (pid 1838) conn 0x0
[2012/06/23 14:07:02.441853, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441864, 4] smbd/reply.c:786(reply_tcon_and_X)
Client requested device type [?????] for share [TESTUSER]
[2012/06/23 14:07:02.441876, 3] lib/util_sid.c:228(string_to_sid)
string_to_sid: Sid testuser does not start with 'S-'.
[2012/06/23 14:07:02.441889, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.441897, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2012/06/23 14:07:02.441903, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.441918, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.441929, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442061, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.442070, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442299, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.442309, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442453, 3] smbd/service.c:807(make_connection_snum)
Connect path is '/home/testuser' for service [testuser]
[2012/06/23 14:07:02.442466, 3] smbd/vfs.c:97(vfs_init_default)
Initialising default vfs hooks
[2012/06/23 14:07:02.442474, 3] smbd/vfs.c:122(vfs_init_custom)
Initialising custom vfs hooks from [/[Default VFS]/]
[2012/06/23 14:07:02.442571, 3] lib/util_sid.c:228(string_to_sid)
string_to_sid: Sid testuser does not start with 'S-'.
[2012/06/23 14:07:02.442583, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.442590, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2012/06/23 14:07:02.442597, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2012/06/23 14:07:02.442611, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.442623, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442755, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.442764, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.442992, 4] lib/substitute.c:504(automount_server)
Home server: tux
[2012/06/23 14:07:02.443002, 4] lib/substitute.c:504(automount_server)
Home server: tux
...
[2012/06/23 14:07:02.443161, 1] smbd/service.c:1070(make_connection_snum)
tux (::ffff:127.0.0.1) connect to service testuser initially as user
testuser (uid=1001, gid=1001) (pid 1838)
[2012/06/23 14:07:02.443172, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.443184, 3] smbd/reply.c:865(reply_tcon_and_X)
tconX service=TESTUSER
[2012/06/23 14:07:02.443521, 3] smbd/process.c:1485(process_smb)
Transaction 7 of length 57 (0 toread)
[2012/06/23 14:07:02.443532, 3] smbd/process.c:1294(switch_message)
switch message SMBecho (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:02.443539, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:02.443555, 3] smbd/reply.c:4978(reply_echo)
echo 1 times
[2012/06/23 14:07:05.484171, 3] smbd/process.c:1485(process_smb)
Transaction 8 of length 52 (0 toread)
[2012/06/23 14:07:05.484194, 3] smbd/process.c:1294(switch_message)
switch message SMBmkdir (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:05.484206, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (1001, 1001) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:05.484222, 3] smbd/error.c:80(error_packet_set)
error packet at smbd/process.c(1354) cmd=0 (SMBmkdir)
NT_STATUS_MEDIA_WRITE_PROTECTED
[2012/06/23 14:07:07.068152, 3] smbd/process.c:1485(process_smb)
Transaction 9 of length 57 (0 toread)
[2012/06/23 14:07:07.068173, 3] smbd/process.c:1294(switch_message)
switch message SMBecho (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:07.068185, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.068215, 3] smbd/reply.c:4978(reply_echo)
echo 1 times
[2012/06/23 14:07:07.644148, 3] smbd/process.c:1485(process_smb)
Transaction 10 of length 39 (0 toread)
[2012/06/23 14:07:07.644170, 3] smbd/process.c:1294(switch_message)
switch message SMBtdis (pid 1838) conn 0x7f248e902500
[2012/06/23 14:07:07.644181, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.644195, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /home/testuser
[2012/06/23 14:07:07.644209, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.644219, 1] smbd/service.c:1251(close_cnum)
tux (::ffff:127.0.0.1) closed connection to service testuser
[2012/06/23 14:07:07.644228, 3] smbd/connection.c:31(yield_connection)
Yielding connection to testuser
[2012/06/23 14:07:07.644245, 4] smbd/vfs.c:721(vfs_ChDir)
vfs_ChDir to /
[2012/06/23 14:07:07.644253, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.659571, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2012/06/23 14:07:07.659600, 4] auth/pampass.c:472(smb_pam_start)
smb_pam_start: PAM: Init user: testuser
[2012/06/23 14:07:07.660099, 4] auth/pampass.c:489(smb_pam_start)
smb_pam_start: PAM: setting rhost to: ::ffff:127.0.0.1
[2012/06/23 14:07:07.660112, 4] auth/pampass.c:498(smb_pam_start)
smb_pam_start: PAM: setting tty
[2012/06/23 14:07:07.660119, 4] auth/pampass.c:506(smb_pam_start)
smb_pam_start: PAM: Init passed for user: testuser
[2012/06/23 14:07:07.660125, 4]
auth/pampass.c:643(smb_internal_pam_session)
smb_internal_pam_session: PAM: tty set to: smb/1838/100
[2012/06/23 14:07:07.660200, 4] auth/pampass.c:450(smb_pam_end)
smb_pam_end: PAM: PAM_END OK.
[2012/06/23 14:07:07.660221, 3] smbd/connection.c:31(yield_connection)
Yielding connection to
[2012/06/23 14:07:07.660268, 3] smbd/server.c:906(exit_server_common)
Server exit (failed to receive smb request)
-------------------------------- 8< --------------------------------
Unfortunately, I'm not particularly good at reading Samba logs...
So does anyone know what exactly is going on here and how to fix it?
Best regards,
Sebastian