> On Mar 24, 2015, at 17:17, Jakub Hrozek <jhro...@redhat.com> wrote:
> 
> On Tue, Mar 24, 2015 at 04:45:53PM +0100, 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.
> 
> I guess what Alexander meant (in a very simplified way) was that the 'id'
> command could take a long time. Sumit recently fixed two nasty issues that
> would make this operation take too long with POSIX attributes in effect
> and also that the initgroups operation might be done too frequently with
> SSH. I wonder if you might be seeing this issue, the SSSD logs capturing
> the login on the server side would help.
Yeah, I noticed the other thread about slow logins a couple of days ago. The 
‘id’ command takes 5 to 10 seconds on the IPA server for a couple of accounts I 
tested with (50 to 60 group memberships, some with a lot of/300+ members). I’m 
not using 'Identity Management for UNIX’ on Windows if that’s what you mean. 
I’ll try to clean up (read: remove customer data) the SSSD logs a bit tomorrow 
so I can post them.
> 
>> 
>> 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.
>> 
>> -- 
>> 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
> 
> -- 
> 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


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