[Freeipa-users] LDAP/SSSD/IPA performance

[Bret Wortman]

Crud. That was supposed to have a second comparison log too:

I found something in the slapd-FOO-NET/access log. I figured out which 
conn ID related to a sudo -i that I performed which took longer than 
expected and grepped for that conn ID:

[26/May/2014:09:08:56 -0400] conn=183751 fd=111 slot=111 connection from 
192.168.208.129 to 192.168.10.111
[26/May/2014:09:08:57 -0400] conn=183751 op=0 EXT 
oid="1.3.6.1.4.1.1466.20037" name="startTLS"
[26/May/2014:09:08:57 -0400] conn=183751 op=0 RESULT err=0 tag=120 
nentries=0 etime=0
[26/May/2014:09:08:59 -0400] conn=183751 SSL 128-bit AES
[26/May/2014:09:08:59 -0400] conn=183751 op=1 BIND 
dn="uid=sudo,cn=sysaccounts,cn=etc,dc=foo,dc=net" method=128 version=3
[26/May/2014:09:08:59 -0400] conn=183751 op=1 RESULT err=0 tag=97 
nentries=0 etime=0
[26/May/2014:09:09:00 -0400] conn=183751 op=2 SRCH 
base="ou=SUDOers,dc=foo,dc=net" scope=2 filter="(cn=deraults)" attrs=ALL
[26/May/2014:09:09:00 -0400] conn=183751 op=2 RESULT err=0 tag=101 
nentries=0 etime=0
[26/May/2014:09:09:00 -0400] conn=183751 op=3 SRCH 
base="ou=SUDOers,dc=foo,dc=net" scope=2 
filter="(|(sudoUser=bretw)(sudoUser=%users)(sudoUser=%#100)(sudoUser=%admins)(sudoUser=%nonexp)(sudoUser=%sudoers)(sudoUser=$unrestricted)(sudoUser=%#1855200000)(sudoUser=%#18552000004) 
(sudoUser=%#1855200006)(sudoUser=%#1855200007)(sudoUser=ALL))" attrs=ALL
[26/May/2014:09:09:00 -0400] conn=183751 op=3 RESULT erro=0 tag=101 
nentries=2 etime=0
[26/May/2014:09:09:01 -0400] conn=183751 op=4 SRCH 
base="ou=SUDOers,dc=foo,dc=net" scope=2 filter="(sudoUser=+*)" attrs=ALL
[26/May/2014:09:09:01 -0400] conn=183751op=4 RESULT err=0 tag=101 
nentries=0 etime=0
[26/May/2014:09:09:03 -0400] conn=183751 op=5 UNBIND
[26/May/2014:09:09:03 -0400] conn=183751 op=5 fd=111 closed = U1

I think this shows, roughly, a 7 second elapsed time from start to 
finish, right? Granted, there were other request being serficed during 
this interval as well, but nothing that looked like outrageous volume.

On our faster network, this same exchange went much faster:

[26/May/2014:09:22:55 -0400] conn=12896 fd=100 slot=100 connection from 
192.168.2.13 to 192.168.2.61
[26/May/2014:09:22:55 -0400] conn=12896 op=0 EXT 
oid="1.3.6.1.4.1.1466.20037" name="startTLS"
[26/May/2014:09:22:55 -0400] conn=12896 op=0 RESULT err=0 tag=120 
nentries=0 etime=0
[26/May/2014:09:22:56 -0400] conn=12896 SSL 128-bit AES
[26/May/2014:09:22:56 -0400] conn=12896 op=1 BIND 
dn="uid=sudo,cn=sysaccounts,cn=etc,dc=wedgeofli,dc=me" method=128 version=3
[26/May/2014:09:22:56 -0400] conn=12896 op=1 RESULT err=0 tag=97 
nentries=0 etime=0 dn="uid=sudo,cn=sysaccounts,cn=etc,dc=wedgeofli,dc=me"
[26/May/2014:09:22:56 -0400] conn=12896 op=2 SRCH 
base="ou=SUDOers,dc=wedgeofli,dc=me" scope=2 filter="(cn=defaults)" 
attrs=ALL
[26/May/2014:09:22:56 -0400] conn=12896 op=2 RESULT err=0 tag=101 
nentries=0 etime=0
[26/May/2014:09:22:56 -0400] conn=12896 op=3 SRCH 
base="ou=SUDOers,dc=wedgeofli,dc=me" scope=2 
filter="(|(sudoUser=bretw)(sudoUser=%bretw)(sudoUser=%#10042)(sudoUser=%admins)(sudoUser=%#388800000)(sudoUser=ALL))" 
attrs=ALL
[26/May/2014:09:22:56 -0400] conn=12896 op=3 RESULT err=0 tag=101 
nentries=1 etime=0
[26/May/2014:09:22:56 -0400] conn=12896 op=4 SRCH 
base="ou=SUDOers,dc=wedgeofli,dc=me" scope=2 filter="(sudoUser=+*)" 
attrs=ALL
[26/May/2014:09:22:56 -0400] conn=12896 op=4 RESULT err=0 tag=101 
nentries=0 etime=0
[26/May/2014:09:22:56 -0400] conn=12896 op=5 UNBIND
[26/May/2014:09:22:56 -0400] conn=12896 op=5 fd=100 closed - U1



Bret

On 05/26/2014 09:51 AM, Bret Wortman wrote:
> Okay, I found something in the slapd-FOO-NET/access log. I figured out 
> which conn ID related to a sudo -i that I performed which took longer 
> than expected and grepped for that conn ID:
>
> [26/May/2014:09:08:56 -0400] conn=183751 fd=111 slot=111 connection 
> from 192.168.208.129 to 192.168.10.111
> [26/May/2014:09:08:57 -0400] conn=183751 op=0 EXT 
> oid="1.3.6.1.4.1.1466.20037" name="startTLS"
> [26/May/2014:09:08:57 -0400] conn=183751 op=0 RESULT err=0 tag=120 
> nentries=0 etime=0
> [26/May/2014:09:08:59 -0400] conn=183751 SSL 128-bit AES
> [26/May/2014:09:08:59 -0400] conn=183751 op=1 BIND 
> dn="uid=sudo,cn=sysaccounts,cn=etc,dc=foo,dc=net" method=128 version=3
> [26/May/2014:09:08:59 -0400] conn=183751 op=1 RESULT err=0 tag=97 
> nentries=0 etime=0
> [26/May/2014:09:09:00 -0400] conn=183751 op=2 SRCH 
> base="ou=SUDOers,dc=foo,dc=net" scope=2 filter="(cn=deraults)" attrs=ALL
> [26/May/2014:09:09:00 -0400] conn=183751 op=2 RESULT err=0 tag=101 
> nentries=0 etime=0
> [26/May/2014:09:09:00 -0400] conn=183751 op=3 SRCH 
> base="ou=SUDOers,dc=foo,dc=net" scope=2 
> filter="(|(sudoUser=bretw)(sudoUser=%users)(sudoUser=%#100)(sudoUser=%admins)(sudoUser=%nonexp)(sudoUser=%sudoers)(sudoUser=$unrestricted)(sudoUser=%#1855200000)(sudoUser=%#18552000004) 
> (sudoUser=%#1855200006)(sudoUser=%#1855200007)(sudoUser=ALL))" attrs=ALL
> [26/May/2014:09:09:00 -0400] conn=183751 op=3 RESULT erro=0 tag=101 
> nentries=2 etime=0
> [26/May/2014:09:09:01 -0400] conn=183751 op=4 SRCH 
> base="ou=SUDOers,dc=foo,dc=net" scope=2 filter="(sudoUser=+*)" attrs=ALL
> [26/May/2014:09:09:01 -0400] conn=183751 op=4 RESULT err=0 tag=101 
> nentries=0 etime=0
> [26/May/2014:09:09:03 -0400] conn=183751 op=5 UNBIND
> [26/May/2014:09:09:03 -0400] conn=183751 op=5 fd=111 closed = U1
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20140526/f475d0ef/attachment.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 3766 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20140526/f475d0ef/attachment.p7s>