[Samba] sometimes users fails to login

[Andrea Cucciarre']

The OS is OmniOS, the DC is Windows Server (not sure about the release), 
and below the smb.conf.
I have also noted that they have more trusted domains, but since they 
configured ad idmap only for one domain, then all the other domains use 
tdb idmap

[global]
client ldap sasl wrapping = plain
dedicated keytab file = /etc/krb5.keytab
disable spoolss = yes
host msdfs = no
idmap config * : backend = tdb
idmap config * : range = 30000-40000
idmap config * : schema_mode = rfc2307
idmap config BITINTRA : backend = ad
idmap config BITINTRA : range = 10000-3001000
idmap config BITINTRA : schema_mode = rfc2307
kerberos method = secrets and keytab
load printers = no
local master = no
log file = /opt/samba/log/%m.log
log level = 10
map acl inherit = Yes
map to guest = bad user
os level = 3
preferred master = no
realm = bitintra.de
security = ads
server string = Data %h
store dos attributes = Yes
vfs objects = zfsacl
winbind enum groups = yes
winbind enum users = yes
winbind expand groups = 4
winbind normalize names = Yes
winbind nss info = rfc2307
winbind refresh tickets = Yes
winbind use default domain = no
workgroup = BITINTRA

Thanks
Andrea




Il 3/12/2019 11:48 AM, Rowland Penny via samba ha scritto:
> On Tue, 12 Mar 2019 11:32:46 +0100
> Andrea Cucciarre' via samba <samba at lists.samba.org> wrote:
>
>> Hello,
>>
>> I have Samba 4.6 as AD domain member and sometime the users fails to
>> login, the issue disappear after some minutes.
>> I have enabled log leve 10 and I can see the following errors:
>>
>> 2019/03/12 09:20:32.280799,  5, pid=15466, effective(0, 0), real(0,
>> 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc)
>>     Finding user BITINTRA\U002489
>> [2019/03/12 09:20:32.281111,  5, pid=15466, effective(0, 0), real(0,
>> 0)] ../source3/lib/username.c:128(Get_Pwnam_internals)
>>     Trying _Get_Pwnam(), username as given is BITINTRA\U002489
>> [2019/03/12 09:20:32.281222,  5, pid=15466, effective(0, 0), real(0,
>> 0)] ../source3/lib/username.c:153(Get_Pwnam_internals)
>>     Get_Pwnam_internals didn't find user [BITINTRA\U002489]!
>> [2019/03/12 09:20:32.282015,  3, pid=15466, effective(0, 0), real(0,
>> 0),
>> class=auth] ../source3/auth/user_krb5.c:164(get_user_from_kerberos_info)
>> get_user_from_kerberos_info: Username BITINTRA\U002489 is invalid on
>> this system [2019/03/12 09:20:32.282043,  3, pid=15466, effective(0,
>> 0), real(0,
>> 0)] ../source3/auth/auth_generic.c:145(auth3_generate_session_info_pac)
>> auth3_generate_session_info_pac: Failed to map kerberos principal to
>> system user (NT_STATUS_LOGON_FAILURE) [2019/03/12 09:20:32.282196,
>> 3, pid=15466, effective(0, 0), real(0,
>> 0)] ../source3/smbd/smb2_server.c:3097(smbd_smb2_request_error_ex)
>> smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1]
>> status[NT_STATUS_ACCESS_DENIED] ||
>> at ../source3/smbd/smb2_sesssetup.c:134
>>
>> my understanding of the code is that getpwnam fails, which is
>> supposed to query winbindd.
>> In the log file log.wb-BITINTRA I can see the following error:
>>
>> [2019/03/12 09:20:24.540456, 10, pid=15439, effective(0, 0), real(0,
>> 0),
>> class=winbind] ../source3/winbindd/winbindd_cm.c:1014(cm_prepare_connection)
>> cm_prepare_connection: connecting to DC WG101SC0002.BITIntra.de for
>> domain BITINTRA [2019/03/12 09:21:04.540067,  5, pid=15439,
>> effective(0, 0), real(0,
>> 0)] ../lib/tdb_wrap/tdb_wrap.c:64(tdb_wrap_log)
>> tdb(/opt/samba/var/lock/mutex.tdb): tdb_brlock failed (fd=22) at
>> offset 592 rw_type=2 flags=1 len=1 [2019/03/12 09:21:04.540189,  1,
>> pid=15439, effective(0, 0), real(0,
>> 0)] ../lib/tdb_wrap/tdb_wrap.c:64(tdb_wrap_log)
>> tdb(/opt/samba/var/lock/mutex.tdb): tdb_lock failed on list 106
>> ltype=2 (Interrupted system call) [2019/03/12 09:21:04.540219,  0,
>> pid=15439, effective(0, 0), real(0,
>> 0)] ../source3/lib/util_tdb.c:497(tdb_chainlock_with_timeout_internal)
>> tdb_chainlock_with_timeout_internal: alarm (40) timed out for key
>> WG101SC0002.BITIntra.de in tdb /opt/samba/var/lock/mutex.tdb
>> [2019/03/12 09:21:04.540384,  1, pid=15439, effective(0, 0), real(0,
>> 0)] ../source3/lib/server_mutex.c:97(grab_named_mutex) Could not get
>> the lock for WG101SC0002.BITIntra.de [2019/03/12 09:21:04.540508,  0,
>> pid=15439, effective(0, 0), real(0, 0),
>> class=winbind] ../source3/winbindd/winbindd_cm.c:1023(cm_prepare_connection)
>> cm_prepare_connection: mutex grab failed for WG101SC0002.BITIntra.de
>> [2019/03/12 09:21:04.540667,  1, pid=15439, effective(0, 0), real(0,
>> 0),
>> class=winbind] ../source3/winbindd/winbindd_cm.c:1320(cm_prepare_connection)
>> Failed to prepare SMB connection to WG101SC0002.BITIntra.de:
>> NT_STATUS_POSSIBLE_DEADLOCK
>>
>> my understanding is that it was hanging locking an offset in the file
>> /opt/samba/var/lock/mutex.tdb, so when the timeout elapsed the
>> process was interrupted (I guess the offset was that of the mutex for
>> WG101SC0002.BITIntra.de)
>> Could it be a corrupted mutex.tdb file? A slow responding DC?
>> Any other suggestion?
> Can you please post your smb.conf.
> What OS ?
> What is your AD DC ?
>
> Rowland
>
>