On Tue, 24 Mar 2015, Bobby Prins wrote:
----- Oorspronkelijk bericht -----
Van: "Alexander Bokovoy" <aboko...@redhat.com>
Aan: "Bobby Prins" <bobby.pr...@proxy.nl>
Cc: d...@redhat.com, freeipa-users@redhat.com
Verzonden: Dinsdag 24 maart 2015 15:13:38
Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
ipa_server_mode

On Tue, 24 Mar 2015, Bobby Prins wrote:
----- Oorspronkelijk bericht -----
Van: "Alexander Bokovoy" <aboko...@redhat.com>
Aan: "Bobby Prins" <bobby.pr...@proxy.nl>
Cc: d...@redhat.com, freeipa-users@redhat.com
Verzonden: Maandag 23 maart 2015 16:44:47
Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
ipa_server_mode

...

Can you show relevant parts of /var/log/dirsrv/slapd-EXAMPLE-CORP/access
and sssd logs from IPA master (with debug_level = 10) at least in
[domain], [nss], and [pam] sections.

You need to filter dirsrv logs by connection coming from AIX IP address
and then by conn=<number> where number is the same number as the one
with IP address line.

When authenticating, AIX would talk to IPA LDAP server to compat tree
and slapi-nis plugin which serves compat tree would do PAM
authentication as service system-auth where SSSD on IPA master will do
the actual authentication work.

--
/ Alexander Bokovoy

Here you can see the DS connection from AIX:
[24/Mar/2015:12:53:19 +0100] conn=96 fd=110 slot=110 connection from 
192.168.140.107 to 192.168.140.133
[24/Mar/2015:12:53:20 +0100] conn=96 op=0 BIND 
dn="uid=bpr...@example.corp,cn=users,cn=compat,dc=unix,dc=example,dc=corp" 
method=128 version=3
[24/Mar/2015:12:53:43 +0100] conn=96 op=0 RESULT err=0 tag=97 nentries=0 etime=24 
dn="uid=bpr...@example.corp,cn=users,cn=compat,dc=unix,dc=example,dc=corp"
[24/Mar/2015:12:53:43 +0100] conn=96 op=-1 fd=110 closed - B1

As you can see it also takes quite some time to process the login.
Could that be a problem?
24 seconds sounds like bprins2example.com is a member of few groups with
big amount of members. On the other hand, BIND operation result is 0
(success) and it doesn't look like AIX dropped the connection, at least
there is no ABANDON within the context of this connection so AIX did not
cancel the request by itself.

How long does it take on AIX side to report the inability to login? Is
this time longer or shorter the one reported in etime= value on RESULT
line above?

The SSSD log files are a bit large with debug_level set to 10 and it
will take me some time to strip all customer data from it. Any log
events in particular you would like to see?
https://fedorahosted.org/sssd/wiki/Troubleshooting has explanation for
some times of issues you might find in the SSSD logs. I'd be interested
in "Common AD provider issues", "Troubleshooting authentication,
password change and access control".

--
/ Alexander Bokovoy

The inability to login is reported in about the same time as the number of 
seconds you would find in the etime= field of the RESULT line.

I checked the "Common AD provider issues" and "Troubleshooting authentication, 
password change and access control" sections on the SSSD Troubleshooting page. None of the 
issues reported there seem to be applicable in my situation.

PAM logging on AIX:
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: pam_start(login 
bpr...@example.corp)
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: pam_set_item(1)
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: pam_set_item(2)
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: pam_set_item(5)
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: pam_set_item(3)
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: pam_set_item(4)
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: pam_set_item(8)
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: 
pam_authenticate()
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: load_modules: 
/usr/lib/security/pam_aix
Mar 24 16:23:10 tst01 auth|security:debug /usr/sbin/getty PAM: load_function: 
successful load of pam_sm_authenticate
Mar 24 16:23:22 tst01 auth|security:debug /usr/sbin/getty PAM: pam_set_item(6)
Mar 24 16:23:37 tst01 auth|security:debug /usr/sbin/getty PAM: 
pam_authenticate: error Authentication failed
Mar 24 16:23:37 tst01 auth|security:debug /usr/sbin/getty PAM: pam_set_item(6)
Mar 24 16:23:37 tst01 auth|security:debug /usr/sbin/getty PAM: pam_acct_mgmt()
Mar 24 16:23:37 tst01 auth|security:debug /usr/sbin/getty PAM: load_modules: 
/usr/lib/security/pam_aix
Mar 24 16:23:37 tst01 auth|security:debug /usr/sbin/getty PAM: load_function: 
successful load of pam_sm_acct_mgmt
Mar 24 16:23:37 tst01 auth|security:debug /usr/sbin/getty PAM: pam_acct_mgmt: 
error No account present for user
Mar 24 16:23:37 tst01 auth|security:debug /usr/sbin/getty PAM: pam_end(): 
status = Authentication failed
Mar 24 16:23:37 tst01 auth|security:info syslog: vty0: failed login attempt for 
UNKNOWN_USER

Doing a ldapsearch with bpr...@example.corp as bind user works without any 
problems.
According to the log above you get failure from pam_aix which should be
expected if pam_aix doesn't think that the user in question is coming
from LDAP.

Can you show output of
lsuser -R LDAP bpr...@example.corp
lsuser -a registry SYSTEM bpr...@example.corp

The attributes 'registry' and 'SYSTEM' should be set to LDAP (or KRB5LDAP).

Can you show how you configured the AIX client?
--
/ Alexander Bokovoy

--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Reply via email to