Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-06-12 Thread Bobby Prins
On Jun 11, 2015, at 15:37, Alexander Bokovoy  wrote:
> 
> On Thu, 11 Jun 2015, Bobby Prins wrote:
>> On Apr 7, 2015, at 13:41, Bobby Prins  wrote:
>>> 
>>> 
>>>> On Apr 3, 2015, at 14:40, Bobby Prins  wrote:
>>>> 
>>>>> - Oorspronkelijk bericht -
>>>>> Van: "Alexander Bokovoy" 
>>>>> Aan: "Bobby Prins" 
>>>>> Cc: d...@redhat.com, freeipa-users@redhat.com
>>>>> Verzonden: Vrijdag 3 april 2015 14:26:17
>>>>> Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>>>>> ipa_server_mode
>>>>> 
>>>>> On Fri, 03 Apr 2015, Bobby Prins wrote:
>>>>>>> - Oorspronkelijk bericht -----
>>>>>>> Van: "Alexander Bokovoy" 
>>>>>>> Aan: "Bobby Prins" 
>>>>>>> Cc: d...@redhat.com, freeipa-users@redhat.com
>>>>>>> Verzonden: Vrijdag 3 april 2015 12:45:07
>>>>>>> Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>>>>>>> ipa_server_mode
>>>>>>> 
>>>>>>> On Fri, 03 Apr 2015, Bobby Prins wrote:
>>>>>>>> access:
>>>>>>>> [03/Apr/2015:11:58:47 +0200] conn=5950 fd=68 slot=68 connection from 
>>>>>>>> 192.168.140.107 to 192.168.140.133
>>>>>>>> [03/Apr/2015:11:58:47 +0200] conn=5950 op=0 BIND dn="" method=128 
>>>>>>>> version=3
>>>>>>>> [03/Apr/2015:11:58:47 +0200] conn=5950 op=0 RESULT err=0 tag=97 
>>>>>>>> nentries=0 etime=0 dn=""
>>>>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=1 SRCH 
>>>>>>>> base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>>>>>>> filter="(&(objectClass=posixaccount)(uid=bpr...@example.corp))" 
>>>>>>>> attrs=ALL
>>>>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=1 RESULT err=0 tag=101 
>>>>>>>> nentries=1 etime=0
>>>>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=2 SRCH 
>>>>>>>> base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>>>>>>> filter="(&(objectClass=posixaccount)(uid=bprins))" attrs=ALL
>>>>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=2 RESULT err=0 tag=101 
>>>>>>>> nentries=0 etime=0
>>>>>>> Above there are two lookups:
>>>>>>> 
>>>>>>> - successful lookup for user bpri...@example.com
>>>>>>> - unsuccessful lookup for user bprins
>>>>>>> 
>>>>>>> What is causing to perform a lookup without @example.com? Compat tree
>>>>>>> presents AD users fully qualified, it is the only way it knows to
>>>>>>> trigger lookup via SSSD on IPA master for these users (because non-fully
>>>>>>> qualified users are in IPA LDAP tree already and copied to compat tree
>>>>>>> automatically).
>>>>>> This seems to be (standard?) behaviour of the AIX LDAP client. Did some
>>>>>> more tests with different accounts and always see the two lookups. I
>>>>>> doubt if I can influence that..
>>>>> No, this is not standard -- I haven't seen such behavior when testing
>>>>> FreeIPA with AIX last autumn.
>>>>> --
>>>>> / Alexander Bokovoy
>>>> OK, with the idsldap client software and an AD trust configured? This is 
>>>> on AIX7.1. I'm spinning up an AIX5.3 machine now for another test. Might 
>>>> try AIX6.1 as well. What works is creating the user object in freeIPA so 
>>>> the lookup succeeds. After that I can authenticate succesfully against AD. 
>>>> Not the solution I'm looking for though.
>>> Did some tests with AIX5.3 and then I don’t run into any issues. There is 
>>> no lookup to be seen after entering my username on AIX5.3 (as there was on 
>>> AIX7.1), only the authentication request which succeeds. Will test AIX6.1 
>>> later on..
>> 
>> AIX6.1 also worked without any problems. In the end my methods.cfg was 
>> causing the problems on AIX7.1. After deleting these lines authentication 
>> worked:
>> 
>> KRB5:
>>  program = /usr/lib/security/KRB5
>>  program_64 = /usr/lib/security/KRB5_64
>>  options = authonly,kadmind=no
>> 
>> KRB5LDAP:
>>  options = auth=KRB5,db=LDAP
>> 
>> So my methods.cfg now looks like this:
>> 
>> LDAP:
>>  program = /usr/lib/security/LDAP
>>  program_64 = /usr/lib/security/LDAP64
>> 
>> NIS:
>>  program = /usr/lib/security/NIS
>>  program_64 = /usr/lib/security/NIS_64
>> 
>> DCE:
>>  program = /usr/lib/security/DCE
>> 
>> I was not expecting this since I was not using KRB5 or KRB5LDAP in 
>> /etc/security/user. Well, I’m glad I got this sorted out now :)
> Great. Could you please write your configurations up somewhere so that
> we can have an article on freeipa.org detailing the configs for future
> users?

Yes, I will do that Alexander. Hope to have some time for that next week.

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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-06-11 Thread Alexander Bokovoy

On Thu, 11 Jun 2015, Bobby Prins wrote:

On Apr 7, 2015, at 13:41, Bobby Prins  wrote:




On Apr 3, 2015, at 14:40, Bobby Prins  wrote:


- Oorspronkelijk bericht -
Van: "Alexander Bokovoy" 
Aan: "Bobby Prins" 
Cc: d...@redhat.com, freeipa-users@redhat.com
Verzonden: Vrijdag 3 april 2015 14:26:17
Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
ipa_server_mode

On Fri, 03 Apr 2015, Bobby Prins wrote:

- Oorspronkelijk bericht -
Van: "Alexander Bokovoy" 
Aan: "Bobby Prins" 
Cc: d...@redhat.com, freeipa-users@redhat.com
Verzonden: Vrijdag 3 april 2015 12:45:07
Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
ipa_server_mode

On Fri, 03 Apr 2015, Bobby Prins wrote:

access:
[03/Apr/2015:11:58:47 +0200] conn=5950 fd=68 slot=68 connection from 
192.168.140.107 to 192.168.140.133
[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 BIND dn="" method=128 version=3
[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 RESULT err=0 tag=97 nentries=0 etime=0 
dn=""
[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 SRCH 
base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
filter="(&(objectClass=posixaccount)(uid=bpr...@example.corp))" attrs=ALL
[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 RESULT err=0 tag=101 nentries=1 
etime=0
[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 SRCH 
base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
filter="(&(objectClass=posixaccount)(uid=bprins))" attrs=ALL
[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 RESULT err=0 tag=101 nentries=0 
etime=0

Above there are two lookups:

- successful lookup for user bpri...@example.com
- unsuccessful lookup for user bprins

What is causing to perform a lookup without @example.com? Compat tree
presents AD users fully qualified, it is the only way it knows to
trigger lookup via SSSD on IPA master for these users (because non-fully
qualified users are in IPA LDAP tree already and copied to compat tree
automatically).

This seems to be (standard?) behaviour of the AIX LDAP client. Did some
more tests with different accounts and always see the two lookups. I
doubt if I can influence that..

No, this is not standard -- I haven't seen such behavior when testing
FreeIPA with AIX last autumn.
--
/ Alexander Bokovoy

OK, with the idsldap client software and an AD trust configured? This is on 
AIX7.1. I'm spinning up an AIX5.3 machine now for another test. Might try 
AIX6.1 as well. What works is creating the user object in freeIPA so the lookup 
succeeds. After that I can authenticate succesfully against AD. Not the 
solution I'm looking for though.

Did some tests with AIX5.3 and then I don’t run into any issues. There is no 
lookup to be seen after entering my username on AIX5.3 (as there was on 
AIX7.1), only the authentication request which succeeds. Will test AIX6.1 later 
on..


AIX6.1 also worked without any problems. In the end my methods.cfg was causing 
the problems on AIX7.1. After deleting these lines authentication worked:

KRB5:
  program = /usr/lib/security/KRB5
  program_64 = /usr/lib/security/KRB5_64
  options = authonly,kadmind=no

KRB5LDAP:
  options = auth=KRB5,db=LDAP

So my methods.cfg now looks like this:

LDAP:
  program = /usr/lib/security/LDAP
  program_64 = /usr/lib/security/LDAP64

NIS:
  program = /usr/lib/security/NIS
  program_64 = /usr/lib/security/NIS_64

DCE:
  program = /usr/lib/security/DCE

I was not expecting this since I was not using KRB5 or KRB5LDAP in 
/etc/security/user. Well, I’m glad I got this sorted out now :)

Great. Could you please write your configurations up somewhere so that
we can have an article on freeipa.org detailing the configs for future
users?
--
/ 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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-06-11 Thread Bobby Prins
On Apr 7, 2015, at 13:41, Bobby Prins  wrote:
> 
> 
>> On Apr 3, 2015, at 14:40, Bobby Prins  wrote:
>> 
>>> - Oorspronkelijk bericht -
>>> Van: "Alexander Bokovoy" 
>>> Aan: "Bobby Prins" 
>>> Cc: d...@redhat.com, freeipa-users@redhat.com
>>> Verzonden: Vrijdag 3 april 2015 14:26:17
>>> Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>>> ipa_server_mode
>>> 
>>> On Fri, 03 Apr 2015, Bobby Prins wrote:
>>>>> - Oorspronkelijk bericht -
>>>>> Van: "Alexander Bokovoy" 
>>>>> Aan: "Bobby Prins" 
>>>>> Cc: d...@redhat.com, freeipa-users@redhat.com
>>>>> Verzonden: Vrijdag 3 april 2015 12:45:07
>>>>> Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>>>>> ipa_server_mode
>>>>> 
>>>>> On Fri, 03 Apr 2015, Bobby Prins wrote:
>>>>>> access:
>>>>>> [03/Apr/2015:11:58:47 +0200] conn=5950 fd=68 slot=68 connection from 
>>>>>> 192.168.140.107 to 192.168.140.133
>>>>>> [03/Apr/2015:11:58:47 +0200] conn=5950 op=0 BIND dn="" method=128 
>>>>>> version=3
>>>>>> [03/Apr/2015:11:58:47 +0200] conn=5950 op=0 RESULT err=0 tag=97 
>>>>>> nentries=0 etime=0 dn=""
>>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=1 SRCH 
>>>>>> base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>>>>> filter="(&(objectClass=posixaccount)(uid=bpr...@example.corp))" attrs=ALL
>>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=1 RESULT err=0 tag=101 
>>>>>> nentries=1 etime=0
>>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=2 SRCH 
>>>>>> base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>>>>> filter="(&(objectClass=posixaccount)(uid=bprins))" attrs=ALL
>>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=2 RESULT err=0 tag=101 
>>>>>> nentries=0 etime=0
>>>>> Above there are two lookups:
>>>>> 
>>>>> - successful lookup for user bpri...@example.com
>>>>> - unsuccessful lookup for user bprins
>>>>> 
>>>>> What is causing to perform a lookup without @example.com? Compat tree
>>>>> presents AD users fully qualified, it is the only way it knows to
>>>>> trigger lookup via SSSD on IPA master for these users (because non-fully
>>>>> qualified users are in IPA LDAP tree already and copied to compat tree
>>>>> automatically).
>>>> This seems to be (standard?) behaviour of the AIX LDAP client. Did some
>>>> more tests with different accounts and always see the two lookups. I
>>>> doubt if I can influence that..
>>> No, this is not standard -- I haven't seen such behavior when testing
>>> FreeIPA with AIX last autumn.
>>> -- 
>>> / Alexander Bokovoy
>> OK, with the idsldap client software and an AD trust configured? This is on 
>> AIX7.1. I'm spinning up an AIX5.3 machine now for another test. Might try 
>> AIX6.1 as well. What works is creating the user object in freeIPA so the 
>> lookup succeeds. After that I can authenticate succesfully against AD. Not 
>> the solution I'm looking for though.
> Did some tests with AIX5.3 and then I don’t run into any issues. There is no 
> lookup to be seen after entering my username on AIX5.3 (as there was on 
> AIX7.1), only the authentication request which succeeds. Will test AIX6.1 
> later on..

AIX6.1 also worked without any problems. In the end my methods.cfg was causing 
the problems on AIX7.1. After deleting these lines authentication worked:

KRB5:
   program = /usr/lib/security/KRB5
   program_64 = /usr/lib/security/KRB5_64
   options = authonly,kadmind=no

KRB5LDAP:
   options = auth=KRB5,db=LDAP

So my methods.cfg now looks like this:

LDAP:
   program = /usr/lib/security/LDAP
   program_64 = /usr/lib/security/LDAP64

NIS:
   program = /usr/lib/security/NIS
   program_64 = /usr/lib/security/NIS_64

DCE:
   program = /usr/lib/security/DCE

I was not expecting this since I was not using KRB5 or KRB5LDAP in 
/etc/security/user. Well, I’m glad I got this sorted out now :)

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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-04-07 Thread Bobby Prins

> On Apr 3, 2015, at 14:40, Bobby Prins  wrote:
> 
>> - Oorspronkelijk bericht -
>> Van: "Alexander Bokovoy" 
>> Aan: "Bobby Prins" 
>> Cc: d...@redhat.com, freeipa-users@redhat.com
>> Verzonden: Vrijdag 3 april 2015 14:26:17
>> Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>> ipa_server_mode
>> 
>> On Fri, 03 Apr 2015, Bobby Prins wrote:
>>>> - Oorspronkelijk bericht -
>>>> Van: "Alexander Bokovoy" 
>>>> Aan: "Bobby Prins" 
>>>> Cc: d...@redhat.com, freeipa-users@redhat.com
>>>> Verzonden: Vrijdag 3 april 2015 12:45:07
>>>> Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>>>> ipa_server_mode
>>>> 
>>>> On Fri, 03 Apr 2015, Bobby Prins wrote:
>>>>> access:
>>>>> [03/Apr/2015:11:58:47 +0200] conn=5950 fd=68 slot=68 connection from 
>>>>> 192.168.140.107 to 192.168.140.133
>>>>> [03/Apr/2015:11:58:47 +0200] conn=5950 op=0 BIND dn="" method=128 
>>>>> version=3
>>>>> [03/Apr/2015:11:58:47 +0200] conn=5950 op=0 RESULT err=0 tag=97 
>>>>> nentries=0 etime=0 dn=""
>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=1 SRCH 
>>>>> base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>>>> filter="(&(objectClass=posixaccount)(uid=bpr...@example.corp))" attrs=ALL
>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=1 RESULT err=0 tag=101 
>>>>> nentries=1 etime=0
>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=2 SRCH 
>>>>> base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>>>> filter="(&(objectClass=posixaccount)(uid=bprins))" attrs=ALL
>>>>> [03/Apr/2015:11:59:04 +0200] conn=5950 op=2 RESULT err=0 tag=101 
>>>>> nentries=0 etime=0
>>>> Above there are two lookups:
>>>> 
>>>> - successful lookup for user bpri...@example.com
>>>> - unsuccessful lookup for user bprins
>>>> 
>>>> What is causing to perform a lookup without @example.com? Compat tree
>>>> presents AD users fully qualified, it is the only way it knows to
>>>> trigger lookup via SSSD on IPA master for these users (because non-fully
>>>> qualified users are in IPA LDAP tree already and copied to compat tree
>>>> automatically).
>>> This seems to be (standard?) behaviour of the AIX LDAP client. Did some
>>> more tests with different accounts and always see the two lookups. I
>>> doubt if I can influence that..
>> No, this is not standard -- I haven't seen such behavior when testing
>> FreeIPA with AIX last autumn.
>> -- 
>> / Alexander Bokovoy
> OK, with the idsldap client software and an AD trust configured? This is on 
> AIX7.1. I'm spinning up an AIX5.3 machine now for another test. Might try 
> AIX6.1 as well. What works is creating the user object in freeIPA so the 
> lookup succeeds. After that I can authenticate succesfully against AD. Not 
> the solution I'm looking for though.
Did some tests with AIX5.3 and then I don’t run into any issues. There is no 
lookup to be seen after entering my username on AIX5.3 (as there was on 
AIX7.1), only the authentication request which succeeds. Will test AIX6.1 later 
on..


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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-04-03 Thread Bobby Prins
>- Oorspronkelijk bericht -
>Van: "Alexander Bokovoy" 
>Aan: "Bobby Prins" 
>Cc: d...@redhat.com, freeipa-users@redhat.com
>Verzonden: Vrijdag 3 april 2015 14:26:17
>Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>ipa_server_mode
>
>On Fri, 03 Apr 2015, Bobby Prins wrote:
>>>- Oorspronkelijk bericht -
>>>Van: "Alexander Bokovoy" 
>>>Aan: "Bobby Prins" 
>>>Cc: d...@redhat.com, freeipa-users@redhat.com
>>>Verzonden: Vrijdag 3 april 2015 12:45:07
>>>Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>>>ipa_server_mode
>>>
>>>On Fri, 03 Apr 2015, Bobby Prins wrote:
>>>>access:
>>>>[03/Apr/2015:11:58:47 +0200] conn=5950 fd=68 slot=68 connection from 
>>>>192.168.140.107 to 192.168.140.133
>>>>[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 BIND dn="" method=128 version=3
>>>>[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 RESULT err=0 tag=97 nentries=0 
>>>>etime=0 dn=""
>>>>[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 SRCH 
>>>>base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>>>filter="(&(objectClass=posixaccount)(uid=bpr...@example.corp))" attrs=ALL
>>>>[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 RESULT err=0 tag=101 nentries=1 
>>>>etime=0
>>>>[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 SRCH 
>>>>base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>>>filter="(&(objectClass=posixaccount)(uid=bprins))" attrs=ALL
>>>>[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 RESULT err=0 tag=101 nentries=0 
>>>>etime=0
>>>Above there are two lookups:
>>>
>>>- successful lookup for user bpri...@example.com
>>>- unsuccessful lookup for user bprins
>>>
>>>What is causing to perform a lookup without @example.com? Compat tree
>>>presents AD users fully qualified, it is the only way it knows to
>>>trigger lookup via SSSD on IPA master for these users (because non-fully
>>>qualified users are in IPA LDAP tree already and copied to compat tree
>>>automatically).
>>This seems to be (standard?) behaviour of the AIX LDAP client. Did some
>>more tests with different accounts and always see the two lookups. I
>>doubt if I can influence that..
>No, this is not standard -- I haven't seen such behavior when testing
>FreeIPA with AIX last autumn.
>-- 
>/ Alexander Bokovoy
OK, with the idsldap client software and an AD trust configured? This is on 
AIX7.1. I'm spinning up an AIX5.3 machine now for another test. Might try 
AIX6.1 as well. What works is creating the user object in freeIPA so the lookup 
succeeds. After that I can authenticate succesfully against AD. Not the 
solution I'm looking for though.

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


Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-04-03 Thread Alexander Bokovoy

On Fri, 03 Apr 2015, Bobby Prins wrote:

- Oorspronkelijk bericht -
Van: "Alexander Bokovoy" 
Aan: "Bobby Prins" 
Cc: d...@redhat.com, freeipa-users@redhat.com
Verzonden: Vrijdag 3 april 2015 12:45:07
Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
ipa_server_mode

On Fri, 03 Apr 2015, Bobby Prins wrote:

On Mar 24, 2015, at 17:11, Dmitri Pal  wrote:

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.

I need to do some more testing.. Did not have a lot of time today, but I tried 
to authenticate with an AD user against the compact tree using a Linux client 
with pam_ldap. I was able to log in but this would take up to a minute or so. 
I’m still waiting for my AD test account with lesser group memberships.


--
Thank you,
Dmitri Pal

Sr. Engineering Manager IdM portfolio
Red Hat, Inc.


So I finally found some time to do extra tests. I now have an AD
account with lesser group memberships which seems to speed up the login
process (with Linux LDAP auth against the compat tree), but still no
success on AIX. Did some more digging and it looks like AIX invalidates
the user before it even is authenticated. The output below shows the
lookup that is performed after I enter the username en press enter
(before entering the password).

access:
[03/Apr/2015:11:58:47 +0200] conn=5950 fd=68 slot=68 connection from 
192.168.140.107 to 192.168.140.133
[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 BIND dn="" method=128 version=3
[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 RESULT err=0 tag=97 nentries=0 etime=0 
dn=""
[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 SRCH 
base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
filter="(&(objectClass=posixaccount)(uid=bpr...@example.corp))" attrs=ALL
[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 RESULT err=0 tag=101 nentries=1 
etime=0
[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 SRCH 
base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
filter="(&(objectClass=posixaccount)(uid=bprins))" attrs=ALL
[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 RESULT err=0 tag=101 nentries=0 
etime=0

Above there are two lookups:

- successful lookup for user bpri...@example.com
- unsuccessful lookup for user bprins

What is causing to perform a lookup without @example.com? Compat tree
presents AD users fully qualified, it is the only way it knows to
trigger lookup via SSSD on IPA master for these users (because non-fully
qualified users are in IPA LDAP tree already and copied to compat tree
automatically).

This seems to be (standard?) behaviour of the AIX LDAP client. Did some
more tests with different accounts and always see the two lookups. I
doubt if I can influence that..

No, this is not standard -- I haven't seen such behavior when testing
FreeIPA with AIX last autumn.
--
/ 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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-04-03 Thread Bobby Prins
>- Oorspronkelijk bericht -
>Van: "Alexander Bokovoy" 
>Aan: "Bobby Prins" 
>Cc: d...@redhat.com, freeipa-users@redhat.com
>Verzonden: Vrijdag 3 april 2015 12:45:07
>Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>ipa_server_mode
>
>On Fri, 03 Apr 2015, Bobby Prins wrote:
>>>> On Mar 24, 2015, at 17:11, Dmitri Pal  wrote:
>>>>
>>>> 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.
>>>I need to do some more testing.. Did not have a lot of time today, but I 
>>>tried to authenticate with an AD user against the compact tree using a Linux 
>>>client with pam_ldap. I was able to log in but this would take up to a 
>>>minute or so. I’m still waiting for my AD test account with lesser group 
>>>memberships.
>>>>
>>>> --
>>>> Thank you,
>>>> Dmitri Pal
>>>>
>>>> Sr. Engineering Manager IdM portfolio
>>>> Red Hat, Inc.
>>>>
>>So I finally found some time to do extra tests. I now have an AD
>>account with lesser group memberships which seems to speed up the login
>>process (with Linux LDAP auth against the compat tree), but still no
>>success on AIX. Did some more digging and it looks like AIX invalidates
>>the user before it even is authenticated. The output below shows the
>>lookup that is performed after I enter the username en press enter
>>(before entering the password).
>>
>>access:
>>[03/Apr/2015:11:58:47 +0200] conn=5950 fd=68 slot=68 connection from 
>>192.168.140.107 to 192.168.140.133
>>[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 BIND dn="" method=128 version=3
>>[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 RESULT err=0 tag=97 nentries=0 
>>etime=0 dn=""
>>[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 SRCH 
>>base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>filter="(&(objectClass=posixaccount)(uid=bpr...@example.corp))" attrs=ALL
>>[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 RESULT err=0 tag=101 nentries=1 
>>etime=0
>>[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 SRCH 
>>base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
>>filter="(&(objectClass=posixaccount)(uid=bprins))" attrs=ALL
>>[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 RESULT err=0 tag=101 nentries=0 
>>etime=0
>Above there are two lookups:
>
>- successful lookup for user bpri...@example.com
>- unsuccessful lookup for user bprins
>
>What is causing to perform a lookup without @example.com? Compat tree
>presents AD users fully qualified, it is the only way it knows to
>trigger lookup via SSSD on IPA master for these users (because non-fully
>qualified users are in IPA LDAP tree already and copied to compat tree
>automatically).
>-- 
>/ Alexander Bokovoy
This seems to be (standard?) behaviour of the AIX LDAP client. Did some more 
tests with different accounts and always see the two lookups. I doubt if I can 
influence that..

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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-04-03 Thread Alexander Bokovoy

On Fri, 03 Apr 2015, Bobby Prins wrote:

On Mar 24, 2015, at 17:11, Dmitri Pal  wrote:

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.

I need to do some more testing.. Did not have a lot of time today, but I tried 
to authenticate with an AD user against the compact tree using a Linux client 
with pam_ldap. I was able to log in but this would take up to a minute or so. 
I’m still waiting for my AD test account with lesser group memberships.


--
Thank you,
Dmitri Pal

Sr. Engineering Manager IdM portfolio
Red Hat, Inc.


So I finally found some time to do extra tests. I now have an AD
account with lesser group memberships which seems to speed up the login
process (with Linux LDAP auth against the compat tree), but still no
success on AIX. Did some more digging and it looks like AIX invalidates
the user before it even is authenticated. The output below shows the
lookup that is performed after I enter the username en press enter
(before entering the password).

access:
[03/Apr/2015:11:58:47 +0200] conn=5950 fd=68 slot=68 connection from 
192.168.140.107 to 192.168.140.133
[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 BIND dn="" method=128 version=3
[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 RESULT err=0 tag=97 nentries=0 etime=0 
dn=""
[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 SRCH 
base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
filter="(&(objectClass=posixaccount)(uid=bpr...@example.corp))" attrs=ALL
[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 RESULT err=0 tag=101 nentries=1 
etime=0
[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 SRCH 
base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
filter="(&(objectClass=posixaccount)(uid=bprins))" attrs=ALL
[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 RESULT err=0 tag=101 nentries=0 
etime=0

Above there are two lookups:

- successful lookup for user bpri...@example.com
- unsuccessful lookup for user bprins

What is causing to perform a lookup without @example.com? Compat tree
presents AD users fully qualified, it is the only way it knows to
trigger lookup via SSSD on IPA master for these users (because non-fully
qualified users are in IPA LDAP tree already and copied to compat tree
automatically).
--
/ 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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-04-03 Thread Bobby Prins
>> On Mar 24, 2015, at 17:11, Dmitri Pal  wrote:
>> 
>> 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.
>I need to do some more testing.. Did not have a lot of time today, but I tried 
>to authenticate with an AD user against the compact tree using a Linux client 
>with pam_ldap. I was able to log in but this would take up to a minute or so. 
>I’m still waiting for my AD test account with lesser group memberships.
>> 
>> -- 
>> Thank you,
>> Dmitri Pal
>> 
>> Sr. Engineering Manager IdM portfolio
>> Red Hat, Inc.
>> 
So I finally found some time to do extra tests. I now have an AD account with 
lesser group memberships which seems to speed up the login process (with Linux 
LDAP auth against the compat tree), but still no success on AIX. Did some more 
digging and it looks like AIX invalidates the user before it even is 
authenticated. The output below shows the lookup that is performed after I 
enter the username en press enter (before entering the password).

access:
[03/Apr/2015:11:58:47 +0200] conn=5950 fd=68 slot=68 connection from 
192.168.140.107 to 192.168.140.133
[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 BIND dn="" method=128 version=3
[03/Apr/2015:11:58:47 +0200] conn=5950 op=0 RESULT err=0 tag=97 nentries=0 
etime=0 dn=""
[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 SRCH 
base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
filter="(&(objectClass=posixaccount)(uid=bpr...@example.corp))" attrs=ALL
[03/Apr/2015:11:59:04 +0200] conn=5950 op=1 RESULT err=0 tag=101 nentries=1 
etime=0
[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 SRCH 
base="cn=users,cn=compat,dc=unix,dc=example,dc=corp" scope=2 
filter="(&(objectClass=posixaccount)(uid=bprins))" attrs=ALL
[03/Apr/2015:11:59:04 +0200] conn=5950 op=2 RESULT err=0 tag=101 nentries=0 
etime=0

sssd_unix.example.corp.log:
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] [sbus_dispatch] 
(0x4000): dbus conn: 0x7fae8e331c20
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] [sbus_dispatch] 
(0x4000): Dispatching.
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] [sbus_message_handler] 
(0x4000): Received SBUS method [getAccountInfo]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [getAccountInfo]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] [be_get_account_info] 
(0x0200): Got request for [0x1001][1][name=bprins]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] [be_req_set_domain] 
(0x0400): Changing request domain from [unix.example.corp] to 
[unix.example.corp]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_id_op_connect_step] (0x4000): reusing cached connection
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_search_user_next_base] (0x0400): Searching for users with base 
[cn=accounts,dc=unix,dc=example,dc=corp]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] [sdap_print_server] 
(0x2000): Searching 192.168.140.133
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
[(&(uid=bprins)(objectclass=posixAccount)(uid=*)(&(uidNumber=*)(!(uidNumber=0][cn=accounts,dc=unix,dc=example,dc=corp].
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uid]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [homeDirectory]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPrincipalName]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.example.corp]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Fri Apr  3 11:59:04 2015) [sssd[be[unix.e

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-25 Thread Bobby Prins

> On Mar 24, 2015, at 17:11, Dmitri Pal  wrote:
> 
> On 03/24/2015 11:45 AM, Bobby Prins wrote:
>>> - Oorspronkelijk bericht -
>>> Van: "Alexander Bokovoy" 
>>> Aan: "Bobby Prins" 
>>> 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" 
>>>>> Aan: "Bobby Prins" 
>>>>> 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= 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 /u

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Jakub Hrozek
On Tue, Mar 24, 2015 at 08:10:43PM +0100, Bobby Prins wrote:
> > 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.

Ah, thank you, then it's unlikely either of the two bugs affect you.

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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Bobby Prins

> On Mar 24, 2015, at 17:17, Jakub Hrozek  wrote:
> 
> On Tue, Mar 24, 2015 at 04:45:53PM +0100, Bobby Prins wrote:
>>> - Oorspronkelijk bericht -
>>> Van: "Alexander Bokovoy" 
>>> Aan: "Bobby Prins" 
>>> 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" 
>>>>> Aan: "Bobby Prins" 
>>>>> 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= 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.
Ye

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Bobby Prins

> On Mar 24, 2015, at 17:11, Dmitri Pal  wrote:
> 
> On 03/24/2015 11:45 AM, Bobby Prins wrote:
>>> - Oorspronkelijk bericht -
>>> Van: "Alexander Bokovoy" 
>>> Aan: "Bobby Prins" 
>>> 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" 
>>>>> Aan: "Bobby Prins" 
>>>>> 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= 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/

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Bobby Prins

> On Mar 24, 2015, at 18:42, Alexander Bokovoy  wrote:
> 
> On Tue, 24 Mar 2015, Bobby Prins wrote:
 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
>> 
>> lsuser -R LDAP bpr...@example.corp:
>> bpr...@example.corp id=211623277 pgrp=bpr...@example.corp 
>> groups=bpr...@example.corp home=/home/example.corp/bprins shell=/bin/bash 
>> gecos=Bobby Prins login=true su=true rlogin=true daemon=true admin=false 
>> sugroups=ALL admgroups= tpath=nosak ttys=ALL expires=0 auth1=SYSTEM 
>> auth2=NONE umask=22 registry=LDAP SYSTEM=LDAP logintimes= loginretries=0 
>> pwdwarntime=0 account_locked=false minage=0 maxage=0 maxexpired=-1 
>> minalpha=0 minloweralpha=0 minupperalpha=0 minother=0 mindigit=0 
>> minspecialchar=0 mindiff=0 maxrepeats=8 minlen=0 histexpire=0 histsize=0 
>> pwdchecks= dictionlist= default_roles= fsize=8388604 cpu=-1 data=262144 
>> stack=65536 core=2097151 rss=65536 nofiles=2000 roles=
> I assume you have /bin/bash installed on AIX? This user has shell
> defined as /bin/bash and if it is missing, login or ssh will deny its
> access to the system.
Yes, bash is a valid shell on this machine and also in use by local and IPA 
users.
> 
>> 
>> lsuser -a registry SYSTEM bpr...@example.corp:
>> bpr...@example.corp registry=LDAP SYSTEM=LDAP
>> 
>> Contents of /etc/security/ldap/ldap.cfg:
>> ldapservers:idm01.unix.example.corp
>> authtype:ldap_auth
>> useSSL:no
>> userattrmappath:/etc/security/ldap/IPAuser.map
>> groupattrmappath:/etc/security/ldap/IPAgroup.map
>> userbasedn:cn=users,cn=compat,dc=unix,dc=example,dc=corp
>> groupbasedn:cn=groups,cn=compat,dc=unix,dc=example,dc=corp
>> userclasses:posixaccount
>> groupclasses:posixgroup
>> ldapport:389
>> searchmode:ALL
>> defaultentrylocation:LDAP
>> serverschematype:rfc2307
>> 
>> Map file /etc/security/ldap/IPAuser.map:
>> #IPAuser.map file
>> keyobjectclass  SEC_CHARposixaccounts
>> 
>> # The following attributes are required by AIX to be functional
>> usernameSEC_CHARuid s
>> id  SEC_INT uidnumber   s

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Alexander Bokovoy

On Tue, 24 Mar 2015, Bobby Prins wrote:

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


lsuser -R LDAP bpr...@example.corp:
bpr...@example.corp id=211623277 pgrp=bpr...@example.corp 
groups=bpr...@example.corp home=/home/example.corp/bprins shell=/bin/bash 
gecos=Bobby Prins login=true su=true rlogin=true daemon=true admin=false 
sugroups=ALL admgroups= tpath=nosak ttys=ALL expires=0 auth1=SYSTEM auth2=NONE 
umask=22 registry=LDAP SYSTEM=LDAP logintimes= loginretries=0 pwdwarntime=0 
account_locked=false minage=0 maxage=0 maxexpired=-1 minalpha=0 minloweralpha=0 
minupperalpha=0 minother=0 mindigit=0 minspecialchar=0 mindiff=0 maxrepeats=8 
minlen=0 histexpire=0 histsize=0 pwdchecks= dictionlist= default_roles= 
fsize=8388604 cpu=-1 data=262144 stack=65536 core=2097151 rss=65536 
nofiles=2000 roles=

I assume you have /bin/bash installed on AIX? This user has shell
defined as /bin/bash and if it is missing, login or ssh will deny its
access to the system.



lsuser -a registry SYSTEM bpr...@example.corp:
bpr...@example.corp registry=LDAP SYSTEM=LDAP

Contents of /etc/security/ldap/ldap.cfg:
ldapservers:idm01.unix.example.corp
authtype:ldap_auth
useSSL:no
userattrmappath:/etc/security/ldap/IPAuser.map
groupattrmappath:/etc/security/ldap/IPAgroup.map
userbasedn:cn=users,cn=compat,dc=unix,dc=example,dc=corp
groupbasedn:cn=groups,cn=compat,dc=unix,dc=example,dc=corp
userclasses:posixaccount
groupclasses:posixgroup
ldapport:389
searchmode:ALL
defaultentrylocation:LDAP
serverschematype:rfc2307

Map file /etc/security/ldap/IPAuser.map:
#IPAuser.map file
keyobjectclass  SEC_CHARposixaccounts

# The following attributes are required by AIX to be functional
usernameSEC_CHARuid s
id  SEC_INT uidnumber   s
pgrpSEC_CHARgidnumber   s
homeSEC_CHARhomedirectory   s
shell   SEC_CHARloginshell  s
gecos   SEC_CHARgecos   s
spassword   SEC_CHARuserpasswords
lastupdate  SEC_INT shadowlastchanges

Map file /etc/security/ldap/IPAgroup.map:
#IPAgroup.map file
groupname   SEC_CHARcns
id  SEC_INT gidNumber s
users   SEC_LISTmemberm

With the curre

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Bobby Prins
>- Oorspronkelijk bericht -
>Van: "Alexander Bokovoy" 
>Aan: "Bobby Prins" 
>Cc: d...@redhat.com, freeipa-users@redhat.com
>Verzonden: Dinsdag 24 maart 2015 17:23:08
>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" 
>>>Aan: "Bobby Prins" 
>>>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" 
>>>>>Aan: "Bobby Prins" 
>>>>>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= 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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Alexander Bokovoy

On Tue, 24 Mar 2015, Bobby Prins wrote:

- Oorspronkelijk bericht -
Van: "Alexander Bokovoy" 
Aan: "Bobby Prins" 
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" 
Aan: "Bobby Prins" 
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= 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 fo

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Jakub Hrozek
On Tue, Mar 24, 2015 at 04:45:53PM +0100, Bobby Prins wrote:
> >- Oorspronkelijk bericht -
> >Van: "Alexander Bokovoy" 
> >Aan: "Bobby Prins" 
> >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" 
> >>>Aan: "Bobby Prins" 
> >>>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= 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.

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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Dmitri Pal

On 03/24/2015 11:45 AM, Bobby Prins wrote:

- Oorspronkelijk bericht -
Van: "Alexander Bokovoy" 
Aan: "Bobby Prins" 
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" 
Aan: "Bobby Prins" 
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= 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|se

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Bobby Prins
>- Oorspronkelijk bericht -
>Van: "Alexander Bokovoy" 
>Aan: "Bobby Prins" 
>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" 
>>>Aan: "Bobby Prins" 
>>>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= 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

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Bobby Prins
>- Oorspronkelijk bericht -
>Van: "Dmitri Pal" 
>Aan: "Bobby Prins" 
>Cc: "Alexander Bokovoy" , freeipa-users@redhat.com
>Verzonden: Dinsdag 24 maart 2015 16:08:07
>Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>ipa_server_mode
>
>On 03/24/2015 10:18 AM, Bobby Prins wrote:
>>> - Oorspronkelijk bericht -
>>> Van: "Dmitri Pal" 
>>> Aan: "Bobby Prins" , "Alexander Bokovoy" 
>>> 
>>> Cc: freeipa-users@redhat.com
>>> Verzonden: Dinsdag 24 maart 2015 14:44:42
>>> Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>>> ipa_server_mode
>>>
>>> On 03/24/2015 09:01 AM, Bobby Prins wrote:
>>>>> ----- Oorspronkelijk bericht -
>>>>> Van: "Alexander Bokovoy" 
>>>>> Aan: "Bobby Prins" 
>>>>> 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= 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?
>>>>
>>>> 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?
>>> Does the user that you use (bpr...@example.corp) is a member of many
>>> large groups?
>>>
>>> -- 
>>> Thank you,
>>> Dmitri Pal
>>>
>>> Sr. Engineering Manager IdM portfolio
>>> Red Hat, Inc.
>> 53 groups in total ranging from groups with only a couple of users to groups 
>> with multiple hundreds of users.
>And probably nesting is involved too, right?
>
>-- 
>Thank you,
>Dmitri Pal
>
>Sr. Engineering Manager IdM portfolio
>Red Hat, Inc.

Yes, that is correct, but the 53 groups is including nested memberships.

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


Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Dmitri Pal

On 03/24/2015 10:18 AM, Bobby Prins wrote:

- Oorspronkelijk bericht -
Van: "Dmitri Pal" 
Aan: "Bobby Prins" , "Alexander Bokovoy" 

Cc: freeipa-users@redhat.com
Verzonden: Dinsdag 24 maart 2015 14:44:42
Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
ipa_server_mode

On 03/24/2015 09:01 AM, Bobby Prins wrote:

- Oorspronkelijk bericht -
Van: "Alexander Bokovoy" 
Aan: "Bobby Prins" 
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= 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?

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?

Does the user that you use (bpr...@example.corp) is a member of many
large groups?

--
Thank you,
Dmitri Pal

Sr. Engineering Manager IdM portfolio
Red Hat, Inc.

53 groups in total ranging from groups with only a couple of users to groups 
with multiple hundreds of users.

And probably nesting is involved too, right?

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


Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Bobby Prins
>- Oorspronkelijk bericht -
>Van: "Dmitri Pal" 
>Aan: "Bobby Prins" , "Alexander Bokovoy" 
>
>Cc: freeipa-users@redhat.com
>Verzonden: Dinsdag 24 maart 2015 14:44:42
>Onderwerp: Re: [Freeipa-users] 'Preauthentication failed' with SSSD in 
>ipa_server_mode
>
>On 03/24/2015 09:01 AM, Bobby Prins wrote:
>>> - Oorspronkelijk bericht -
>>> Van: "Alexander Bokovoy" 
>>> Aan: "Bobby Prins" 
>>> 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= 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?
>>
>> 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?
>Does the user that you use (bpr...@example.corp) is a member of many 
>large groups?
>
>-- 
>Thank you,
>Dmitri Pal
>
>Sr. Engineering Manager IdM portfolio
>Red Hat, Inc.

53 groups in total ranging from groups with only a couple of users to groups 
with multiple hundreds of users.

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


Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Alexander Bokovoy

On Tue, 24 Mar 2015, Bobby Prins wrote:

- Oorspronkelijk bericht -
Van: "Alexander Bokovoy" 
Aan: "Bobby Prins" 
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= 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

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


Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Dmitri Pal

On 03/24/2015 09:01 AM, Bobby Prins wrote:

- Oorspronkelijk bericht -
Van: "Alexander Bokovoy" 
Aan: "Bobby Prins" 
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= 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?

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?
Does the user that you use (bpr...@example.corp) is a member of many 
large groups?


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


Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-24 Thread Bobby Prins
>- Oorspronkelijk bericht -
>Van: "Alexander Bokovoy" 
>Aan: "Bobby Prins" 
>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= 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?

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?

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


Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-23 Thread Alexander Bokovoy

On Mon, 23 Mar 2015, Bobby Prins wrote:

On 03/20/2015 08:05 AM, Alexander Bokovoy wrote:

On Fri, 20 Mar 2015, Bobby Prins wrote:

On Fri, 20 Mar 2015, Sumit Bose wrote:

On Fri, Mar 20, 2015 at 11:44:43AM +0100, Bobby Prins wrote:

On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
>> Hi there,
>>
>> I'm currently trying to use the 'AD Trust for Legacy Clients'
>> freeIPA setup (described here:
>> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf)
>> to be able to autenticate AIX 7.1 clients against an AD domain
>> using LDAP. After the trust was created all seems to work well
>> on the freeIPA server. I can also do a lookup of AD users and
>> groups on an AIX test server.
>>
>> But as soon as I want to log in on the AIX system I get an SSSD
error on the freeIPA server in krb5_child.log (debug_level = 10):
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS
key obtained for encrypted timestamp: aes256-cts/2F5D
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326:
Encrypted timestamp (for 1426778442.525165): plain
301AA011180F32303135303331393135323034325AA105020308036D,
encrypted
9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349:
Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360:
Produced preauth for next request: 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384:
Sending request (238 bytes) to EXAMPLE.CORP
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325:
Resolving hostname dct020.example.corp.
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889:
Sending initial UDP request to dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127:
Received answer from dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626:
Response was not from master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667:
Received error from KDC: -1765328360/Preauthentication failed
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698:
Preauth tryagain input types: 16, 14, 19, 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728:
Retrying AS request with master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741:
Getting initial credentials for bpr...@example.corp
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787:
Sending request (160 bytes) to EXAMPLE.CORP (master)
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[get_and_save_tgt] (0x0020): 979: [-1765328360][Preauthentication
failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[map_krb5_error] (0x0020): 1040: [-1765328360][Preauthentication
failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775
[k5c_send_data] (0x0200): Received error code 1432158214
>>
>> If I do the same with 'KRB5_TRACE=/dev/stderr kinit
bpr...@example.corp':
>> [12299] 1426773524.361785: AS key obtained for encrypted
timestamp: aes256-cts/B997
>> [12299] 1426773524.361850: Encrypted timestamp (for
1426773524.277583): plain
301AA011180F32303135303331393133353834345AA1050203043C4F,
encrypted
ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
>> [12299] 1426773524.361876: Preauth module encrypted_timestamp
(2) (flags=1) returned: 0/Success
>> [12299] 1426773524.361880: Produced preauth for next request: 2
>> [12299] 1426773524.361901: Sending request (238 bytes) to
EXAMPLE.CORP
>> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
>> [12299] 1426773524.363841: Sending initial UDP request to dgram
192.168.141.1:88
>> [12299] 1426773524.368089: Received answer from dgram
192.168.141.1:88
>> [12299] 1426773524.368482: Response was not from master KDC
>> [12299] 1426773524.368500: Received error from KDC:
-1765328332/Response too big for UDP, retry with TCP
>> [12299] 1426773524.368506: Request or response is too big for
UDP; retrying with TCP
>> [12299] 1426773524.368511: Sending request (238 bytes) to
EXAMPLE.

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-23 Thread Bobby Prins
>On 03/20/2015 08:05 AM, Alexander Bokovoy wrote:
>> On Fri, 20 Mar 2015, Bobby Prins wrote:
 On Fri, 20 Mar 2015, Sumit Bose wrote:
> On Fri, Mar 20, 2015 at 11:44:43AM +0100, Bobby Prins wrote:
>> On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
>> >> Hi there,
>> >>
>> >> I'm currently trying to use the 'AD Trust for Legacy Clients'
>> >> freeIPA setup (described here:
>> >> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf)
>> >> to be able to autenticate AIX 7.1 clients against an AD domain
>> >> using LDAP. After the trust was created all seems to work well
>> >> on the freeIPA server. I can also do a lookup of AD users and
>> >> groups on an AIX test server.
>> >>
>> >> But as soon as I want to log in on the AIX system I get an SSSD 
>> error on the freeIPA server in krb5_child.log (debug_level = 10):
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS 
>> key obtained for encrypted timestamp: aes256-cts/2F5D
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: 
>> Encrypted timestamp (for 1426778442.525165): plain 
>> 301AA011180F32303135303331393135323034325AA105020308036D, 
>> encrypted 
>> 9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: 
>> Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: 
>> Produced preauth for next request: 2
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: 
>> Sending request (238 bytes) to EXAMPLE.CORP
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: 
>> Resolving hostname dct020.example.corp.
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: 
>> Sending initial UDP request to dgram 192.168.143.1:88
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: 
>> Received answer from dgram 192.168.143.1:88
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: 
>> Response was not from master KDC
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: 
>> Received error from KDC: -1765328360/Preauthentication failed
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: 
>> Preauth tryagain input types: 16, 14, 19, 2
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: 
>> Retrying AS request with master KDC
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: 
>> Getting initial credentials for bpr...@example.corp
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: 
>> Sending request (160 bytes) to EXAMPLE.CORP (master)
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [get_and_save_tgt] (0x0020): 979: [-1765328360][Preauthentication 
>> failed]
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [map_krb5_error] (0x0020): 1040: [-1765328360][Preauthentication 
>> failed]
>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [k5c_send_data] (0x0200): Received error code 1432158214
>> >>
>> >> If I do the same with 'KRB5_TRACE=/dev/stderr kinit 
>> bpr...@example.corp':
>> >> [12299] 1426773524.361785: AS key obtained for encrypted 
>> timestamp: aes256-cts/B997
>> >> [12299] 1426773524.361850: Encrypted timestamp (for 
>> 1426773524.277583): plain 
>> 301AA011180F32303135303331393133353834345AA1050203043C4F, 
>> encrypted 
>> ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
>> >> [12299] 1426773524.361876: Preauth module encrypted_timestamp 
>> (2) (flags=1) returned: 0/Success
>> >> [12299] 1426773524.361880: Produced preauth for next request: 2
>> >> [12299] 1426773524.361901: Sending request (238 bytes)

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-20 Thread Dmitri Pal

On 03/20/2015 08:05 AM, Alexander Bokovoy wrote:

On Fri, 20 Mar 2015, Bobby Prins wrote:

On Fri, 20 Mar 2015, Sumit Bose wrote:

On Fri, Mar 20, 2015 at 11:44:43AM +0100, Bobby Prins wrote:

On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
>> Hi there,
>>
>> I'm currently trying to use the 'AD Trust for Legacy Clients'
>> freeIPA setup (described here:
>> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf)
>> to be able to autenticate AIX 7.1 clients against an AD domain
>> using LDAP. After the trust was created all seems to work well
>> on the freeIPA server. I can also do a lookup of AD users and
>> groups on an AIX test server.
>>
>> But as soon as I want to log in on the AIX system I get an SSSD 
error on the freeIPA server in krb5_child.log (debug_level = 10):
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS 
key obtained for encrypted timestamp: aes256-cts/2F5D
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: 
Encrypted timestamp (for 1426778442.525165): plain 
301AA011180F32303135303331393135323034325AA105020308036D, 
encrypted 
9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: 
Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: 
Produced preauth for next request: 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: 
Sending request (238 bytes) to EXAMPLE.CORP
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: 
Resolving hostname dct020.example.corp.
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: 
Sending initial UDP request to dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: 
Received answer from dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: 
Response was not from master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: 
Received error from KDC: -1765328360/Preauthentication failed
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: 
Preauth tryagain input types: 16, 14, 19, 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: 
Retrying AS request with master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: 
Getting initial credentials for bpr...@example.corp
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: 
Sending request (160 bytes) to EXAMPLE.CORP (master)
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[get_and_save_tgt] (0x0020): 979: [-1765328360][Preauthentication 
failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[map_krb5_error] (0x0020): 1040: [-1765328360][Preauthentication 
failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[k5c_send_data] (0x0200): Received error code 1432158214

>>
>> If I do the same with 'KRB5_TRACE=/dev/stderr kinit 
bpr...@example.corp':
>> [12299] 1426773524.361785: AS key obtained for encrypted 
timestamp: aes256-cts/B997
>> [12299] 1426773524.361850: Encrypted timestamp (for 
1426773524.277583): plain 
301AA011180F32303135303331393133353834345AA1050203043C4F, 
encrypted 
ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
>> [12299] 1426773524.361876: Preauth module encrypted_timestamp 
(2) (flags=1) returned: 0/Success

>> [12299] 1426773524.361880: Produced preauth for next request: 2
>> [12299] 1426773524.361901: Sending request (238 bytes) to 
EXAMPLE.CORP

>> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
>> [12299] 1426773524.363841: Sending initial UDP request to dgram 
192.168.141.1:88
>> [12299] 1426773524.368089: Received answer from dgram 
192.168.141.1:88

>> [12299] 1426773524.368482: Response was not from master KDC
>> [12299] 1426773524.368500: Received error from KDC: 
-1765328332/Response too big for UDP, retry with TCP
>> [12299] 1426773524.368506: Request or response is too big for 
UDP; retrying with TCP
>> [12299] 1426773524.368511: Sending request (238 bytes)

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-20 Thread Alexander Bokovoy

On Fri, 20 Mar 2015, Bobby Prins wrote:

On Fri, 20 Mar 2015, Sumit Bose wrote:

On Fri, Mar 20, 2015 at 11:44:43AM +0100, Bobby Prins wrote:

On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
>> Hi there,
>>
>> I'm currently trying to use the 'AD Trust for Legacy Clients'
>> freeIPA setup (described here:
>> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf)
>> to be able to autenticate AIX 7.1 clients against an AD domain
>> using LDAP. After the trust was created all seems to work well
>> on the freeIPA server. I can also do a lookup of AD users and
>> groups on an AIX test server.
>>
>> But as soon as I want to log in on the AIX system I get an SSSD error on the 
freeIPA server in krb5_child.log (debug_level = 10):
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS key obtained for 
encrypted timestamp: aes256-cts/2F5D
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: Encrypted timestamp 
(for 1426778442.525165): plain 
301AA011180F32303135303331393135323034325AA105020308036D, encrypted 
9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: Preauth module 
encrypted_timestamp (2) (flags=1) returned: 0/Success
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: Produced preauth for 
next request: 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: Sending request (238 
bytes) to EXAMPLE.CORP
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: Resolving hostname 
dct020.example.corp.
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: Sending initial UDP 
request to dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: Received answer from 
dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: Response was not from 
master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: Received error from 
KDC: -1765328360/Preauthentication failed
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: Preauth tryagain input 
types: 16, 14, 19, 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: Retrying AS request 
with master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: Getting initial 
credentials for bpr...@example.corp
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: Sending request (160 
bytes) to EXAMPLE.CORP (master)
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [get_and_save_tgt] 
(0x0020): 979: [-1765328360][Preauthentication failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [map_krb5_error] 
(0x0020): 1040: [-1765328360][Preauthentication failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [k5c_send_data] 
(0x0200): Received error code 1432158214
>>
>> If I do the same with 'KRB5_TRACE=/dev/stderr kinit bpr...@example.corp':
>> [12299] 1426773524.361785: AS key obtained for encrypted timestamp: 
aes256-cts/B997
>> [12299] 1426773524.361850: Encrypted timestamp (for 1426773524.277583): 
plain 301AA011180F32303135303331393133353834345AA1050203043C4F, encrypted 
ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
>> [12299] 1426773524.361876: Preauth module encrypted_timestamp (2) (flags=1) 
returned: 0/Success
>> [12299] 1426773524.361880: Produced preauth for next request: 2
>> [12299] 1426773524.361901: Sending request (238 bytes) to EXAMPLE.CORP
>> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
>> [12299] 1426773524.363841: Sending initial UDP request to dgram 
192.168.141.1:88
>> [12299] 1426773524.368089: Received answer from dgram 192.168.141.1:88
>> [12299] 1426773524.368482: Response was not from master KDC
>> [12299] 1426773524.368500: Received error from KDC: -1765328332/Response too 
big for UDP, retry with TCP
>> [12299] 1426773524.368506: Request or response is too big for UDP; retrying 
with TCP
>> [12299] 1426773524.368511: Sending request (238 bytes) to EXAMPLE.CORP (tcp 
only)
>> [12299] 1426773524.368953: Res

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-20 Thread Bobby Prins
>On Fri, 20 Mar 2015, Sumit Bose wrote:
>>On Fri, Mar 20, 2015 at 11:44:43AM +0100, Bobby Prins wrote:
>>> On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
>>> >> Hi there,
>>> >>
>>> >> I'm currently trying to use the 'AD Trust for Legacy Clients' freeIPA 
>>> >> setup (described here: 
>>> >> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf) to be 
>>> >> able to autenticate AIX 7.1 clients against an AD domain using LDAP. 
>>> >> After the trust was created all seems to work well on the freeIPA 
>>> >> server. I can also do a lookup of AD users and groups on an AIX test 
>>> >> server.
>>> >>
>>> >> But as soon as I want to log in on the AIX system I get an SSSD error on 
>>> >> the freeIPA server in krb5_child.log (debug_level = 10):
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS key 
>>> >> obtained for encrypted timestamp: aes256-cts/2F5D
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: Encrypted 
>>> >> timestamp (for 1426778442.525165): plain 
>>> >> 301AA011180F32303135303331393135323034325AA105020308036D, encrypted 
>>> >> 9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: Preauth 
>>> >> module encrypted_timestamp (2) (flags=1) returned: 0/Success
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: Produced 
>>> >> preauth for next request: 2
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: Sending 
>>> >> request (238 bytes) to EXAMPLE.CORP
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: Resolving 
>>> >> hostname dct020.example.corp.
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: Sending 
>>> >> initial UDP request to dgram 192.168.143.1:88
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: Received 
>>> >> answer from dgram 192.168.143.1:88
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: Response 
>>> >> was not from master KDC
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: Received 
>>> >> error from KDC: -1765328360/Preauthentication failed
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: Preauth 
>>> >> tryagain input types: 16, 14, 19, 2
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: Retrying 
>>> >> AS request with master KDC
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: Getting 
>>> >> initial credentials for bpr...@example.corp
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: Sending 
>>> >> request (160 bytes) to EXAMPLE.CORP (master)
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>>> >> [get_and_save_tgt] (0x0020): 979: [-1765328360][Preauthentication failed]
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [map_krb5_error] 
>>> >> (0x0020): 1040: [-1765328360][Preauthentication failed]
>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [k5c_send_data] 
>>> >> (0x0200): Received error code 1432158214
>>> >>
>>> >> If I do the same with 'KRB5_TRACE=/dev/stderr kinit bpr...@example.corp':
>>> >> [12299] 1426773524.361785: AS key obtained for encrypted timestamp: 
>>> >> aes256-cts/B997
>>> >> [12299] 1426773524.361850: Encrypted timestamp (for 1426773524.277583): 
>>> >> plain 301AA011180F32303135303331393133353834345AA1050203043C4F, 
>>> >> encrypted 
>>> >> ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
>>> >> [12299] 1426773524.361876: Preauth module encrypted_timestamp (2) 
>>> >> (flags=1) returned: 0/Success
>>> >> [12299] 1426773524.361880: Produced preauth for next request: 2
>>> >> [12299] 1426773524.361901: Sending request (238 bytes) to EXAMPLE.CORP
>>> >> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
>>> >> [12299] 1426773524.363841: Sending initial UDP request to dgram 
>>> >> 192.168.141.1:88
>>> >> [12299] 1426773524.368089: Received answer from d

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-20 Thread Alexander Bokovoy

On Fri, 20 Mar 2015, Sumit Bose wrote:

On Fri, Mar 20, 2015 at 11:44:43AM +0100, Bobby Prins wrote:

On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
>> Hi there,
>>
>> I'm currently trying to use the 'AD Trust for Legacy Clients' freeIPA setup 
(described here: http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf) to 
be able to autenticate AIX 7.1 clients against an AD domain using LDAP. After the 
trust was created all seems to work well on the freeIPA server. I can also do a 
lookup of AD users and groups on an AIX test server.
>>
>> But as soon as I want to log in on the AIX system I get an SSSD error on the 
freeIPA server in krb5_child.log (debug_level = 10):
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS key obtained for 
encrypted timestamp: aes256-cts/2F5D
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: Encrypted timestamp 
(for 1426778442.525165): plain 
301AA011180F32303135303331393135323034325AA105020308036D, encrypted 
9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: Preauth module 
encrypted_timestamp (2) (flags=1) returned: 0/Success
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: Produced preauth for 
next request: 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: Sending request (238 
bytes) to EXAMPLE.CORP
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: Resolving hostname 
dct020.example.corp.
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: Sending initial UDP 
request to dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: Received answer from 
dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: Response was not from 
master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: Received error from 
KDC: -1765328360/Preauthentication failed
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: Preauth tryagain input 
types: 16, 14, 19, 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: Retrying AS request 
with master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: Getting initial 
credentials for bpr...@example.corp
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: Sending request (160 
bytes) to EXAMPLE.CORP (master)
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [get_and_save_tgt] 
(0x0020): 979: [-1765328360][Preauthentication failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [map_krb5_error] 
(0x0020): 1040: [-1765328360][Preauthentication failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [k5c_send_data] 
(0x0200): Received error code 1432158214
>>
>> If I do the same with 'KRB5_TRACE=/dev/stderr kinit bpr...@example.corp':
>> [12299] 1426773524.361785: AS key obtained for encrypted timestamp: 
aes256-cts/B997
>> [12299] 1426773524.361850: Encrypted timestamp (for 1426773524.277583): 
plain 301AA011180F32303135303331393133353834345AA1050203043C4F, encrypted 
ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
>> [12299] 1426773524.361876: Preauth module encrypted_timestamp (2) (flags=1) 
returned: 0/Success
>> [12299] 1426773524.361880: Produced preauth for next request: 2
>> [12299] 1426773524.361901: Sending request (238 bytes) to EXAMPLE.CORP
>> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
>> [12299] 1426773524.363841: Sending initial UDP request to dgram 
192.168.141.1:88
>> [12299] 1426773524.368089: Received answer from dgram 192.168.141.1:88
>> [12299] 1426773524.368482: Response was not from master KDC
>> [12299] 1426773524.368500: Received error from KDC: -1765328332/Response too 
big for UDP, retry with TCP
>> [12299] 1426773524.368506: Request or response is too big for UDP; retrying 
with TCP
>> [12299] 1426773524.368511: Sending request (238 bytes) to EXAMPLE.CORP (tcp 
only)
>> [12299] 1426773524.368953: Resolving hostname dct030.EXAMPLE.corp.
>> [12299] 1426773

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-20 Thread Sumit Bose
On Fri, Mar 20, 2015 at 11:44:43AM +0100, Bobby Prins wrote:
> On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
> >> Hi there,
> >> 
> >> I'm currently trying to use the 'AD Trust for Legacy Clients' freeIPA 
> >> setup (described here: 
> >> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf) to be 
> >> able to autenticate AIX 7.1 clients against an AD domain using LDAP. After 
> >> the trust was created all seems to work well on the freeIPA server. I can 
> >> also do a lookup of AD users and groups on an AIX test server.
> >> 
> >> But as soon as I want to log in on the AIX system I get an SSSD error on 
> >> the freeIPA server in krb5_child.log (debug_level = 10):
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS key 
> >> obtained for encrypted timestamp: aes256-cts/2F5D
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: Encrypted 
> >> timestamp (for 1426778442.525165): plain 
> >> 301AA011180F32303135303331393135323034325AA105020308036D, encrypted 
> >> 9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: Preauth 
> >> module encrypted_timestamp (2) (flags=1) returned: 0/Success
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: Produced 
> >> preauth for next request: 2
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: Sending 
> >> request (238 bytes) to EXAMPLE.CORP
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: Resolving 
> >> hostname dct020.example.corp.
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: Sending 
> >> initial UDP request to dgram 192.168.143.1:88
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: Received 
> >> answer from dgram 192.168.143.1:88
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: Response 
> >> was not from master KDC
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: Received 
> >> error from KDC: -1765328360/Preauthentication failed
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: Preauth 
> >> tryagain input types: 16, 14, 19, 2
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: Retrying AS 
> >> request with master KDC
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: Getting 
> >> initial credentials for bpr...@example.corp
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> >> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: Sending 
> >> request (160 bytes) to EXAMPLE.CORP (master)
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [get_and_save_tgt] 
> >> (0x0020): 979: [-1765328360][Preauthentication failed]
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [map_krb5_error] 
> >> (0x0020): 1040: [-1765328360][Preauthentication failed]
> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [k5c_send_data] 
> >> (0x0200): Received error code 1432158214
> >> 
> >> If I do the same with 'KRB5_TRACE=/dev/stderr kinit bpr...@example.corp':
> >> [12299] 1426773524.361785: AS key obtained for encrypted timestamp: 
> >> aes256-cts/B997
> >> [12299] 1426773524.361850: Encrypted timestamp (for 1426773524.277583): 
> >> plain 301AA011180F32303135303331393133353834345AA1050203043C4F, encrypted 
> >> ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
> >> [12299] 1426773524.361876: Preauth module encrypted_timestamp (2) 
> >> (flags=1) returned: 0/Success
> >> [12299] 1426773524.361880: Produced preauth for next request: 2
> >> [12299] 1426773524.361901: Sending request (238 bytes) to EXAMPLE.CORP
> >> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
> >> [12299] 1426773524.363841: Sending initial UDP request to dgram 
> >> 192.168.141.1:88
> >> [12299] 1426773524.368089: Received answer from dgram 192.168.141.1:88
> >> [12299] 1426773524.368482: Response was not from master KDC
> >> [12299] 1426773524.368500: Received error from KDC: -1765328332/Response 
> >> too big for UDP, retry with TCP
> >> [

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-20 Thread Bobby Prins
On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
>> Hi there,
>> 
>> I'm currently trying to use the 'AD Trust for Legacy Clients' freeIPA setup 
>> (described here: 
>> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf) to be able 
>> to autenticate AIX 7.1 clients against an AD domain using LDAP. After the 
>> trust was created all seems to work well on the freeIPA server. I can also 
>> do a lookup of AD users and groups on an AIX test server.
>> 
>> But as soon as I want to log in on the AIX system I get an SSSD error on the 
>> freeIPA server in krb5_child.log (debug_level = 10):
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS key 
>> obtained for encrypted timestamp: aes256-cts/2F5D
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: Encrypted 
>> timestamp (for 1426778442.525165): plain 
>> 301AA011180F32303135303331393135323034325AA105020308036D, encrypted 
>> 9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: Preauth 
>> module encrypted_timestamp (2) (flags=1) returned: 0/Success
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: Produced 
>> preauth for next request: 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: Sending 
>> request (238 bytes) to EXAMPLE.CORP
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: Resolving 
>> hostname dct020.example.corp.
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: Sending 
>> initial UDP request to dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: Received 
>> answer from dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: Response was 
>> not from master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: Received 
>> error from KDC: -1765328360/Preauthentication failed
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: Preauth 
>> tryagain input types: 16, 14, 19, 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: Retrying AS 
>> request with master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: Getting 
>> initial credentials for bpr...@example.corp
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: Sending 
>> request (160 bytes) to EXAMPLE.CORP (master)
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [get_and_save_tgt] 
>> (0x0020): 979: [-1765328360][Preauthentication failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [map_krb5_error] 
>> (0x0020): 1040: [-1765328360][Preauthentication failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [k5c_send_data] 
>> (0x0200): Received error code 1432158214
>> 
>> If I do the same with 'KRB5_TRACE=/dev/stderr kinit bpr...@example.corp':
>> [12299] 1426773524.361785: AS key obtained for encrypted timestamp: 
>> aes256-cts/B997
>> [12299] 1426773524.361850: Encrypted timestamp (for 1426773524.277583): 
>> plain 301AA011180F32303135303331393133353834345AA1050203043C4F, encrypted 
>> ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
>> [12299] 1426773524.361876: Preauth module encrypted_timestamp (2) (flags=1) 
>> returned: 0/Success
>> [12299] 1426773524.361880: Produced preauth for next request: 2
>> [12299] 1426773524.361901: Sending request (238 bytes) to EXAMPLE.CORP
>> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
>> [12299] 1426773524.363841: Sending initial UDP request to dgram 
>> 192.168.141.1:88
>> [12299] 1426773524.368089: Received answer from dgram 192.168.141.1:88
>> [12299] 1426773524.368482: Response was not from master KDC
>> [12299] 1426773524.368500: Received error from KDC: -1765328332/Response too 
>> big for UDP, retry with TCP
>> [12299] 1426773524.368506: Request or response is too big for UDP; retrying 
>> with TCP
>> [12299] 1426773524.368511: Sending request (238 bytes) to EXAMPLE.CORP (tcp 
>> only)
>> [12299] 1426773524.368953: Resolving hostna

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-19 Thread Sumit Bose
On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
> Hi there,
> 
> I'm currently trying to use the 'AD Trust for Legacy Clients' freeIPA setup 
> (described here: 
> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf) to be able 
> to autenticate AIX 7.1 clients against an AD domain using LDAP. After the 
> trust was created all seems to work well on the freeIPA server. I can also do 
> a lookup of AD users and groups on an AIX test server.
> 
> But as soon as I want to log in on the AIX system I get an SSSD error on the 
> freeIPA server in krb5_child.log (debug_level = 10):
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS key 
> obtained for encrypted timestamp: aes256-cts/2F5D
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: Encrypted 
> timestamp (for 1426778442.525165): plain 
> 301AA011180F32303135303331393135323034325AA105020308036D, encrypted 
> 9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: Preauth module 
> encrypted_timestamp (2) (flags=1) returned: 0/Success
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: Produced 
> preauth for next request: 2
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: Sending 
> request (238 bytes) to EXAMPLE.CORP
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: Resolving 
> hostname dct020.example.corp.
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: Sending 
> initial UDP request to dgram 192.168.143.1:88
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: Received 
> answer from dgram 192.168.143.1:88
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: Response was 
> not from master KDC
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: Received error 
> from KDC: -1765328360/Preauthentication failed
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: Preauth 
> tryagain input types: 16, 14, 19, 2
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: Retrying AS 
> request with master KDC
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: Getting 
> initial credentials for bpr...@example.corp
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: Sending 
> request (160 bytes) to EXAMPLE.CORP (master)
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [get_and_save_tgt] 
> (0x0020): 979: [-1765328360][Preauthentication failed]
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [map_krb5_error] 
> (0x0020): 1040: [-1765328360][Preauthentication failed]
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [k5c_send_data] 
> (0x0200): Received error code 1432158214
> 
> If I do the same with 'KRB5_TRACE=/dev/stderr kinit bpr...@example.corp':
> [12299] 1426773524.361785: AS key obtained for encrypted timestamp: 
> aes256-cts/B997
> [12299] 1426773524.361850: Encrypted timestamp (for 1426773524.277583): plain 
> 301AA011180F32303135303331393133353834345AA1050203043C4F, encrypted 
> ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
> [12299] 1426773524.361876: Preauth module encrypted_timestamp (2) (flags=1) 
> returned: 0/Success
> [12299] 1426773524.361880: Produced preauth for next request: 2
> [12299] 1426773524.361901: Sending request (238 bytes) to EXAMPLE.CORP
> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
> [12299] 1426773524.363841: Sending initial UDP request to dgram 
> 192.168.141.1:88
> [12299] 1426773524.368089: Received answer from dgram 192.168.141.1:88
> [12299] 1426773524.368482: Response was not from master KDC
> [12299] 1426773524.368500: Received error from KDC: -1765328332/Response too 
> big for UDP, retry with TCP
> [12299] 1426773524.368506: Request or response is too big for UDP; retrying 
> with TCP
> [12299] 1426773524.368511: Sending request (238 bytes) to EXAMPLE.CORP (tcp 
> only)
> [12299] 1426773524.368953: Resolving hostname dct030.EXAMPLE.corp.
> [12299] 1426773524.370056: Initiating TCP connection to st

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-19 Thread Bobby Prins
On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
>> Hi there,
>> 
>> I'm currently trying to use the 'AD Trust for Legacy Clients' freeIPA setup 
>> (described here: 
>> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf) to be able 
>> to autenticate AIX 7.1 clients against an AD domain using LDAP. After the 
>> trust was created all seems to work well on the freeIPA server. I can also 
>> do a lookup of AD users and groups on an AIX test server.
>> 
>> But as soon as I want to log in on the AIX system I get an SSSD error on the 
>> freeIPA server in krb5_child.log (debug_level = 10):
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS key 
>> obtained for encrypted timestamp: aes256-cts/2F5D
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: Encrypted 
>> timestamp (for 1426778442.525165): plain 
>> 301AA011180F32303135303331393135323034325AA105020308036D, encrypted 
>> 9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: Preauth 
>> module encrypted_timestamp (2) (flags=1) returned: 0/Success
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: Produced 
>> preauth for next request: 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: Sending 
>> request (238 bytes) to EXAMPLE.CORP
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: Resolving 
>> hostname dct020.example.corp.
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: Sending 
>> initial UDP request to dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: Received 
>> answer from dgram 192.168.143.1:88
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: Response was 
>> not from master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: Received 
>> error from KDC: -1765328360/Preauthentication failed
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: Preauth 
>> tryagain input types: 16, 14, 19, 2
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: Retrying AS 
>> request with master KDC
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: Getting 
>> initial credentials for bpr...@example.corp
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: Sending 
>> request (160 bytes) to EXAMPLE.CORP (master)
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [get_and_save_tgt] 
>> (0x0020): 979: [-1765328360][Preauthentication failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [map_krb5_error] 
>> (0x0020): 1040: [-1765328360][Preauthentication failed]
>> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [k5c_send_data] 
>> (0x0200): Received error code 1432158214
>> 
>> If I do the same with 'KRB5_TRACE=/dev/stderr kinit bpr...@example.corp':
>
>Can you test if kinit -C -E makes any difference?

KRB5_TRACE=/dev/stderr kinit -C -E bpr...@example.corp output:
[12994] 1426781014.22372: Resolving unique ccache of type KEYRING
[12994] 1426781014.22420: Getting initial credentials for 
BPrins\@example.c...@unix.example.corp
[12994] 1426781014.24809: Sending request (182 bytes) to UNIX.EXAMPLE.CORP
[12994] 1426781014.25036: Sending initial UDP request to dgram 
192.168.140.133:88
[12994] 1426781014.26345: Received answer from dgram 192.168.140.133:88
[12994] 1426781014.26381: Response was from master KDC
[12994] 1426781014.26402: Received error from KDC: -1765328378/Client not found 
in Kerberos database
kinit: Client 'BPrins\@example.c...@unix.example.corp' not found in Kerberos 
database while getting initial credentials

>
>> [12299] 1426773524.361785: AS key obtained for encrypted timestamp: 
>> aes256-cts/B997
>> [12299] 1426773524.361850: Encrypted timestamp (for 1426773524.277583): 
>> plain 301AA011180F32303135303331393133353834345AA1050203043C4F, encrypted 
>> ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
>> [12299] 1426773524.361876: Preauth module encrypted_timestamp (2) (flags=1) 
>> ret

Re: [Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-19 Thread Jakub Hrozek
On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
> Hi there,
> 
> I'm currently trying to use the 'AD Trust for Legacy Clients' freeIPA setup 
> (described here: 
> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf) to be able 
> to autenticate AIX 7.1 clients against an AD domain using LDAP. After the 
> trust was created all seems to work well on the freeIPA server. I can also do 
> a lookup of AD users and groups on an AIX test server.
> 
> But as soon as I want to log in on the AIX system I get an SSSD error on the 
> freeIPA server in krb5_child.log (debug_level = 10):
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS key 
> obtained for encrypted timestamp: aes256-cts/2F5D
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: Encrypted 
> timestamp (for 1426778442.525165): plain 
> 301AA011180F32303135303331393135323034325AA105020308036D, encrypted 
> 9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: Preauth module 
> encrypted_timestamp (2) (flags=1) returned: 0/Success
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: Produced 
> preauth for next request: 2
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: Sending 
> request (238 bytes) to EXAMPLE.CORP
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: Resolving 
> hostname dct020.example.corp.
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: Sending 
> initial UDP request to dgram 192.168.143.1:88
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: Received 
> answer from dgram 192.168.143.1:88
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: Response was 
> not from master KDC
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: Received error 
> from KDC: -1765328360/Preauthentication failed
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: Preauth 
> tryagain input types: 16, 14, 19, 2
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: Retrying AS 
> request with master KDC
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: Getting 
> initial credentials for bpr...@example.corp
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: Sending 
> request (160 bytes) to EXAMPLE.CORP (master)
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [get_and_save_tgt] 
> (0x0020): 979: [-1765328360][Preauthentication failed]
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [map_krb5_error] 
> (0x0020): 1040: [-1765328360][Preauthentication failed]
> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [k5c_send_data] 
> (0x0200): Received error code 1432158214
> 
> If I do the same with 'KRB5_TRACE=/dev/stderr kinit bpr...@example.corp':

Can you test if kinit -C -E makes any difference?

> [12299] 1426773524.361785: AS key obtained for encrypted timestamp: 
> aes256-cts/B997
> [12299] 1426773524.361850: Encrypted timestamp (for 1426773524.277583): plain 
> 301AA011180F32303135303331393133353834345AA1050203043C4F, encrypted 
> ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
> [12299] 1426773524.361876: Preauth module encrypted_timestamp (2) (flags=1) 
> returned: 0/Success
> [12299] 1426773524.361880: Produced preauth for next request: 2
> [12299] 1426773524.361901: Sending request (238 bytes) to EXAMPLE.CORP
> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
> [12299] 1426773524.363841: Sending initial UDP request to dgram 
> 192.168.141.1:88
> [12299] 1426773524.368089: Received answer from dgram 192.168.141.1:88
> [12299] 1426773524.368482: Response was not from master KDC
> [12299] 1426773524.368500: Received error from KDC: -1765328332/Response too 
> big for UDP, retry with TCP
> [12299] 1426773524.368506: Request or response is too big for UDP; retrying 
> with TCP
> [12299] 1426773524.368511: Sending request (238 bytes) to EXAMPLE.CORP (tcp 
> only)
> [12299] 1426773524.368953: Resolving hostname dct030.EXAMPLE.corp.
> [12299

[Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

2015-03-19 Thread Bobby Prins
Hi there,

I'm currently trying to use the 'AD Trust for Legacy Clients' freeIPA setup 
(described here: 
http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf) to be able to 
autenticate AIX 7.1 clients against an AD domain using LDAP. After the trust 
was created all seems to work well on the freeIPA server. I can also do a 
lookup of AD users and groups on an AIX test server.

But as soon as I want to log in on the AIX system I get an SSSD error on the 
freeIPA server in krb5_child.log (debug_level = 10):
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS key obtained 
for encrypted timestamp: aes256-cts/2F5D
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: Encrypted 
timestamp (for 1426778442.525165): plain 
301AA011180F32303135303331393135323034325AA105020308036D, encrypted 
9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: Preauth module 
encrypted_timestamp (2) (flags=1) returned: 0/Success
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: Produced preauth 
for next request: 2
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: Sending request 
(238 bytes) to EXAMPLE.CORP
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: Resolving 
hostname dct020.example.corp.
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: Sending initial 
UDP request to dgram 192.168.143.1:88
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: Received answer 
from dgram 192.168.143.1:88
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: Response was not 
from master KDC
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: Received error 
from KDC: -1765328360/Preauthentication failed
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: Preauth tryagain 
input types: 16, 14, 19, 2
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: Retrying AS 
request with master KDC
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: Getting initial 
credentials for bpr...@example.corp
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 
[sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: Sending request 
(160 bytes) to EXAMPLE.CORP (master)
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [get_and_save_tgt] 
(0x0020): 979: [-1765328360][Preauthentication failed]
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [map_krb5_error] 
(0x0020): 1040: [-1765328360][Preauthentication failed]
(Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775 [k5c_send_data] 
(0x0200): Received error code 1432158214

If I do the same with 'KRB5_TRACE=/dev/stderr kinit bpr...@example.corp':
[12299] 1426773524.361785: AS key obtained for encrypted timestamp: 
aes256-cts/B997
[12299] 1426773524.361850: Encrypted timestamp (for 1426773524.277583): plain 
301AA011180F32303135303331393133353834345AA1050203043C4F, encrypted 
ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
[12299] 1426773524.361876: Preauth module encrypted_timestamp (2) (flags=1) 
returned: 0/Success
[12299] 1426773524.361880: Produced preauth for next request: 2
[12299] 1426773524.361901: Sending request (238 bytes) to EXAMPLE.CORP
[12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
[12299] 1426773524.363841: Sending initial UDP request to dgram 192.168.141.1:88
[12299] 1426773524.368089: Received answer from dgram 192.168.141.1:88
[12299] 1426773524.368482: Response was not from master KDC
[12299] 1426773524.368500: Received error from KDC: -1765328332/Response too 
big for UDP, retry with TCP
[12299] 1426773524.368506: Request or response is too big for UDP; retrying 
with TCP
[12299] 1426773524.368511: Sending request (238 bytes) to EXAMPLE.CORP (tcp 
only)
[12299] 1426773524.368953: Resolving hostname dct030.EXAMPLE.corp.
[12299] 1426773524.370056: Initiating TCP connection to stream 192.168.143.5:88
[12299] 1426773524.375140: Sending TCP request to stream 192.168.143.5:88
[12299] 1426773524.383801: Received answer from stream 192.168.143.5:88
[12299] 1426773524.384237: Response was not from master KDC
[122