Re: [Freeipa-users] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-08 Thread Simo Sorce
On Wed, 2015-04-08 at 10:11 +0200, Martin (Lists) wrote:
> Am 07.04.2015 um 18:27 schrieb Simo Sorce:
> > On Tue, 2015-04-07 at 17:57 +0200, Martin (Lists) wrote:
> >> Hallo
> >>
> >> attached you can find the data from krb_child.log. As far as I can see
> >> it, the three seconds are due to the communication with the kerberos
> >> server. (1.2.3.4 is my server).
> > 
> > Do you experience the same latency if you kinit manually ?
> > 
> > Simo.
> > 
> 
> No, kinit completes almost instantly after entering the password.

Any chance you can take a network trace when authenticating via sssd and
when authenticating via kinit ? It would be nice to see what differs
there and what operation exactly is taking longer.
Looking at the server krb5kdc.log may also shed some light.

Simo.

-- 
Simo Sorce * Red Hat, Inc * New York

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-08 Thread Martin (Lists)
Am 08.04.2015 um 10:57 schrieb Jakub Hrozek:
>  
> >
> >
> > Most of the host can only communicate in the local net, which has not
> > that much hosts (10). The wired ones are connected via GBit Network,
> > wireless it is up to 150MBit. Server is a Xeon E3-1225 with 8GB Mem. All
> > Systems have Fedora 21 installed
>
> Does it communicate with the same KDC as krb5_child?
>
Yep, same host, same port number. Currently I have only one IPA server
running. Replication is on my todo list though.

Martin

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-08 Thread Jakub Hrozek
On Wed, Apr 08, 2015 at 10:43:10AM +0200, Martin (Lists) wrote:
> Am 08.04.2015 um 10:27 schrieb Jakub Hrozek:
> > Can you run:
> > KRB5_TRACE=/dev/stderr kinit yourprinc@YOUR.REALM
> >
> > So that we can compare with the krb5_child.log you sent earlier? I
> > wonder if SSSD talks to a KDC that is slower or far away from your
> > client..
> >
> This is my trace from kinit:
> 
> [2422] 1428482081.62208: AS key obtained for encrypted timestamp:
> aes256-cts/61D1
> [2422] 1428482081.62288: Encrypted timestamp (for 1428482081.868994):
> plain ***, encrypted ***
> [2422] 1428482081.62328: Preauth module encrypted_timestamp (2) (real)
> returned: 0/Success
> [2422] 1428482081.62342: Produced preauth for next request: 133, 2
> [2422] 1428482081.62379: Sending request (265 bytes) to MITTELERDE.DE
> [2422] 1428482081.62484: Sending initial UDP request to dgram 1.2.3.4:88
> [2422] 1428482081.201814: Received answer (740 bytes) from dgram 1.2.3.4:88
> [2422] 1428482081.201872: Response was from master KDC
> [2422] 1428482081.201905: Processing preauth types: 19
> [2422] 1428482081.201914: Selected etype info: etype aes256-cts, salt
> "***", params ""
> [2422] 1428482081.201920: Produced preauth for next request: (empty)
> [2422] 1428482081.201929: AS key determined by preauth: aes256-cts/61D1
> [2422] 1428482081.201973: Decrypted AS reply; session key is:
> aes256-cts/C464
> [2422] 1428482081.201991: FAST negotiation: available
> [2422] 1428482081.202014: Initializing KEYRING:persistent:0:0 with
> default princ fr...@mittelerde.de
> [2422] 1428482081.202058: Removing fr...@mittelerde.de ->
> krbtgt/mittelerde...@mittelerde.de from KEYRING:persistent:0:0
> [2422] 1428482081.202065: Storing fr...@mittelerde.de ->
> krbtgt/mittelerde...@mittelerde.de in KEYRING:persistent:0:0
> [2422] 1428482081.202110: Storing config in KEYRING:persistent:0:0 for
> krbtgt/mittelerde...@mittelerde.de: fast_avail: yes
> [2422] 1428482081.202126: Removing fr...@mittelerde.de ->
> krb5_ccache_conf_data/fast_avail/krbtgt\/MITTELERDE.DE\@MITTELERDE.DE@X-CACHECONF:
> from KEYRING:persistent:0:0
> [2422] 1428482081.202133: Storing fr...@mittelerde.de ->
> krb5_ccache_conf_data/fast_avail/krbtgt\/MITTELERDE.DE\@MITTELERDE.DE@X-CACHECONF:
> in KEYRING:persistent:0:0
> [2422] 1428482081.202166: Storing config in KEYRING:persistent:0:0 for
> krbtgt/mittelerde...@mittelerde.de: pa_type: 2
> [2422] 1428482081.202177: Removing fr...@mittelerde.de ->
> krb5_ccache_conf_data/pa_type/krbtgt\/MITTELERDE.DE\@MITTELERDE.DE@X-CACHECONF:
> from
> KEYRING:persistent:0:0
>   
>
> 
> [2422] 1428482081.202184: Storing fr...@mittelerde.de ->
> krb5_ccache_conf_data/pa_type/krbtgt\/MITTELERDE.DE\@MITTELERDE.DE@X-CACHECONF:
> in
> KEYRING:persistent:0:0
>   
>   
> 
> 
> Most of the host can only communicate in the local net, which has not
> that much hosts (10). The wired ones are connected via GBit Network,
> wireless it is up to 150MBit. Server is a Xeon E3-1225 with 8GB Mem. All
> Systems have Fedora 21 installed

Does it communicate with the same KDC as krb5_child?

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-08 Thread Martin (Lists)
Am 08.04.2015 um 10:27 schrieb Jakub Hrozek:
> Can you run:
> KRB5_TRACE=/dev/stderr kinit yourprinc@YOUR.REALM
>
> So that we can compare with the krb5_child.log you sent earlier? I
> wonder if SSSD talks to a KDC that is slower or far away from your
> client..
>
This is my trace from kinit:

[2422] 1428482081.62208: AS key obtained for encrypted timestamp:
aes256-cts/61D1
[2422] 1428482081.62288: Encrypted timestamp (for 1428482081.868994):
plain ***, encrypted ***
[2422] 1428482081.62328: Preauth module encrypted_timestamp (2) (real)
returned: 0/Success
[2422] 1428482081.62342: Produced preauth for next request: 133, 2
[2422] 1428482081.62379: Sending request (265 bytes) to MITTELERDE.DE
[2422] 1428482081.62484: Sending initial UDP request to dgram 1.2.3.4:88
[2422] 1428482081.201814: Received answer (740 bytes) from dgram 1.2.3.4:88
[2422] 1428482081.201872: Response was from master KDC
[2422] 1428482081.201905: Processing preauth types: 19
[2422] 1428482081.201914: Selected etype info: etype aes256-cts, salt
"***", params ""
[2422] 1428482081.201920: Produced preauth for next request: (empty)
[2422] 1428482081.201929: AS key determined by preauth: aes256-cts/61D1
[2422] 1428482081.201973: Decrypted AS reply; session key is:
aes256-cts/C464
[2422] 1428482081.201991: FAST negotiation: available
[2422] 1428482081.202014: Initializing KEYRING:persistent:0:0 with
default princ fr...@mittelerde.de
[2422] 1428482081.202058: Removing fr...@mittelerde.de ->
krbtgt/mittelerde...@mittelerde.de from KEYRING:persistent:0:0
[2422] 1428482081.202065: Storing fr...@mittelerde.de ->
krbtgt/mittelerde...@mittelerde.de in KEYRING:persistent:0:0
[2422] 1428482081.202110: Storing config in KEYRING:persistent:0:0 for
krbtgt/mittelerde...@mittelerde.de: fast_avail: yes
[2422] 1428482081.202126: Removing fr...@mittelerde.de ->
krb5_ccache_conf_data/fast_avail/krbtgt\/MITTELERDE.DE\@MITTELERDE.DE@X-CACHECONF:
from KEYRING:persistent:0:0
[2422] 1428482081.202133: Storing fr...@mittelerde.de ->
krb5_ccache_conf_data/fast_avail/krbtgt\/MITTELERDE.DE\@MITTELERDE.DE@X-CACHECONF:
in KEYRING:persistent:0:0
[2422] 1428482081.202166: Storing config in KEYRING:persistent:0:0 for
krbtgt/mittelerde...@mittelerde.de: pa_type: 2
[2422] 1428482081.202177: Removing fr...@mittelerde.de ->
krb5_ccache_conf_data/pa_type/krbtgt\/MITTELERDE.DE\@MITTELERDE.DE@X-CACHECONF:
from
KEYRING:persistent:0:0  

   

[2422] 1428482081.202184: Storing fr...@mittelerde.de ->
krb5_ccache_conf_data/pa_type/krbtgt\/MITTELERDE.DE\@MITTELERDE.DE@X-CACHECONF:
in
KEYRING:persistent:0:0  

  


Most of the host can only communicate in the local net, which has not
that much hosts (10). The wired ones are connected via GBit Network,
wireless it is up to 150MBit. Server is a Xeon E3-1225 with 8GB Mem. All
Systems have Fedora 21 installed

Martin.

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-08 Thread Jakub Hrozek
On Wed, Apr 08, 2015 at 10:11:01AM +0200, Martin (Lists) wrote:
> Am 07.04.2015 um 18:27 schrieb Simo Sorce:
> > On Tue, 2015-04-07 at 17:57 +0200, Martin (Lists) wrote:
> >> Hallo
> >>
> >> attached you can find the data from krb_child.log. As far as I can see
> >> it, the three seconds are due to the communication with the kerberos
> >> server. (1.2.3.4 is my server).
> > 
> > Do you experience the same latency if you kinit manually ?
> > 
> > Simo.
> > 
> 
> No, kinit completes almost instantly after entering the password.
> 
> Martin

Can you run:
KRB5_TRACE=/dev/stderr kinit yourprinc@YOUR.REALM

So that we can compare with the krb5_child.log you sent earlier? I
wonder if SSSD talks to a KDC that is slower or far away from your
client..

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-08 Thread Martin (Lists)
Am 07.04.2015 um 18:27 schrieb Simo Sorce:
> On Tue, 2015-04-07 at 17:57 +0200, Martin (Lists) wrote:
>> Hallo
>>
>> attached you can find the data from krb_child.log. As far as I can see
>> it, the three seconds are due to the communication with the kerberos
>> server. (1.2.3.4 is my server).
> 
> Do you experience the same latency if you kinit manually ?
> 
> Simo.
> 

No, kinit completes almost instantly after entering the password.

Martin

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-07 Thread Jakub Hrozek
On Tue, Apr 07, 2015 at 01:15:46PM -0500, Dan Mossor wrote:
> On 04/07/2015 03:05 AM, Jakub Hrozek wrote:
> >On Mon, Apr 06, 2015 at 08:01:46PM -0500, Dan Mossor wrote:
> >>On 04/05/2015 12:51 PM, Dmitri Pal wrote:
> >>>Several tips.
> >>>Please check your DNS configuration.
> >>>Such delay is usually caused by the DNS lookups timing out. That means
> >>>that the servers probably trying to resolve names against an old DNS
> >>>server that is not around. Look at resolve.conf and make sure only valid
> >>>DNS servers are there and they are in the proper order.
> >>>
> >>>If this does not help please turn on SSSD debug_level to 10, sanitize
> >>>and send the SSSD domain logs and sssd.conf to the list.
> >>>More hints can be found here:
> >>>https://fedorahosted.org/sssd/wiki/Troubleshooting
> >>>
> >>DNS lookups are good - 'dig' and 'dig -x' return instantaneous forward and
> >>reverse lookups on the IPA server, the target server, and the client. The
> >>only DNS server configured is the IPA server.
> >>
> >>I did catch some sssd logs. I set logging to 0x0450 instead of 10, and I
> >>didn't have time to compare if any different information was caught. If you
> >>still need me to specify log level 10 or some other setting, let me know.
> >>The login that these logs are for took 15.371 seconds (checked via 'time ssh
> >>danofs...@yoda.example.lcl exit'
> >>
> >>selinux_child.log: http://fpaste.org/207805/
> >>sssd_sudo.log: http://fpaste.org/207806/
> >>sssd_pac.log: http://fpaste.org/207807/
> >>sssd_pam.log: http://fpaste.org/207808/67775142/
> >>sssd_nss.log: http://fpaste.org/207809/
> >>sssd.log: http://fpaste.org/207810/
> >>sssd_example.lcl.log: http://fpaste.org/207811/36832514/
> >
> >We've recently found a performance problem in the SELinux code. Can you
> >check if setting:
> > selinux_provider = none
> >improves the performance anyhow?
> >
> 
> Adding "selinux_provider = none" to the domain section of
> /etc/sssd/sssd.conf seems to have drastically improved ssh logins. The
> Apache authentications are faster, but we're still hitting a performance
> issue somewhere in that chain. It may be with Apache itself, so stand
> by...but otherwise, I'm calling this fixed.

Not fixed, merely worked around.

> 
> Thanks!

Thank you for confirming the problem and the workaround. I do have a WIP
patch, I "just" need to finish testing it.

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-07 Thread Dan Mossor

On 04/07/2015 03:05 AM, Jakub Hrozek wrote:

On Mon, Apr 06, 2015 at 08:01:46PM -0500, Dan Mossor wrote:

On 04/05/2015 12:51 PM, Dmitri Pal wrote:

Several tips.
Please check your DNS configuration.
Such delay is usually caused by the DNS lookups timing out. That means
that the servers probably trying to resolve names against an old DNS
server that is not around. Look at resolve.conf and make sure only valid
DNS servers are there and they are in the proper order.

If this does not help please turn on SSSD debug_level to 10, sanitize
and send the SSSD domain logs and sssd.conf to the list.
More hints can be found here:
https://fedorahosted.org/sssd/wiki/Troubleshooting


DNS lookups are good - 'dig' and 'dig -x' return instantaneous forward and
reverse lookups on the IPA server, the target server, and the client. The
only DNS server configured is the IPA server.

I did catch some sssd logs. I set logging to 0x0450 instead of 10, and I
didn't have time to compare if any different information was caught. If you
still need me to specify log level 10 or some other setting, let me know.
The login that these logs are for took 15.371 seconds (checked via 'time ssh
danofs...@yoda.example.lcl exit'

selinux_child.log: http://fpaste.org/207805/
sssd_sudo.log: http://fpaste.org/207806/
sssd_pac.log: http://fpaste.org/207807/
sssd_pam.log: http://fpaste.org/207808/67775142/
sssd_nss.log: http://fpaste.org/207809/
sssd.log: http://fpaste.org/207810/
sssd_example.lcl.log: http://fpaste.org/207811/36832514/


We've recently found a performance problem in the SELinux code. Can you
check if setting:
 selinux_provider = none
improves the performance anyhow?



Adding "selinux_provider = none" to the domain section of 
/etc/sssd/sssd.conf seems to have drastically improved ssh logins. The 
Apache authentications are faster, but we're still hitting a performance 
issue somewhere in that chain. It may be with Apache itself, so stand 
by...but otherwise, I'm calling this fixed.


Thanks!

--
Dan Mossor
Systems Engineer at Large
Fedora KDE WG | Fedora QA Team | Fedora Server SIG
Fedora Infrastructure Apprentice
FAS: dmossor IRC: danofsatx
San Antonio, Texas, USA

--
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-07 Thread Simo Sorce
On Tue, 2015-04-07 at 17:57 +0200, Martin (Lists) wrote:
> Hallo
> 
> attached you can find the data from krb_child.log. As far as I can see
> it, the three seconds are due to the communication with the kerberos
> server. (1.2.3.4 is my server).

Do you experience the same latency if you kinit manually ?

Simo.

-- 
Simo Sorce * Red Hat, Inc * New York

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-07 Thread Jakub Hrozek
On Tue, Apr 07, 2015 at 05:57:49PM +0200, Martin (Lists) wrote:
> Hallo
> 
> attached you can find the data from krb_child.log. As far as I can see
> it, the three seconds are due to the communication with the kerberos
> server. (1.2.3.4 is my server).
> 
> regards
> Martin

Yes. It looks like kinit takes two seconds and validation one second.
You might be interested in:
https://fedorahosted.org/sssd/ticket/1807

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-07 Thread Martin (Lists)
Hallo

attached you can find the data from krb_child.log. As far as I can see
it, the three seconds are due to the communication with the kerberos
server. (1.2.3.4 is my server).

regards
Martin

Am 07.04.2015 um 11:21 schrieb Jakub Hrozek:
> On Tue, Apr 07, 2015 at 11:12:40AM +0200, Martin (Lists) wrote:
> > Am 05.04.2015 um 11:51 schrieb Martin (Lists):
> >>
> >> Hallo
> >>
> >> I have a similar issue. On login (graphic systems and ssh) and on the
> >> screen saver I have a delay from about 2 secons to 10 seconds.
> >>
> >> According to my logfile i have the following timeline at login:
> >>
> >> 0pam_unix (auth)
> >> 3pam_sss (auth)
> >> 3pam_kwallet (sddm:auth)
> >> 4pam_kwallet (sddm:setcred)
> >> 5pam_unix (session)
> >>
> >> First collum is the number of seconds after the first action. On
> myl old
> >> server I had a pure kerberos (handmade) system, which reacted almost
> >> instandly.
> >>
> >> Regards
> >> Martin
> >>
> > Hallo
> >
> > I enabled debugging (set to level 6). selinux provider is set to none.
> > During a login I got data accorting to my attachment.
> >
> > Regards
> > Martin
>
> If that's all the data, then the login seems quite fast (3 seconds).
> The slowdown seems to happen when the krb5 provider is initializing the
> krb5 ccache for the user. krb5_child.log with a high debug level would
> show what's happening in particular.
>
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [be_req_set_domain] (0x0400): Changing request domain from
> [mittelerde.de] to [mittelerde.de]
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [be_pam_handler] (0x0100): Got request with the following data
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): domain: mittelerde.de
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): user: frodo
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): service: sddm
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): tty:
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): ruser:
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): rhost:
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): authtok type: 1
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): newauthtok type: 0
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): priv: 1
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): cli_pid: 6409
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): logon name: not set
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [be_resolve_server_process] (0x0200): Found address for server
> gandalf.mittelerde.de: [10.2.33.5] TTL 1200
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [ipa_resolve_callback] (0x0400): Constructed uri
> 'ldap://gandalf.mittelerde.de'
> > (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]]
> [write_pipe_handler] (0x0400): All data has been sent!
>
> Here we sent data to krb5_child
>
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [child_sig_handler] (0x0100): child [6410] finished successfully.
>
> Here the krb5_child process finished
>
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [read_pipe_handler] (0x0400): EOF received, client finished
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [fo_set_port_status] (0x0100): Marking port 0 of server
> 'gandalf.mittelerde.de' as 'working'
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [set_server_common_status] (0x0100): Marking server
> 'gandalf.mittelerde.de' as 'working'
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [fo_set_port_status] (0x0400): Marking port 0 of duplicate server
> 'gandalf.mittelerde.de' as 'working'
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, )
> [Success]
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [be_pam_handler_callback] (0x0100): Sending result [0][mittelerde.de]
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [be_pam_handler_callback] (0x0100): Sent result [0][mittelerde.de]
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [be_req_set_domain] (0x0400): Changing request domain from
> [mittelerde.de] to [mittelerde.de]
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [be_pam_handler] (0x0100): Got request with the following data
> > (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]]
> [pam_print_data] (0x0100): command: PAM_ACCT_MGMT
> > (

Re: [Freeipa-users] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-07 Thread Jakub Hrozek
On Tue, Apr 07, 2015 at 11:12:40AM +0200, Martin (Lists) wrote:
> Am 05.04.2015 um 11:51 schrieb Martin (Lists):
> > 
> > Hallo
> > 
> > I have a similar issue. On login (graphic systems and ssh) and on the
> > screen saver I have a delay from about 2 secons to 10 seconds.
> > 
> > According to my logfile i have the following timeline at login:
> > 
> > 0   pam_unix (auth)
> > 3   pam_sss (auth)
> > 3   pam_kwallet (sddm:auth)
> > 4   pam_kwallet (sddm:setcred)
> > 5   pam_unix (session)
> > 
> > First collum is the number of seconds after the first action. On myl old
> > server I had a pure kerberos (handmade) system, which reacted almost
> > instandly.
> > 
> > Regards
> > Martin
> > 
> Hallo
> 
> I enabled debugging (set to level 6). selinux provider is set to none.
> During a login I got data accorting to my attachment.
> 
> Regards
> Martin

If that's all the data, then the login seems quite fast (3 seconds).
The slowdown seems to happen when the krb5 provider is initializing the
krb5 ccache for the user. krb5_child.log with a high debug level would
show what's happening in particular.

> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [be_req_set_domain] 
> (0x0400): Changing request domain from [mittelerde.de] to [mittelerde.de]
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [be_pam_handler] 
> (0x0100): Got request with the following data
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): command: PAM_AUTHENTICATE
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): domain: mittelerde.de
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): user: frodo
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): service: sddm
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): tty:
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): ruser:
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): rhost:
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): authtok type: 1
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): newauthtok type: 0
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): priv: 1
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): cli_pid: 6409
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): logon name: not set
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] 
> [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] 
> [be_resolve_server_process] (0x0200): Found address for server 
> gandalf.mittelerde.de: [10.2.33.5] TTL 1200
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [ipa_resolve_callback] 
> (0x0400): Constructed uri 'ldap://gandalf.mittelerde.de'
> (Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [write_pipe_handler] 
> (0x0400): All data has been sent!

Here we sent data to krb5_child

> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [child_sig_handler] 
> (0x0100): child [6410] finished successfully.

Here the krb5_child process finished

> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [read_pipe_handler] 
> (0x0400): EOF received, client finished
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [fo_set_port_status] 
> (0x0100): Marking port 0 of server 'gandalf.mittelerde.de' as 'working'
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] 
> [set_server_common_status] (0x0100): Marking server 'gandalf.mittelerde.de' 
> as 'working'
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [fo_set_port_status] 
> (0x0400): Marking port 0 of duplicate server 'gandalf.mittelerde.de' as 
> 'working'
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] 
> [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, ) [Success]
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] 
> [be_pam_handler_callback] (0x0100): Sending result [0][mittelerde.de]
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] 
> [be_pam_handler_callback] (0x0100): Sent result [0][mittelerde.de]
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [be_req_set_domain] 
> (0x0400): Changing request domain from [mittelerde.de] to [mittelerde.de]
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [be_pam_handler] 
> (0x0100): Got request with the following data
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): command: PAM_ACCT_MGMT
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): domain: mittelerde.de
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): user: frodo
> (Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] 
> (0x0100): service: sddm
> (Tue Apr  7 10:52:41 2015) [sssd

Re: [Freeipa-users] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-07 Thread Martin (Lists)
Am 05.04.2015 um 11:51 schrieb Martin (Lists):
> 
> Hallo
> 
> I have a similar issue. On login (graphic systems and ssh) and on the
> screen saver I have a delay from about 2 secons to 10 seconds.
> 
> According to my logfile i have the following timeline at login:
> 
> 0 pam_unix (auth)
> 3 pam_sss (auth)
> 3 pam_kwallet (sddm:auth)
> 4 pam_kwallet (sddm:setcred)
> 5 pam_unix (session)
> 
> First collum is the number of seconds after the first action. On myl old
> server I had a pure kerberos (handmade) system, which reacted almost
> instandly.
> 
> Regards
> Martin
> 
Hallo

I enabled debugging (set to level 6). selinux provider is set to none.
During a login I got data accorting to my attachment.

Regards
Martin
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [be_req_set_domain] (0x0400): Changing request domain from [mittelerde.de] to [mittelerde.de]
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [be_pam_handler] (0x0100): Got request with the following data
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): domain: mittelerde.de
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): user: frodo
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): service: sddm
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): tty:
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): ruser:
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): rhost:
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): authtok type: 1
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): newauthtok type: 0
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): priv: 1
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): cli_pid: 6409
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): logon name: not set
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [be_resolve_server_process] (0x0200): Found address for server gandalf.mittelerde.de: [10.2.33.5] TTL 1200
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://gandalf.mittelerde.de'
(Tue Apr  7 10:52:38 2015) [sssd[be[mittelerde.de]]] [write_pipe_handler] (0x0400): All data has been sent!
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [child_sig_handler] (0x0100): child [6410] finished successfully.
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [read_pipe_handler] (0x0400): EOF received, client finished
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'gandalf.mittelerde.de' as 'working'
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [set_server_common_status] (0x0100): Marking server 'gandalf.mittelerde.de' as 'working'
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'gandalf.mittelerde.de' as 'working'
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, ) [Success]
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [be_pam_handler_callback] (0x0100): Sending result [0][mittelerde.de]
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [be_pam_handler_callback] (0x0100): Sent result [0][mittelerde.de]
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [be_req_set_domain] (0x0400): Changing request domain from [mittelerde.de] to [mittelerde.de]
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [be_pam_handler] (0x0100): Got request with the following data
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): domain: mittelerde.de
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): user: frodo
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): service: sddm
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): tty:
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): ruser:
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): rhost:
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): authtok type: 0
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): newauthtok type: 0
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): priv: 1
(Tue Apr  7 10:52:41 2015) [sssd[be[mittelerde.de]]] [pam_print_data] (0x0100): cli_pid: 6409
(Tu

Re: [Freeipa-users] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-07 Thread Jakub Hrozek
On Mon, Apr 06, 2015 at 08:01:46PM -0500, Dan Mossor wrote:
> On 04/05/2015 12:51 PM, Dmitri Pal wrote:
> >On 04/05/2015 12:10 AM, Dan Mossor wrote:
> >>I've recently deployed a new domain based on 4.1.2 in F21. We've
> >>noticed an issue and can't quite seem to nail it down. The problem is
> >>that logins are taking an inordinate amount of time to complete - the
> >>fastest logon we can get using LDAP credentials is 8 seconds. During
> >>our testing, even logons to the IPA server itself took over 30 seconds
> >>to complete.
> >>
> >>I've narrowed this down to sssd, but that is as far as I can get. When
> >>cranking up debugging for sshd and PAM, I see a minimum 2 second delay
> >>between ssh handing off the authentication request to sssd and the
> >>reply back. The only troubleshooting I've done is with ssh, but the
> >>area that causes the most grief is Apache logins. We configured Apache
> >>to use PAM for auth through IPA, vice directly calling IPA itself.
> >>Logging in to our Redmine site takes users a minimum of 34 seconds to
> >>complete. Following this, a simple webpage containing two hyperlinks
> >>and two small thumbnail images takes over a minute to load on a
> >>gigabit network.
> >>
> >>The *only* thing changed in this environment was the IPA server. We
> >>moved the Redmine from our old network that was using IPA 3.x (F20
> >>branch) to the new one. My initial reaction was that it was the VM
> >>that was hosting Redmine, but we've run these tests against bare metal
> >>machines in the same network and have the same issue. It appears that
> >>sssd is taking a very, very long time to talk to FreeIPA - even on the
> >>IPA server itself.
> >>
> >>However, Kerberos logins into the IPA web GUI are near instantaneous,
> >>while Username/Password logins take more than a few seconds.
> >>
> >>I need to get this solved. My developers don't appreciate the glory
> >>days of XP taking 5 minutes to log into an IIS 2.1 web server on the
> >>local network. I don't have the budget to keep them at the coffee pot
> >>waiting on the network. So, what further information do you need from
> >>me to track this one down?
> >>
> >>Dan
> >>
> >Several tips.
> >Please check your DNS configuration.
> >Such delay is usually caused by the DNS lookups timing out. That means
> >that the servers probably trying to resolve names against an old DNS
> >server that is not around. Look at resolve.conf and make sure only valid
> >DNS servers are there and they are in the proper order.
> >
> >If this does not help please turn on SSSD debug_level to 10, sanitize
> >and send the SSSD domain logs and sssd.conf to the list.
> >More hints can be found here:
> >https://fedorahosted.org/sssd/wiki/Troubleshooting
> >
> DNS lookups are good - 'dig' and 'dig -x' return instantaneous forward and
> reverse lookups on the IPA server, the target server, and the client. The
> only DNS server configured is the IPA server.
> 
> I did catch some sssd logs. I set logging to 0x0450 instead of 10, and I
> didn't have time to compare if any different information was caught. If you
> still need me to specify log level 10 or some other setting, let me know.
> The login that these logs are for took 15.371 seconds (checked via 'time ssh
> danofs...@yoda.example.lcl exit'
> 
> selinux_child.log: http://fpaste.org/207805/
> sssd_sudo.log: http://fpaste.org/207806/
> sssd_pac.log: http://fpaste.org/207807/
> sssd_pam.log: http://fpaste.org/207808/67775142/
> sssd_nss.log: http://fpaste.org/207809/
> sssd.log: http://fpaste.org/207810/
> sssd_example.lcl.log: http://fpaste.org/207811/36832514/

We've recently found a performance problem in the SELinux code. Can you
check if setting:
selinux_provider = none
improves the performance anyhow?

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-06 Thread Dan Mossor

On 04/05/2015 12:51 PM, Dmitri Pal wrote:

On 04/05/2015 12:10 AM, Dan Mossor wrote:

I've recently deployed a new domain based on 4.1.2 in F21. We've
noticed an issue and can't quite seem to nail it down. The problem is
that logins are taking an inordinate amount of time to complete - the
fastest logon we can get using LDAP credentials is 8 seconds. During
our testing, even logons to the IPA server itself took over 30 seconds
to complete.

I've narrowed this down to sssd, but that is as far as I can get. When
cranking up debugging for sshd and PAM, I see a minimum 2 second delay
between ssh handing off the authentication request to sssd and the
reply back. The only troubleshooting I've done is with ssh, but the
area that causes the most grief is Apache logins. We configured Apache
to use PAM for auth through IPA, vice directly calling IPA itself.
Logging in to our Redmine site takes users a minimum of 34 seconds to
complete. Following this, a simple webpage containing two hyperlinks
and two small thumbnail images takes over a minute to load on a
gigabit network.

The *only* thing changed in this environment was the IPA server. We
moved the Redmine from our old network that was using IPA 3.x (F20
branch) to the new one. My initial reaction was that it was the VM
that was hosting Redmine, but we've run these tests against bare metal
machines in the same network and have the same issue. It appears that
sssd is taking a very, very long time to talk to FreeIPA - even on the
IPA server itself.

However, Kerberos logins into the IPA web GUI are near instantaneous,
while Username/Password logins take more than a few seconds.

I need to get this solved. My developers don't appreciate the glory
days of XP taking 5 minutes to log into an IIS 2.1 web server on the
local network. I don't have the budget to keep them at the coffee pot
waiting on the network. So, what further information do you need from
me to track this one down?

Dan


Several tips.
Please check your DNS configuration.
Such delay is usually caused by the DNS lookups timing out. That means
that the servers probably trying to resolve names against an old DNS
server that is not around. Look at resolve.conf and make sure only valid
DNS servers are there and they are in the proper order.

If this does not help please turn on SSSD debug_level to 10, sanitize
and send the SSSD domain logs and sssd.conf to the list.
More hints can be found here:
https://fedorahosted.org/sssd/wiki/Troubleshooting

DNS lookups are good - 'dig' and 'dig -x' return instantaneous forward 
and reverse lookups on the IPA server, the target server, and the 
client. The only DNS server configured is the IPA server.


I did catch some sssd logs. I set logging to 0x0450 instead of 10, and I 
didn't have time to compare if any different information was caught. If 
you still need me to specify log level 10 or some other setting, let me 
know. The login that these logs are for took 15.371 seconds (checked via 
'time ssh danofs...@yoda.example.lcl exit'


selinux_child.log: http://fpaste.org/207805/
sssd_sudo.log: http://fpaste.org/207806/
sssd_pac.log: http://fpaste.org/207807/
sssd_pam.log: http://fpaste.org/207808/67775142/
sssd_nss.log: http://fpaste.org/207809/
sssd.log: http://fpaste.org/207810/
sssd_example.lcl.log: http://fpaste.org/207811/36832514/

--
Dan Mossor
Systems Engineer at Large
Fedora KDE WG | Fedora QA Team | Fedora Server SIG
Fedora Infrastructure Apprentice
FAS: dmossor IRC: danofsatx
San Antonio, Texas, USA

--
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-05 Thread Dmitri Pal

On 04/05/2015 12:10 AM, Dan Mossor wrote:
I've recently deployed a new domain based on 4.1.2 in F21. We've 
noticed an issue and can't quite seem to nail it down. The problem is 
that logins are taking an inordinate amount of time to complete - the 
fastest logon we can get using LDAP credentials is 8 seconds. During 
our testing, even logons to the IPA server itself took over 30 seconds 
to complete.


I've narrowed this down to sssd, but that is as far as I can get. When 
cranking up debugging for sshd and PAM, I see a minimum 2 second delay 
between ssh handing off the authentication request to sssd and the 
reply back. The only troubleshooting I've done is with ssh, but the 
area that causes the most grief is Apache logins. We configured Apache 
to use PAM for auth through IPA, vice directly calling IPA itself. 
Logging in to our Redmine site takes users a minimum of 34 seconds to 
complete. Following this, a simple webpage containing two hyperlinks 
and two small thumbnail images takes over a minute to load on a 
gigabit network.


The *only* thing changed in this environment was the IPA server. We 
moved the Redmine from our old network that was using IPA 3.x (F20 
branch) to the new one. My initial reaction was that it was the VM 
that was hosting Redmine, but we've run these tests against bare metal 
machines in the same network and have the same issue. It appears that 
sssd is taking a very, very long time to talk to FreeIPA - even on the 
IPA server itself.


However, Kerberos logins into the IPA web GUI are near instantaneous, 
while Username/Password logins take more than a few seconds.


I need to get this solved. My developers don't appreciate the glory 
days of XP taking 5 minutes to log into an IIS 2.1 web server on the 
local network. I don't have the budget to keep them at the coffee pot 
waiting on the network. So, what further information do you need from 
me to track this one down?


Dan


Several tips.
Please check your DNS configuration.
Such delay is usually caused by the DNS lookups timing out. That means 
that the servers probably trying to resolve names against an old DNS 
server that is not around. Look at resolve.conf and make sure only valid 
DNS servers are there and they are in the proper order.


If this does not help please turn on SSSD debug_level to 10, sanitize 
and send the SSSD domain logs and sssd.conf to the list.
More hints can be found here: 
https://fedorahosted.org/sssd/wiki/Troubleshooting


--
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-05 Thread Martin (Lists)
Am 05.04.2015 um 06:10 schrieb Dan Mossor:
> I've recently deployed a new domain based on 4.1.2 in F21. We've noticed
> an issue and can't quite seem to nail it down. The problem is that
> logins are taking an inordinate amount of time to complete - the fastest
> logon we can get using LDAP credentials is 8 seconds. During our
> testing, even logons to the IPA server itself took over 30 seconds to
> complete.
> 
> I've narrowed this down to sssd, but that is as far as I can get. When
> cranking up debugging for sshd and PAM, I see a minimum 2 second delay
> between ssh handing off the authentication request to sssd and the reply
> back. The only troubleshooting I've done is with ssh, but the area that
> causes the most grief is Apache logins. We configured Apache to use PAM
> for auth through IPA, vice directly calling IPA itself. Logging in to
> our Redmine site takes users a minimum of 34 seconds to complete.
> Following this, a simple webpage containing two hyperlinks and two small
> thumbnail images takes over a minute to load on a gigabit network.
> 
> The *only* thing changed in this environment was the IPA server. We
> moved the Redmine from our old network that was using IPA 3.x (F20
> branch) to the new one. My initial reaction was that it was the VM that
> was hosting Redmine, but we've run these tests against bare metal
> machines in the same network and have the same issue. It appears that
> sssd is taking a very, very long time to talk to FreeIPA - even on the
> IPA server itself.
> 
> However, Kerberos logins into the IPA web GUI are near instantaneous,
> while Username/Password logins take more than a few seconds.
> 
> I need to get this solved. My developers don't appreciate the glory days
> of XP taking 5 minutes to log into an IIS 2.1 web server on the local
> network. I don't have the budget to keep them at the coffee pot waiting
> on the network. So, what further information do you need from me to
> track this one down?
> 
> Dan
> 

Hallo

I have a similar issue. On login (graphic systems and ssh) and on the
screen saver I have a delay from about 2 secons to 10 seconds.

According to my logfile i have the following timeline at login:

0   pam_unix (auth)
3   pam_sss (auth)
3   pam_kwallet (sddm:auth)
4   pam_kwallet (sddm:setcred)
5   pam_unix (session)

First collum is the number of seconds after the first action. On myl old
server I had a pure kerberos (handmade) system, which reacted almost
instandly.

Regards
Martin

-- 
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] Slow logins on FreeIPA 4.1.2 (F21)

2015-04-04 Thread John Obaterspok
Hi Dan,

I had a problem that login time increased by ~ 15 seconds from F20 -> F21.
That was worked around by adding "selinux_provider = none" to the domain
section in /etc/sssd/sssd.conf

Have you checked that dns lookups + reverse lookups work on the ipa server?
Is "id -G the_user_name" and "is the user_name_name" slow or fast?
Did you check https://fedorahosted.org/sssd/wiki/Troubleshooting +


-- john

2015-04-05 6:10 GMT+02:00 Dan Mossor :

> I've recently deployed a new domain based on 4.1.2 in F21. We've noticed
> an issue and can't quite seem to nail it down. The problem is that logins
> are taking an inordinate amount of time to complete - the fastest logon we
> can get using LDAP credentials is 8 seconds. During our testing, even
> logons to the IPA server itself took over 30 seconds to complete.
>
> I've narrowed this down to sssd, but that is as far as I can get. When
> cranking up debugging for sshd and PAM, I see a minimum 2 second delay
> between ssh handing off the authentication request to sssd and the reply
> back. The only troubleshooting I've done is with ssh, but the area that
> causes the most grief is Apache logins. We configured Apache to use PAM for
> auth through IPA, vice directly calling IPA itself. Logging in to our
> Redmine site takes users a minimum of 34 seconds to complete. Following
> this, a simple webpage containing two hyperlinks and two small thumbnail
> images takes over a minute to load on a gigabit network.
>
> The *only* thing changed in this environment was the IPA server. We moved
> the Redmine from our old network that was using IPA 3.x (F20 branch) to the
> new one. My initial reaction was that it was the VM that was hosting
> Redmine, but we've run these tests against bare metal machines in the same
> network and have the same issue. It appears that sssd is taking a very,
> very long time to talk to FreeIPA - even on the IPA server itself.
>
> However, Kerberos logins into the IPA web GUI are near instantaneous,
> while Username/Password logins take more than a few seconds.
>
> I need to get this solved. My developers don't appreciate the glory days
> of XP taking 5 minutes to log into an IIS 2.1 web server on the local
> network. I don't have the budget to keep them at the coffee pot waiting on
> the network. So, what further information do you need from me to track this
> one down?
>
> Dan
>
> --
> Dan Mossor
> Systems Engineer at Large
> Fedora KDE WG | Fedora QA Team | Fedora Server SIG
> Fedora Infrastructure Apprentice
> FAS: dmossor IRC: danofsatx
> San Antonio, Texas, USA
>
> --
> 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