[Samba] samba / winbind user authentication problem

Johannes Schmid smbml at rotfl.org
Sun Dec 2 14:46:58 MST 2012 

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
3200000
3200001

# wbinfo --gid-info 2000
unixuser:x:2000:

# wbinfo --gid-info 3200000
BUILTIN\administrators:x:3200000:

# wbinfo --gid-info 3200001
BUILTIN\users:x:3200001:

# 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 john at MITXP.COM
Password for john at MITXP.COM: ********
# klist
Default principal: john at MITXP.COM

Valid starting    Expires           Service principal
01/12/2012 21:50  02/12/2012 07:50  krbtgt/MITXP.COM at 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 (0x00000388)
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 john at MITXP.COM from ipv4:192.168.35.32:34470 for 
krbtgt/MITXP.COM at 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)
   Kerberos: Looking for PK-INIT(ietf) pa-data -- john at MITXP.COM
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: Looking for PK-INIT(win2k) pa-data -- john at MITXP.COM
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: Looking for ENC-TS pa-data -- john at MITXP.COM
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: Need to use PA-ENC-TIMESTAMP/PA-PK-AS-REQ
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: AS-REQ john at MITXP.COM from ipv4:192.168.35.32:46650 for 
krbtgt/MITXP.COM at 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: ENC-TS, REQ-ENC-PA-REP
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: Looking for PK-INIT(ietf) pa-data -- john at MITXP.COM
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: Looking for PK-INIT(win2k) pa-data -- john at MITXP.COM
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: Looking for ENC-TS pa-data -- john at MITXP.COM
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: ENC-TS Pre-authentication succeeded -- john at MITXP.COM using 
arcfour-hmac-md5
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: ENC-TS pre-authentication succeeded -- john at MITXP.COM
[2012/12/01 21:36:34,  4] ../source4/auth/sam.c:170(authsam_account_ok)
   authsam_account_ok: Checking SMB password for user john at MITXP.COM
[2012/12/01 21:36:34,  5] ../source4/auth/sam.c:105(logon_hours_ok)
   logon_hours_ok: No hours restrictions for user john at 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: AS-REQ authtime: 2012-12-01T21:36:34 starttime: unset 
endtime: 2012-12-02T07:36:34 renew till: 2012-12-08T21:36:34
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: Client supported enctypes: arcfour-hmac-md5, using 
arcfour-hmac-md5/arcfour-hmac-md5
[2012/12/01 21:36:34,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: Requested flags: renewable, forwardable
[2012/12/01 21:36:35,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: TGS-REQ john at MITXP.COM from ipv4:192.168.35.32:57496 for 
GIT$@MITXP.COM [canonicalize, renewable, forwardable]
[2012/12/01 21:36:35,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=mitxp,DC=com NULL -> 1
[2012/12/01 21:36:35,  3] 
../source4/auth/kerberos/krb5_init_context.c:69(smb_krb5_debug_wrapper)
   Kerberos: TGS-REQ authtime: 2012-12-01T21:36:34 starttime: 
2012-12-01T21:36:35 endtime: 2012-12-02T07:36:34 renew till: 
2012-12-08T21:36:34
------------------------------

Finally, some config files:

/etc/nsswitch.conf (excerpt):
------------------------------
passwd:         compat winbind
group:          compat winbind
------------------------------

/etc/pam.d/common-auth: (excerpt):
------------------------------
auth      [success=1 default=ignore] pam_winbind.so krb5_auth 
krb5_ccache_type=FILE cached_login try_first_pass
------------------------------

/etc/pam.d/common-password (excerpt):
------------------------------
password  [success=1 default=ignore] pam_winbind.so use_authtok 
try_first_pass
------------------------------

/etc/pam.d/common-session (excerpt):
------------------------------
session   optional  pam_winbind.so
------------------------------

/etc/krb5.conf (on all systems):
------------------------------
[libdefaults]
         default_realm = MITXP.COM
         dns_lookup_realm = false
         dns_lookup_kdc = true
         kdc_timesync = 1
         ccache_type = 4
         forwardable = true
         proxiable = true

[login]
         krb4_convert = true
         krb4_get_tickets = false
------------------------------


Unfortunately, I don't know what else to do. I also tried to install a 
new machine to authenticate to the samba4 AD, but even the complete 
fresh install didn't work (which tells me that the problem most probably 
can be found on domain controller side).
I really have no idea where this NT_STATUS_LOGON_FAILURE is coming from...


Looking forward to your suggestions.

-- 
Best regards,
   -Johannes.

More information about the samba mailing list