Hi,
I have a problem with samba / winbind PAM authentication. Domain
controller is samba4, machines users log on to via PAM are samba 3.6
(all of them ubuntu 12.04 LTS). The whole user authentication was
working already, but after a reboot it somehow broke. Additional reboots
don't help.
The funny thing is that all logs look quite OK to me (except for the
single line saying NT_STATUS_LOGON_FAILURE).
Also wbinfo only gives me positive feedback (I try to log on as user
"john" to the domain "MITXP", but it won't work with any user in the AD,
"john" is just an example):
# wbinfo --user-info john
john:*:1001:2000::/home/john:/bin/bash
# wbinfo --user-groups john
2000
320
321
# wbinfo --gid-info 2000
unixuser:x:2000:
# wbinfo --gid-info 320
BUILTIN\administrators:x:320:
# wbinfo --gid-info 321
BUILTIN\users:x:321:
# wbinfo --pam-logon john
Enter john's password:
plaintext password authentication succeeded
# wbinfo --authenticate john
Enter john's password:
plaintext password authentication succeeded
Enter john's password:
challenge/response password authentication succeeded
# kinit j...@mitxp.com
Password for j...@mitxp.com:
# klist
Default principal: j...@mitxp.com
Valid startingExpires Service principal
01/12/2012 21:50 02/12/2012 07:50 krbtgt/mitxp@mitxp.com
renew until 02/12/2012 21:50
# ldbsearch -H /var/lib/samba/private/sam.ldb.d/DC\=MITXP\,DC\=COM.ldb
-b 'dc=MITXP,dc=COM' '(sAMAccountType=805306368)' --show-binary
lists all users of the AD, including user "john"
Here's some local machine debugging output when a user tries to log on
via PAM. First of all logging done by pam_winbindd to auth/syslog:
--
pam_winbind(sshd:auth): getting password (0x0388)
pam_winbind(sshd:auth): pam_get_item returned a password
pam_winbind(sshd:auth): request wbcLogonUser failed: WBC_ERR_AUTH_ERROR,
PAM error: PAM_AUTH_ERR (7), NTSTATUS: NT_STATUS_LOGON_FAILURE, Error
message was: Logon failure
pam_winbind(sshd:auth): user 'john' denied access (incorrect password or
invalid membership)
--
Now local machine logging to samba log file:
--
[2012/12/01 21:33:35.285465, 6] winbindd/winbindd.c:792(new_connection)
accepted socket 32
[2012/12/01 21:33:35.285543, 10] winbindd/winbindd.c:615(process_request)
process_request: Handling async request 2303:PAM_AUTH
[2012/12/01 21:33:35.285596, 3]
winbindd/winbindd_pam_auth.c:54(winbindd_pam_auth_send)
[ 2303]: pam auth john
[2012/12/01 21:33:35.342560, 10] winbindd/winbindd.c:677(wb_request_done)
wb_request_done[2303:PAM_AUTH]: NT_STATUS_LOGON_FAILURE
[2012/12/01 21:33:35.342793, 10]
winbindd/winbindd.c:738(winbind_client_response_written)
winbind_client_response_written[2303:PAM_AUTH]: delivered response to
client
--
Now logging of samba4 on domain controller:
--
[2012/12/01 21:36:34, 5]
../source4/ldap_server/ldap_backend.c:572(ldapsrv_SearchRequest)
ldb_request SUB dn=dc=MITXP,dc=COM
filter=(&(|(sAMAccountType=805306368)(sAMAccountType=805306369)(sAMAccountType=805306370)(sAMAccountType=268435456)(sAMAccountType=536870912))(|(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\81i\7FPuFDc\BE-\EF\26S\04\00\00)))
[2012/12/01 21:36:34, 5]
../source4/ldap_server/ldap_backend.c:572(ldapsrv_SearchRequest)
ldb_request SUB dn=dc=MITXP,dc=COM
filter=(&(|(sAMAccountType=805306368)(sAMAccountType=805306369)(sAMAccountType=805306370)(sAMAccountType=268435456)(sAMAccountType=536870912))(|(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\81i\7FPuFDc\BE-\EF\26Q\04\00\00)))
[2012/12/01 21:36:34, 5]
../source4/ldap_server/ldap_backend.c:572(ldapsrv_SearchRequest)
ldb_request SUB dn=dc=MITXP,dc=COM
filter=(&(|(sAMAccountType=805306368)(sAMAccountType=805306369)(sAMAccountType=805306370)(sAMAccountType=268435456)(sAMAccountType=536870912))(|(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\81i\7FPuFDc\BE-\EF\26S\04\00\00)))
[2012/12/01 21:36:34, 5]
../source4/ldap_server/ldap_backend.c:572(ldapsrv_SearchRequest)
ldb_request SUB dn=dc=MITXP,dc=COM
filter=(&(|(sAMAccountType=805306368)(sAMAccountType=805306369)(sAMAccountType=805306370)(sAMAccountType=268435456)(sAMAccountType=536870912))(|(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\81i\7FPuFDc\BE-\EF\26Q\04\00\00)))
[2012/12/01 21:36:34, 3]
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
Kerberos: AS-REQ j...@mitxp.com from ipv4:192.168.35.32:34470 for
krbtgt/mitxp@mitxp.com
[2012/12/01 21:36:34, 6] ../lib/util/util_ldb.c:60(gendb_search_v)
gendb_search_v: DC=mitxp,DC=com NULL -> 1
[2012/12/01 21:36:34, 3]
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
Kerberos: Client sent patypes: REQ-ENC-PA-REP
[2012/12/01 21:36:34, 3]
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
Kerb