Marcin Owsiany
2016-Dec-14 07:43 UTC
[Samba] Cannot get plaintext+pam auth to work on 4.2.10
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