[Samba] samba bad password count reset between logins (not loaded from login_cache.tdb)
Daryl Anthony Chouinard
dachouinard at gentec-eo.com
Fri Oct 6 15:54:39 UTC 2017
I found out the answer to why the bad password count was failing by
following the stack trace
If anyone has the same problem, this was caused by my access rights being
too restrictive.
source/passdb/Init_sam_from_ldap.c:1064 => There is a "goto fn_exit;" in
case ldapsam_get_entry_timestamp() fails before the cache is read via
login_cache_read. This function will fail if it cannot retrieve the
modifyTimestamp attribute of the user entry
At log level 10, the relevant log line appears:
[...] ../source3/lib/smbldap.c:90(smbldap_talloc_single_attribute)
Attribute modifyTimestamp does not exist
The samba user needs read access to the modifyTimestamp attributes of all
the users
In the hopes this will be useful to someone,
Daryl Anthony Chouinard
-----Message d'origine-----
De : Daryl Anthony Chouinard [mailto:dachouinard at gentec-eo.com]
Envoyé : 20 septembre 2017 11:46
À : 'samba at lists.samba.org' <samba at lists.samba.org>
Objet : samba bad password count reset between logins (not loaded from
login_cache.tdb)
I recently migrated our samba PDC to an LDAP backend on a test machine.
Testing my account policies, I found out that the password lockout did not
work.
When authentication fail, samba seems to call init_ldap_from_sam asking to
update the bad password count.
When I set the lockout threshold to 1, the account is locked after a failed
attempt and the badPasswordCount attribute is updated correctly (e.g. set to
1), as expected from the init_ldap_from_sam definition.
When the threshold>1, the cache seems to be updated via login_cache_write,
but the next time I try to login, the badPasswordCount is reset to 0. I
suspect the cache is ignored for some reason?
Heres the relevant part of the logs (/var/log/samba/log.smbd):
#
## with policy=4 (same every time a user fails a password, even if he failed
10 times previous) #
[2017/09/19 13:27:17.589773, 3]
../source3/passdb/pdb_ldap.c:1376(init_ldap_from_sam)
updating bad password fields, policy=4, count=1, time=1505842037
[2017/09/19 13:27:17.589777, 7]
../source3/passdb/pdb_ldap.c:1416(init_ldap_from_sam)
Updating bad password count and time in login cache
[2017/09/19 13:27:17.589783, 5]
../source3/passdb/login_cache.c:47(login_cache_init)
Opening cache file at /var/lib/samba/login_cache.tdb
[2017/09/19 13:27:17.589818, 4]
../source3/passdb/pdb_ldap.c:1904(ldapsam_update_sam_account)
ldapsam_update_sam_account: mods is empty: nothing to update for user:
dachouinard
[2017/09/19 13:27:17.589827, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
#
## with policy = 1 (account is locked and badPasswordCount=1 after #
[2017/09/19 13:22:43.480284, 3]
../source3/passdb/pdb_ldap.c:1376(init_ldap_from_sam)
updating bad password fields, policy=1, count=1, time=1505841763
[2017/09/19 13:22:43.480297, 5]
../source3/passdb/login_cache.c:47(login_cache_init)
Opening cache file at /var/lib/samba/login_cache.tdb
[2017/09/19 13:22:43.480334, 5]
../source3/lib/smbldap.c:1435(smbldap_modify)
smbldap_modify: dn => [uid=dachouinard,ou=people,dc=basedc]
[2017/09/19 13:22:43.524433, 2]
../source3/passdb/pdb_ldap.c:1935(ldapsam_update_sam_account)
[2017/09/19 14:29:47.435922, 6]
../source3/param/loadparm.c:2307(lp_file_list_changed)
lp_file_list_changed()
file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Sep 19
14:08:03 2017
#
## full login log:
#
[2017/09/19 14:38:25.611744, 4]
../source3/param/loadparm.c:3864(lp_load_ex)
pm_process() returned Yes
[2017/09/19 14:38:25.611760, 3]
../source3/param/loadparm.c:1592(lp_add_ipc)
adding IPC service
[2017/09/19 14:38:25.611810, 5]
../source3/auth/auth_util.c:123(make_user_info_map)
Mapping user [LOCALDOMAIN]\[dachouinard] from workstation [GE1]
[2017/09/19 14:38:25.611824, 5]
../source3/auth/auth_util.c:144(make_user_info_map)
Mapped domain from [LOCALDOMAIN] to [GE1] for user [dachouinard] from
workstation [GE1]
[2017/09/19 14:38:25.611830, 5]
../source3/auth/user_info.c:62(make_user_info)
attempting to make a user_info for dachouinard (dachouinard)
[2017/09/19 14:38:25.611835, 5]
../source3/auth/user_info.c:70(make_user_info)
making strings for dachouinard's user_info struct
[2017/09/19 14:38:25.611840, 5]
../source3/auth/user_info.c:108(make_user_info)
making blobs for dachouinard's user_info struct
[2017/09/19 14:38:25.611845, 3]
../source3/auth/auth.c:178(auth_check_ntlm_password)
check_ntlm_password: Checking password for unmapped user
[LOCALDOMAIN]\[dachouinard]@[GE1] with the new password interface
[2017/09/19 14:38:25.611850, 3]
../source3/auth/auth.c:181(auth_check_ntlm_password)
check_ntlm_password: mapped user is: [GE1]\[dachouinard]@[GE1]
[2017/09/19 14:38:25.611854, 5] ../lib/util/util.c:555(dump_data)
[0000] 44 F5 5E 65 01 EE 91 2D D.^e...-
[2017/09/19 14:38:25.611873, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.611878, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2017/09/19 14:38:25.611882, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.611887, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.611891, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.611951, 5]
../source3/lib/smbldap.c:1249(smbldap_search_ext)
smbldap_search_ext: base => [dc=basedc], filter =>
[(&(uid=dachouinard)(objectclass=sambaSamAccount))], scope => [2]
[2017/09/19 14:38:25.611969, 5]
../source3/lib/smbldap.c:1114(smbldap_close)
The connection to the LDAP server was closed
[2017/09/19 14:38:25.612023, 2]
../source3/lib/smbldap.c:794(smbldap_open_connection)
smbldap_open_connection: connection opened
[2017/09/19 14:38:25.615980, 3]
../source3/lib/smbldap.c:1013(smbldap_connect_system)
ldap_connect_system: successful connection to the LDAP server
[2017/09/19 14:38:25.616004, 4] ../source3/lib/smbldap.c:1092(smbldap_open)
The LDAP server is successfully connected
[2017/09/19 14:38:25.695848, 2]
../source3/passdb/pdb_ldap.c:524(init_sam_from_ldap)
init_sam_from_ldap: Entry found for user: dachouinard
[2017/09/19 14:38:25.695896, 4]
../source3/lib/substitute.c:435(automount_server)
Home server: ge1
[2017/09/19 14:38:25.695912, 4]
../source3/lib/substitute.c:435(automount_server)
Home server: ge1
[2017/09/19 14:38:25.695930, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.695936, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 2
[2017/09/19 14:38:25.695940, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.695945, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.695949, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.731783, 5]
../source3/lib/smbldap.c:1249(smbldap_search_ext)
smbldap_search_ext: base => [sambaDomainName=ge1,ou=samba,dc=basedc],
filter => [(objectClass=sambaDomain)], scope => [0]
[2017/09/19 14:38:25.732256, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.732325, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.732332, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 2
[2017/09/19 14:38:25.732336, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.732341, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.732346, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.732358, 5]
../source3/lib/smbldap.c:1249(smbldap_search_ext)
smbldap_search_ext: base => [ou=people,dc=basedc], filter =>
[(&(objectClass=sambaSamAccount)(|(sambaSid=S-1-0-0-3001)))], scope => [2]
[2017/09/19 14:38:25.756370, 5]
../source3/lib/smbldap.c:1249(smbldap_search_ext)
smbldap_search_ext: base => [dc=basedc], filter =>
[(&(objectClass=sambaGroupMapping)(|(sambaSid=S-1-0-0-3001)))], scope => [2]
[2017/09/19 14:38:25.783357, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783411, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.783418, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783423, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.783427, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.783431, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.783443, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783461, 4]
../source3/lib/substitute.c:435(automount_server)
Home server: ge1
[2017/09/19 14:38:25.783471, 4]
../source3/lib/substitute.c:435(automount_server)
Home server: ge1
[2017/09/19 14:38:25.783477, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.783481, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783485, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.783488, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.783491, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.783500, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783513, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2017/09/19 14:38:25.783521, 4]
../libcli/auth/ntlm_check.c:358(ntlm_password_check)
ntlm_password_check: Checking NTLMv2 password with domain [LOCALDOMAIN]
[2017/09/19 14:38:25.783538, 4]
../libcli/auth/ntlm_check.c:372(ntlm_password_check)
ntlm_password_check: Checking NTLMv2 password with uppercased version of
domain [LOCALDOMAIN]
[2017/09/19 14:38:25.783545, 4]
../libcli/auth/ntlm_check.c:385(ntlm_password_check)
ntlm_password_check: Checking NTLMv2 password without a domain
[2017/09/19 14:38:25.783551, 3]
../libcli/auth/ntlm_check.c:397(ntlm_password_check)
ntlm_password_check: NTLMv2 password check failed
[2017/09/19 14:38:25.783555, 3]
../libcli/auth/ntlm_check.c:442(ntlm_password_check)
ntlm_password_check: Lanman passwords NOT PERMITTED for user dachouinard
[2017/09/19 14:38:25.783558, 4]
../libcli/auth/ntlm_check.c:479(ntlm_password_check)
ntlm_password_check: Checking LMv2 password with domain LOCALDOMAIN
[2017/09/19 14:38:25.783564, 4]
../libcli/auth/ntlm_check.c:508(ntlm_password_check)
ntlm_password_check: Checking LMv2 password with upper-cased version of
domain LOCALDOMAIN
[2017/09/19 14:38:25.783570, 4]
../libcli/auth/ntlm_check.c:536(ntlm_password_check)
ntlm_password_check: Checking LMv2 password without a domain
[2017/09/19 14:38:25.783576, 4]
../libcli/auth/ntlm_check.c:567(ntlm_password_check)
ntlm_password_check: Checking NT MD4 password in LM field
[2017/09/19 14:38:25.783579, 3]
../libcli/auth/ntlm_check.c:588(ntlm_password_check)
ntlm_password_check: LM password and LMv2 failed for user dachouinard, and
NT MD4 password in LM field not permitted
[2017/09/19 14:38:25.783586, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783590, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2017/09/19 14:38:25.783594, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783597, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.783601, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.783609, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2017/09/19 14:38:25.783613, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783617, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2017/09/19 14:38:25.783620, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783623, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.783629, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.783634, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.783638, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 2
[2017/09/19 14:38:25.783641, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.783644, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.783648, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.783664, 5]
../source3/lib/smbldap.c:1249(smbldap_search_ext)
smbldap_search_ext: base => [sambaDomainName=ge1,ou=samba,dc=basedc],
filter => [(objectClass=sambaDomain)], scope => [0]
[2017/09/19 14:38:25.809734, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.809752, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2017/09/19 14:38:25.809837, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.809844, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2017/09/19 14:38:25.809848, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.809853, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.809856, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.809872, 4]
../source3/passdb/pdb_ldap.c:1890(ldapsam_update_sam_account)
ldapsam_update_sam_account: user dachouinard to be modified has dn:
uid=dachouinard,ou=people,dc=basedc
[2017/09/19 14:38:25.809880, 2]
../source3/passdb/pdb_ldap.c:1138(init_ldap_from_sam)
init_ldap_from_sam: Setting entry for user: dachouinard
[2017/09/19 14:38:25.809888, 4] ../source3/smbd/sec_ctx.c:217(push_sec_ctx)
push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.809892, 4] ../source3/smbd/uid.c:491(push_conn_ctx)
push_conn_ctx(0) : conn_ctx_stack_ndx = 2
[2017/09/19 14:38:25.809895, 4]
../source3/smbd/sec_ctx.c:321(set_sec_ctx_internal)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 3
[2017/09/19 14:38:25.809898, 5]
../libcli/security/security_token.c:53(security_token_debug)
Security token: (NULL)
[2017/09/19 14:38:25.809902, 5]
../source3/auth/token_util.c:640(debug_unix_user_token)
UNIX token of user 0
Primary group is 0 and contains 0 supplementary groups
[2017/09/19 14:38:25.809913, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 2
[2017/09/19 14:38:25.809917, 3]
../source3/passdb/pdb_ldap.c:1376(init_ldap_from_sam)
updating bad password fields, policy=4, count=1, time=1505846305
[2017/09/19 14:38:25.809921, 7]
../source3/passdb/pdb_ldap.c:1416(init_ldap_from_sam)
Updating bad password count and time in login cache #
<------------------------------------------------------------------------
(only if lockout threshold > 1)
[2017/09/19 14:38:25.809928, 5]
../source3/passdb/login_cache.c:47(login_cache_init)
Opening cache file at /var/lib/samba/login_cache.tdb
[2017/09/19 14:38:25.809964, 4]
../source3/passdb/pdb_ldap.c:1904(ldapsam_update_sam_account)
ldapsam_update_sam_account: mods is empty: nothing to update for user:
dachouinard
[2017/09/19 14:38:25.809973, 4] ../source3/smbd/sec_ctx.c:439(pop_sec_ctx)
pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
#
## my smb.conf:
#
[global]
workgroup = localdomain
netbios name = GE1
server string = GE1
#
security = user
#
passdb backend = ldapsam:"ldap://localhost"
ldap suffix = dc=basedc
ldap user suffix = ou=people
ldap group suffix = ou=groups
ldap admin dn = "cn=samba, dc=basedc"
ldap ssl = Off
# speedup, ignore NSS
ldapsam:trusted = yes
########
domain master = yes
local master = yes
preferred master = yes
##
log level = 7
[homes]
comment = Home
valid users = %S
read only = No
create mask = 0770
browseable = No
##
Am I doing something wrong, is there a way to keep the bad password count in
between logins? The login cache (/var/lib/samba/login_cache.tdb) seems to be
ignored.
tdbtool
> open login_cache.tdb
> keys
key 12 bytes: dachouinard
> dump
[000] 76 64 C1 59 10 00 01 00 76 64 C1 59 vd.Y... vd.Y
I am on CentOS 7.4 running samba 4.6.2
I tested and have same issue with the latest git (4.8.0pre1-GIT-ee4418e)
Hopefully this is the right place to inquire about this.
Your assistance is very appreciated
More information about the samba
mailing list