On 03/24/2015 11:45 AM, 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
Seems like 15 sec timeout on the AIX side.
Can you try with a user that does not have that many groups and see if
that works?
If it does then we should assume it is an AIX side timeout and focus on
making sure the data gets over to IPA within this timeout.
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.
--
Thank you,
Dmitri Pal
Sr. Engineering Manager IdM portfolio
Red Hat, Inc.
--
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
