[Samba] Cannot get plaintext+pam auth to work on 4.2.10
Marcin Owsiany
marcin at owsiany.pl
Wed Dec 14 07:43:51 UTC 2016
Hello,
After an almost 19 year gap, I need to ask this list for help again :-)
I have somewhat specific circumstances, where I think I can tolerate
plaintext passwords on the wire as long as I get samba to authenticate
against the system /etc/shadow (using PAM) in exchange.
0) I'm using Debian 8.4 (jessie), samba packages 2:4.2.10+dfsg-0+deb8u3.
1) I have created user smbtest with password asdasd
2) put the following into /etc/samba/smb.conf and reloaded smbd:
[global]
debug level = 10 passdb:10
server role = standalone server
obey pam restrictions = yes
encrypt passwords = no
lanman auth = yes
ntlm auth = no
server max protocol = LANMAN2
client lanman auth = yes
client plaintext auth = yes
client ntlmv2 auth = no
; the above seem relevant, see below for dump of full config
[data]
path = /srv
read only = no
3) /etc/pam.d/samba is at unexciting default:
@include common-auth
@include common-account
@include common-session-noninteractive
4) and yet:
porridge at piec:~$ smbclient -U smbtest //localhost/data asdasd
session setup failed: NT_STATUS_ACCESS_DENIED
porridge at piec:~$
It seems that the password is being sent as plaintext,
make_user_info_for_reply: User passwords not in encrypted format.
but authentication using pam is failing for some reason:
check_ntlm_password: unix authentication for user [SMBTEST] FAILED with
error NT_STATUS_LOGON_FAILURE
Does anyone have a clue why? From what I understood plaintext auth is
discouraged, but should still work?
Full debug output from both smbclient and smbd follows:
porridge at piec:~$ smbclient -d 10 -U smbtest //localhost/data asdasd
INFO: Current debug levels:
all: 10
tdb: 10
printdrivers: 10
lanman: 10
smb: 10
rpc_parse: 10
rpc_srv: 10
rpc_cli: 10
passdb: 10
sam: 10
auth: 10
winbind: 10
vfs: 10
idmap: 10
quota: 10
acls: 10
locking: 10
msdfs: 10
dmapi: 10
registry: 10
scavenger: 10
dns: 10
ldb: 10
lp_load_ex: refreshing parameters
Initialising global parameters
INFO: Current debug levels:
all: 10
tdb: 10
printdrivers: 10
lanman: 10
smb: 10
rpc_parse: 10
rpc_srv: 10
rpc_cli: 10
passdb: 10
sam: 10
auth: 10
winbind: 10
vfs: 10
idmap: 10
quota: 10
acls: 10
locking: 10
msdfs: 10
dmapi: 10
registry: 10
scavenger: 10
dns: 10
ldb: 10
Processing section "[global]"
doing parameter workgroup = WORKGROUP
doing parameter dns proxy = no
doing parameter log file = /var/log/samba/log.%m
doing parameter max log size = 1000
doing parameter syslog = 0
doing parameter panic action = /usr/share/samba/panic-action %d
doing parameter debug level = 10 passdb:10
doing parameter server role = standalone server
doing parameter obey pam restrictions = yes
doing parameter unix password sync = yes
doing parameter passwd program = /usr/bin/passwd %u
doing parameter passwd chat = *Enter\snew\s*\spassword:* %n\n
*Retype\snew\s*\spassword:* %n\n *password\supdated\ssuccessfully* .
doing parameter pam password change = yes
doing parameter map to guest = bad user
doing parameter usershare allow guests = yes
doing parameter encrypt passwords = no
doing parameter lanman auth = yes
doing parameter ntlm auth = no
doing parameter server max protocol = LANMAN2
doing parameter client lanman auth = yes
doing parameter client plaintext auth = yes
doing parameter client ntlmv2 auth = no
pm_process() returned Yes
lp_servicenumber: couldn't find homes
added interface eth0 ip=192.168.1.1 bcast=192.168.1.255
netmask=255.255.255.0
added interface eth1 ip=192.168.192.1 bcast=192.168.192.255
netmask=255.255.255.0
Netbios name list:-
my_netbios_names[0]="PIEC"
Client started (version 4.2.10-Debian).
Opening cache file at /var/cache/samba/gencache.tdb
gencache_init: Opening cache file /var/cache/samba/gencache.tdb read-only.
Opening cache file at /var/run/samba/gencache_notrans.tdb
sitename_fetch: No stored sitename for
internal_resolve_name: looking up localhost#20 (sitename (null))
no entry for localhost#20 found.
resolve_lmhosts: Attempting lmhosts lookup for name localhost<0x20>
resolve_lmhosts: Attempting lmhosts lookup for name localhost<0x20>
startlmhosts: Can't open lmhosts file /etc/samba/lmhosts. Error was Nie ma
takiego pliku ani katalogu
resolve_wins: WINS server resolution selected and no WINS servers listed.
resolve_hosts: Attempting host lookup for name localhost<0x20>
remove_duplicate_addrs2: looking for duplicate address/port pairs
namecache_store: storing 2 addresses for localhost#20: [::1],127.0.0.1
Adding cache entry with key=[NBT/LOCALHOST#20] and timeout=[śro gru 14
08:49:32 2016 CET] (660 seconds ahead)
internal_resolve_name: returning 2 addresses: ::1:0 127.0.0.1:0
Connecting to ::1 at port 445
Socket options:
SO_KEEPALIVE = 0
SO_REUSEADDR = 0
SO_BROADCAST = 0
TCP_NODELAY = 1
TCP_KEEPCNT = 9
TCP_KEEPIDLE = 7200
TCP_KEEPINTVL = 75
IPTOS_LOWDELAY = 0
IPTOS_THROUGHPUT = 0
SO_REUSEPORT = 0
SO_SNDBUF = 2626560
SO_RCVBUF = 1061504
SO_SNDLOWAT = 1
SO_RCVLOWAT = 1
SO_SNDTIMEO = 0
SO_RCVTIMEO = 0
TCP_QUICKACK = 1
TCP_DEFER_ACCEPT = 0
session request ok
session setup failed: NT_STATUS_ACCESS_DENIED
porridge at piec:~$
[2016/12/14 08:17:38.025725, 6, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2134(lp_file_list_changed)
lp_file_list_changed()
file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Dec
13 22:44:22 2016
file /etc/samba/smb.conf modified: Wed Dec 14 08:09:01 2016
[2016/12/14 08:17:38.025767, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1237(free_service)
free_service: Freeing service homes
[2016/12/14 08:17:38.025787, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1237(free_service)
free_service: Freeing service printers
[2016/12/14 08:17:38.025802, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1237(free_service)
free_service: Freeing service print$
[2016/12/14 08:17:38.025817, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1237(free_service)
free_service: Freeing service data
[2016/12/14 08:17:38.025826, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1237(free_service)
free_service: Freeing service IPC$
[2016/12/14 08:17:38.025834, 3, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:3636(lp_load_ex)
lp_load_ex: refreshing parameters
[2016/12/14 08:17:38.025840, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1212(free_param_opts)
Freeing parametrics:
[2016/12/14 08:17:38.025881, 3, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:527(init_globals)
Initialising global parameters
[2016/12/14 08:17:38.025941, 3, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2579(lp_do_section)
Processing section "[global]"
doing parameter workgroup = WORKGROUP
doing parameter dns proxy = no
doing parameter log file = /var/log/samba/log.%m
doing parameter max log size = 1000
doing parameter syslog = 0
doing parameter panic action = /usr/share/samba/panic-action %d
doing parameter debug level = 10 passdb:10
[2016/12/14 08:17:38.026008, 5, pid=30811, effective(0, 0), real(0, 0)]
../lib/util/debug.c:334(debug_dump_status)
INFO: Current debug levels:
all: 10
tdb: 10
printdrivers: 10
lanman: 10
smb: 10
rpc_parse: 10
rpc_srv: 10
rpc_cli: 10
passdb: 10
sam: 10
auth: 10
winbind: 10
vfs: 10
idmap: 10
quota: 10
acls: 10
locking: 10
msdfs: 10
dmapi: 10
registry: 10
scavenger: 10
dns: 10
ldb: 10
doing parameter server role = standalone server
doing parameter obey pam restrictions = yes
doing parameter unix password sync = yes
doing parameter passwd program = /usr/bin/passwd %u
doing parameter passwd chat = *Enter\snew\s*\spassword:* %n\n
*Retype\snew\s*\spassword:* %n\n *password\supdated\ssuccessfully* .
doing parameter pam password change = yes
doing parameter map to guest = bad user
doing parameter usershare allow guests = yes
doing parameter encrypt passwords = no
doing parameter lanman auth = yes
doing parameter ntlm auth = no
doing parameter server max protocol = LANMAN2
doing parameter client lanman auth = yes
doing parameter client plaintext auth = yes
doing parameter client ntlmv2 auth = no
[2016/12/14 08:17:38.026136, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2596(lp_do_section)
Processing section "[homes]"
[2016/12/14 08:17:38.026151, 8, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1319(add_a_service)
add_a_service: Creating snum = 89 for homes
[2016/12/14 08:17:38.026156, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1369(hash_a_service)
hash_a_service: hashing index 89 for service name homes
doing parameter comment = Home Directories
doing parameter browseable = no
doing parameter read only = yes
doing parameter create mask = 0700
doing parameter directory mask = 0700
doing parameter valid users = %S
[2016/12/14 08:17:38.026214, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2596(lp_do_section)
Processing section "[printers]"
[2016/12/14 08:17:38.026226, 8, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1319(add_a_service)
add_a_service: Creating snum = 90 for printers
[2016/12/14 08:17:38.026231, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1369(hash_a_service)
hash_a_service: hashing index 90 for service name printers
doing parameter comment = All Printers
doing parameter browseable = no
doing parameter path = /var/spool/samba
doing parameter printable = yes
doing parameter guest ok = no
doing parameter read only = yes
doing parameter create mask = 0700
[2016/12/14 08:17:38.026281, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2596(lp_do_section)
Processing section "[print$]"
[2016/12/14 08:17:38.026300, 8, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1319(add_a_service)
add_a_service: Creating snum = 91 for print$
[2016/12/14 08:17:38.026306, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1369(hash_a_service)
hash_a_service: hashing index 91 for service name print$
doing parameter comment = Printer Drivers
doing parameter path = /var/lib/samba/printers
doing parameter browseable = yes
doing parameter read only = yes
doing parameter guest ok = no
[2016/12/14 08:17:38.026339, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2596(lp_do_section)
Processing section "[data]"
[2016/12/14 08:17:38.026349, 8, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1319(add_a_service)
add_a_service: Creating snum = 92 for data
[2016/12/14 08:17:38.026355, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1369(hash_a_service)
hash_a_service: hashing index 92 for service name data
doing parameter path = /srv
doing parameter read only = no
[2016/12/14 08:17:38.026375, 4, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:3677(lp_load_ex)
pm_process() returned Yes
[2016/12/14 08:17:38.026391, 8, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1319(add_a_service)
add_a_service: Creating snum = 93 for IPC$
[2016/12/14 08:17:38.026396, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1369(hash_a_service)
hash_a_service: hashing index 93 for service name IPC$
[2016/12/14 08:17:38.026403, 3, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1476(lp_add_ipc)
adding IPC service
[2016/12/14 08:17:38.026471, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/interface.c:341(add_interface)
added interface eth0 ip=192.168.1.1 bcast=192.168.1.255
netmask=255.255.255.0
[2016/12/14 08:17:38.026483, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/interface.c:341(add_interface)
added interface eth1 ip=192.168.192.1 bcast=192.168.192.255
netmask=255.255.255.0
[2016/12/14 08:17:38.026493, 5, pid=30811, effective(0, 0), real(0, 0)]
../lib/util/util_net.c:1055(print_socket_options)
Socket options:
SO_KEEPALIVE = 1
SO_REUSEADDR = 1
SO_BROADCAST = 0
TCP_NODELAY = 1
TCP_KEEPCNT = 9
TCP_KEEPIDLE = 7200
TCP_KEEPINTVL = 75
IPTOS_LOWDELAY = 0
IPTOS_THROUGHPUT = 0
SO_REUSEPORT = 1
SO_SNDBUF = 2626560
SO_RCVBUF = 1061696
SO_SNDLOWAT = 1
SO_RCVLOWAT = 1
SO_SNDTIMEO = 0
SO_RCVTIMEO = 0
TCP_QUICKACK = 1
TCP_DEFER_ACCEPT = 0
[2016/12/14 08:17:38.026529, 5, pid=30811, effective(0, 0), real(0, 0)]
../lib/util/util_net.c:1055(print_socket_options)
Socket options:
SO_KEEPALIVE = 1
SO_REUSEADDR = 1
SO_BROADCAST = 0
TCP_NODELAY = 1
TCP_KEEPCNT = 9
TCP_KEEPIDLE = 7200
TCP_KEEPINTVL = 75
IPTOS_LOWDELAY = 0
IPTOS_THROUGHPUT = 0
SO_REUSEPORT = 1
SO_SNDBUF = 2626560
SO_RCVBUF = 1061696
SO_SNDLOWAT = 1
SO_RCVLOWAT = 1
SO_SNDTIMEO = 0
SO_RCVTIMEO = 0
TCP_QUICKACK = 1
TCP_DEFER_ACCEPT = 0
[2016/12/14 08:17:38.026579, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 774 - private_data=0x7ff15c68c6c0
[2016/12/14 08:17:38.026586, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 778 - private_data=0x7ff15c68c6c0
[2016/12/14 08:17:38.026591, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 770 - private_data=0x7ff15c68c6c0
[2016/12/14 08:17:38.026596, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 787 - private_data=0x7ff15c68c6c0
[2016/12/14 08:17:38.026601, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 779 - private_data=0x7ff15c68c6c0
[2016/12/14 08:17:38.026610, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 15 - private_data=(nil)
[2016/12/14 08:17:38.026616, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:399(messaging_register)
Overriding messaging pointer for type 15 - private_data=(nil)
[2016/12/14 08:17:38.026621, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:431(messaging_deregister)
Deregistering messaging pointer for type 16 - private_data=(nil)
[2016/12/14 08:17:38.026626, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 16 - private_data=0x7ff15c68c6c0
[2016/12/14 08:17:38.026631, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:431(messaging_deregister)
Deregistering messaging pointer for type 33 - private_data=0x7ff15c662f00
[2016/12/14 08:17:38.026636, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 33 - private_data=0x7ff15c68c6c0
[2016/12/14 08:17:38.026641, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:431(messaging_deregister)
Deregistering messaging pointer for type 790 - private_data=(nil)
[2016/12/14 08:17:38.026646, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 790 - private_data=0x7ff15c68c6c0
[2016/12/14 08:17:38.026651, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:431(messaging_deregister)
Deregistering messaging pointer for type 791 - private_data=(nil)
[2016/12/14 08:17:38.026656, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:431(messaging_deregister)
Deregistering messaging pointer for type 1 - private_data=(nil)
[2016/12/14 08:17:38.026661, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/messages.c:384(messaging_register)
Registering messaging pointer for type 1 - private_data=(nil)
[2016/12/14 08:17:38.026668, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/events.c:483(event_add_idle)
event_add_idle: idle_evt(keepalive) 0x7ff15c690080
[2016/12/14 08:17:38.026674, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/events.c:483(event_add_idle)
event_add_idle: idle_evt(deadtime) 0x7ff15c6902d0
[2016/12/14 08:17:38.026682, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/events.c:483(event_add_idle)
event_add_idle: idle_evt(housekeeping) 0x7ff15c690520
[2016/12/14 08:17:38.026700, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util_sock.c:369(read_smb_length_return_keepalive)
got smb length of 190
[2016/12/14 08:17:38.026708, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util.c:168(show_msg)
[2016/12/14 08:17:38.026712, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util.c:178(show_msg)
size=190
smb_com=0x72
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=24
smb_flg2=51267
smb_tid=0
smb_pid=65534
smb_uid=0
smb_mid=0
smt_wct=0
smb_bcc=155
[2016/12/14 08:17:38.026732, 10, pid=30811, effective(0, 0), real(0, 0)]
../lib/util/util.c:559(dump_data)
[0000] 02 50 43 20 4E 45 54 57 4F 52 4B 20 50 52 4F 47 .PC NETW ORK
PROG
[0010] 52 41 4D 20 31 2E 30 00 02 4D 49 43 52 4F 53 4F RAM 1.0.
.MICROSO
[0020] 46 54 20 4E 45 54 57 4F 52 4B 53 20 31 2E 30 33 FT NETWO RKS
1.03
[0030] 00 02 4D 49 43 52 4F 53 4F 46 54 20 4E 45 54 57 ..MICROS OFT
NETW
[0040] 4F 52 4B 53 20 33 2E 30 00 02 4C 41 4E 4D 41 4E ORKS 3.0
..LANMAN
[0050] 31 2E 30 00 02 4C 4D 31 2E 32 58 30 30 32 00 02 1.0..LM1
.2X002..
[0060] 44 4F 53 20 4C 41 4E 4D 41 4E 32 2E 31 00 02 4C DOS LANM
AN2.1..L
[0070] 41 4E 4D 41 4E 32 2E 31 00 02 53 61 6D 62 61 00 ANMAN2.1
..Samba.
[0080] 02 4E 54 20 4C 41 4E 4D 41 4E 20 31 2E 30 00 02 .NT LANM AN
1.0..
[0090] 4E 54 20 4C 4D 20 30 2E 31 32 00 NT LM 0. 12.
[2016/12/14 08:17:38.026849, 5, pid=30811, effective(0, 0), real(0, 0)]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/14 08:17:38.026859, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/14 08:17:38.027388, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util.c:1291(set_remote_arch)
set_remote_arch: Client arch is 'Samba'
[2016/12/14 08:17:38.027409, 6, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2134(lp_file_list_changed)
lp_file_list_changed()
file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Dec
14 08:09:01 2016
[2016/12/14 08:17:38.027422, 5, pid=30811, effective(0, 0), real(0, 0)]
../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order)
check lock order 2 for /var/run/samba/serverid.tdb
[2016/12/14 08:17:38.027428, 10, pid=30811, effective(0, 0), real(0, 0)]
../lib/dbwrap/dbwrap.c:133(debug_lock_order)
lock order: 1:<none> 2:/var/run/samba/serverid.tdb 3:<none>
[2016/12/14 08:17:38.027436, 10, pid=30811, effective(0, 0), real(0, 0)]
../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
Locking key 5B78000000000000FFFF
[2016/12/14 08:17:38.027446, 10, pid=30811, effective(0, 0), real(0, 0)]
../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal)
Allocated locked data 0x0x7ff15c691410
[2016/12/14 08:17:38.027454, 10, pid=30811, effective(0, 0), real(0, 0)]
../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
Unlocking key 5B78000000000000FFFF
[2016/12/14 08:17:38.027460, 5, pid=30811, effective(0, 0), real(0, 0)]
../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
release lock order 2 for /var/run/samba/serverid.tdb
[2016/12/14 08:17:38.027465, 10, pid=30811, effective(0, 0), real(0, 0)]
../lib/dbwrap/dbwrap.c:133(debug_lock_order)
lock order: 1:<none> 2:<none> 3:<none>
[2016/12/14 08:17:38.027477, 6, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2134(lp_file_list_changed)
lp_file_list_changed()
file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Dec
14 08:09:01 2016
[2016/12/14 08:17:38.027499, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util.c:168(show_msg)
[2016/12/14 08:17:38.027502, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util.c:178(show_msg)
size=61
smb_com=0x72
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=129
smb_flg2=49155
smb_tid=0
smb_pid=65534
smb_uid=0
smb_mid=0
smt_wct=13
smb_vwv[ 0]= 6 (0x6)
smb_vwv[ 1]= 1 (0x1)
smb_vwv[ 2]=16644 (0x4104)
smb_vwv[ 3]= 50 (0x32)
smb_vwv[ 4]= 1 (0x1)
smb_vwv[ 5]= 3 (0x3)
smb_vwv[ 6]=30811 (0x785B)
smb_vwv[ 7]= 0 (0x0)
smb_vwv[ 8]=16947 (0x4233)
smb_vwv[ 9]=18830 (0x498E)
smb_vwv[10]=65476 (0xFFC4)
smb_vwv[11]= 0 (0x0)
smb_vwv[12]= 0 (0x0)
smb_bcc=0
[2016/12/14 08:17:38.027543, 10, pid=30811, effective(0, 0), real(0, 0)]
../lib/util/util.c:559(dump_data)
[2016/12/14 08:17:38.027825, 10, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util_sock.c:369(read_smb_length_return_keepalive)
got smb length of 90
[2016/12/14 08:17:38.027855, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util.c:168(show_msg)
[2016/12/14 08:17:38.027859, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util.c:178(show_msg)
size=90
smb_com=0x73
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=24
smb_flg2=3
smb_tid=65535
smb_pid=30809
smb_uid=0
smb_mid=1
smt_wct=10
smb_vwv[ 0]= 255 (0xFF)
smb_vwv[ 1]= 0 (0x0)
smb_vwv[ 2]=65535 (0xFFFF)
smb_vwv[ 3]= 2 (0x2)
smb_vwv[ 4]= 1 (0x1)
smb_vwv[ 5]=30811 (0x785B)
smb_vwv[ 6]= 0 (0x0)
smb_vwv[ 7]= 6 (0x6)
smb_vwv[ 8]= 0 (0x0)
smb_vwv[ 9]= 0 (0x0)
smb_bcc=35
[2016/12/14 08:17:38.027896, 10, pid=30811, effective(0, 0), real(0, 0)]
../lib/util/util.c:559(dump_data)
[0000] 61 73 64 61 73 64 53 4D 42 54 45 53 54 00 57 4F asdasdSM
BTEST.WO
[0010] 52 4B 47 52 4F 55 50 00 55 6E 69 78 00 53 61 6D RKGROUP.
Unix.Sam
[0020] 62 61 00 ba.
[2016/12/14 08:17:38.027933, 5, pid=30811, effective(0, 0), real(0, 0)]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/14 08:17:38.027939, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/14 08:17:38.027971, 6, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2134(lp_file_list_changed)
lp_file_list_changed()
file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Wed Dec
14 08:09:01 2016
[2016/12/14 08:17:38.027987, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:491(make_auth_context_subsystem)
Making default auth method list for server role = 'standalone server',
encrypt passwords = yes
[2016/12/14 08:17:38.027992, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:497(make_auth_context_subsystem)
Making default auth method list for server role = 'standalone server',
encrypt passwords = no
[2016/12/14 08:17:38.028000, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend sam
[2016/12/14 08:17:38.028008, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'sam'
[2016/12/14 08:17:38.028013, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend sam_ignoredomain
[2016/12/14 08:17:38.028018, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'sam_ignoredomain'
[2016/12/14 08:17:38.028023, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend unix
[2016/12/14 08:17:38.028028, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'unix'
[2016/12/14 08:17:38.028033, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend winbind
[2016/12/14 08:17:38.028038, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'winbind'
[2016/12/14 08:17:38.028043, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend wbc
[2016/12/14 08:17:38.028048, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'wbc'
[2016/12/14 08:17:38.028053, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend trustdomain
[2016/12/14 08:17:38.028058, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'trustdomain'
[2016/12/14 08:17:38.028062, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend ntdomain
[2016/12/14 08:17:38.028070, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'ntdomain'
[2016/12/14 08:17:38.028075, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:48(smb_register_auth)
Attempting to register auth backend guest
[2016/12/14 08:17:38.028112, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:60(smb_register_auth)
Successfully added auth method 'guest'
[2016/12/14 08:17:38.028121, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match guest
[2016/12/14 08:17:38.028127, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method guest has a valid init
[2016/12/14 08:17:38.028132, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:378(load_auth_module)
load_auth_module: Attempting to find an auth method to match unix
[2016/12/14 08:17:38.028138, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:403(load_auth_module)
load_auth_module: auth method unix has a valid init
[2016/12/14 08:17:38.028147, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth_util.c:297(make_user_info_for_reply)
make_user_info_for_reply: User passwords not in encrypted format.
[2016/12/14 08:17:38.028200, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/user_info.c:62(make_user_info)
attempting to make a user_info for SMBTEST (SMBTEST)
[2016/12/14 08:17:38.028206, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/user_info.c:70(make_user_info)
making strings for SMBTEST's user_info struct
[2016/12/14 08:17:38.028215, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/user_info.c:108(make_user_info)
making blobs for SMBTEST's user_info struct
[2016/12/14 08:17:38.028221, 10, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/user_info.c:159(make_user_info)
made a user_info for SMBTEST (SMBTEST)
[2016/12/14 08:17:38.028228, 3, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:3636(lp_load_ex)
lp_load_ex: refreshing parameters
[2016/12/14 08:17:38.028234, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1212(free_param_opts)
Freeing parametrics:
[2016/12/14 08:17:38.028262, 3, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:527(init_globals)
Initialising global parameters
[2016/12/14 08:17:38.028324, 3, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2579(lp_do_section)
Processing section "[global]"
doing parameter workgroup = WORKGROUP
doing parameter dns proxy = no
doing parameter log file = /var/log/samba/log.%m
doing parameter max log size = 1000
doing parameter syslog = 0
doing parameter panic action = /usr/share/samba/panic-action %d
doing parameter debug level = 10 passdb:10
[2016/12/14 08:17:38.028383, 5, pid=30811, effective(0, 0), real(0, 0)]
../lib/util/debug.c:334(debug_dump_status)
INFO: Current debug levels:
all: 10
tdb: 10
printdrivers: 10
lanman: 10
smb: 10
rpc_parse: 10
rpc_srv: 10
rpc_cli: 10
passdb: 10
sam: 10
auth: 10
winbind: 10
vfs: 10
idmap: 10
quota: 10
acls: 10
locking: 10
msdfs: 10
dmapi: 10
registry: 10
scavenger: 10
dns: 10
ldb: 10
doing parameter server role = standalone server
doing parameter obey pam restrictions = yes
doing parameter unix password sync = yes
doing parameter passwd program = /usr/bin/passwd %u
doing parameter passwd chat = *Enter\snew\s*\spassword:* %n\n
*Retype\snew\s*\spassword:* %n\n *password\supdated\ssuccessfully* .
doing parameter pam password change = yes
doing parameter map to guest = bad user
doing parameter usershare allow guests = yes
doing parameter encrypt passwords = no
doing parameter lanman auth = yes
doing parameter ntlm auth = no
doing parameter server max protocol = LANMAN2
doing parameter client lanman auth = yes
doing parameter client plaintext auth = yes
doing parameter client ntlmv2 auth = no
[2016/12/14 08:17:38.028510, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2596(lp_do_section)
Processing section "[homes]"
doing parameter comment = Home Directories
doing parameter browseable = no
doing parameter read only = yes
doing parameter create mask = 0700
doing parameter directory mask = 0700
doing parameter valid users = %S
[2016/12/14 08:17:38.028566, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2596(lp_do_section)
Processing section "[printers]"
doing parameter comment = All Printers
doing parameter browseable = no
doing parameter path = /var/spool/samba
doing parameter printable = yes
doing parameter guest ok = no
doing parameter read only = yes
doing parameter create mask = 0700
[2016/12/14 08:17:38.028608, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2596(lp_do_section)
Processing section "[print$]"
doing parameter comment = Printer Drivers
doing parameter path = /var/lib/samba/printers
doing parameter browseable = yes
doing parameter read only = yes
doing parameter guest ok = no
[2016/12/14 08:17:38.028639, 2, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:2596(lp_do_section)
Processing section "[data]"
doing parameter path = /srv
doing parameter read only = no
[2016/12/14 08:17:38.028658, 4, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:3677(lp_load_ex)
pm_process() returned Yes
[2016/12/14 08:17:38.028669, 3, pid=30811, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1476(lp_add_ipc)
adding IPC service
[2016/12/14 08:17:38.028682, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth_util.c:117(make_user_info_map)
Mapping user []\[SMBTEST] from workstation [__1]
[2016/12/14 08:17:38.028690, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth_util.c:139(make_user_info_map)
Mapped domain from [] to [PIEC] for user [SMBTEST] from workstation [__1]
[2016/12/14 08:17:38.028695, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/user_info.c:62(make_user_info)
attempting to make a user_info for SMBTEST (SMBTEST)
[2016/12/14 08:17:38.028700, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/user_info.c:70(make_user_info)
making strings for SMBTEST's user_info struct
[2016/12/14 08:17:38.028706, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/user_info.c:108(make_user_info)
making blobs for SMBTEST's user_info struct
[2016/12/14 08:17:38.028711, 10, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/user_info.c:159(make_user_info)
made a user_info for SMBTEST (SMBTEST)
[2016/12/14 08:17:38.028716, 3, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:178(auth_check_ntlm_password)
check_ntlm_password: Checking password for unmapped user
[]\[SMBTEST]@[__1] with the new password interface
[2016/12/14 08:17:38.028722, 3, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:181(auth_check_ntlm_password)
check_ntlm_password: mapped user is: [PIEC]\[SMBTEST]@[__1]
[2016/12/14 08:17:38.028727, 10, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:190(auth_check_ntlm_password)
check_ntlm_password: auth_context challenge created by random
[2016/12/14 08:17:38.028732, 10, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:192(auth_check_ntlm_password)
challenge is:
[2016/12/14 08:17:38.028737, 5, pid=30811, effective(0, 0), real(0, 0)]
../lib/util/util.c:559(dump_data)
[0000] 77 7C DA 22 29 C0 63 B6 w|.").c.
[2016/12/14 08:17:38.028748, 10, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth_builtin.c:41(check_guest_security)
Check auth for: [SMBTEST]
[2016/12/14 08:17:38.028753, 10, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:233(auth_check_ntlm_password)
check_ntlm_password: guest had nothing to say
[2016/12/14 08:17:38.028758, 10, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth_unix.c:44(check_unix_security)
Check auth for: [SMBTEST]
[2016/12/14 08:17:38.028767, 5, pid=30811, effective(0, 0), real(0, 0)]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/14 08:17:38.028775, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/14 08:17:38.028784, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/username.c:181(Get_Pwnam_alloc)
Finding user SMBTEST
[2016/12/14 08:17:38.028789, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/username.c:120(Get_Pwnam_internals)
Trying _Get_Pwnam(), username as lowercase is smbtest
[2016/12/14 08:17:38.028826, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/username.c:159(Get_Pwnam_internals)
Get_Pwnam_internals did find user [SMBTEST]!
[2016/12/14 08:17:38.028835, 5, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:252(auth_check_ntlm_password)
check_ntlm_password: unix authentication for user [SMBTEST] FAILED with
error NT_STATUS_LOGON_FAILURE
[2016/12/14 08:17:38.028848, 2, pid=30811, effective(0, 0), real(0, 0),
class=auth] ../source3/auth/auth.c:315(auth_check_ntlm_password)
check_ntlm_password: Authentication for user [SMBTEST] -> [SMBTEST]
FAILED with error NT_STATUS_LOGON_FAILURE
[2016/12/14 08:17:38.028854, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/auth/auth_ntlmssp.c:188(auth3_check_password)
Checking NTLMSSP password for \SMBTEST failed: NT_STATUS_LOGON_FAILURE
[2016/12/14 08:17:38.028863, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util.c:168(show_msg)
[2016/12/14 08:17:38.028867, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util.c:178(show_msg)
size=35
smb_com=0x73
smb_rcls=1
smb_reh=0
smb_err=5
smb_flg=136
smb_flg2=3
smb_tid=65535
smb_pid=30809
smb_uid=0
smb_mid=1
smt_wct=0
smb_bcc=0
[2016/12/14 08:17:38.028887, 10, pid=30811, effective(0, 0), real(0, 0)]
../lib/util/util.c:559(dump_data)
[2016/12/14 08:17:38.028996, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/lib/util_sock.c:132(read_fd_with_timeout)
read_fd_with_timeout: blocking read. EOF from client.
[2016/12/14 08:17:38.029008, 5, pid=30811, effective(0, 0), real(0, 0)]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/14 08:17:38.029013, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/14 08:17:38.029022, 5, pid=30811, effective(0, 0), real(0, 0)]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/14 08:17:38.029027, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/14 08:17:38.029035, 5, pid=30811, effective(0, 0), real(0, 0)]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/14 08:17:38.029039, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2016/12/14 08:17:38.029048, 5, pid=30811, effective(0, 0), real(0, 0)]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2016/12/14 08:17:38.029053, 5, pid=30811, effective(0, 0), real(0, 0)]
../source3/auth/token_util.c:639(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
regards,
Marcin
More information about the samba
mailing list