Daryl Anthony Chouinard
2017-Oct-06 15:54 UTC
[Samba] samba bad password count reset between logins (not loaded from login_cache.tdb)
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 > keyskey 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
Andrew Bartlett
2017-Oct-14 06:15 UTC
[Samba] samba bad password count reset between logins (not loaded from login_cache.tdb)
On Fri, 2017-10-06 at 11:54 -0400, Daryl Anthony Chouinard via samba wrote:> 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 ChouinardThanks for getting back to us. I'm very glad to hear this isn't an issue for most users, as sadly we don't have an automated testsuite for the NT4/classic LDAP backend. Thanks, Andrew Bartlett -- Andrew Bartlett http://samba.org/~abartlet/ Authentication Developer, Samba Team http://samba.org Samba Developer, Catalyst IT http://catalyst.net.nz/services/samba
Reasonably Related Threads
- samba bad password count reset between logins (not loaded from login_cache.tdb)
- samba bad password count reset between logins (not loaded from login_cache.tdb)
- samba bad password count reset between logins (not loaded from login_cache.tdb)
- Account lockout - Bad password count
- Password trouble with LDAP (eDirectory)