slow kerberos authentication

I'm using kerberos authentication in ovirt for the URL /sso/oauth/token-http-auth, but kerberos is done in Apache using auth_gssapi_module and it's quite slow, about 6s for a request. I'm trying to understand if it's apache or ovirt-engine that are slow. Is there a way to get response time metered for http requests inside ovirt instead of seen from apache ?

I am not aware of anything, but debug log of all aaa stuff would help, to understand what takes the most time. - org.ovirt.engineextensions.aaa.ldap - org.ovirt.engineextensions.aaa.misc - org.ovirt.engine.core.aaa - org.ovirt.engine.core.sso To enable it in runtime, please follow: https://github.com/oVirt/ovirt-engine-extension-aaa-ldap/blob/master/README#... On Thu, May 11, 2017 at 7:24 PM, Fabrice Bacchella < fabrice.bacchella@orange.fr> wrote:
I'm using kerberos authentication in ovirt for the URL /sso/oauth/token-http-auth, but kerberos is done in Apache using auth_gssapi_module and it's quite slow, about 6s for a request.
I'm trying to understand if it's apache or ovirt-engine that are slow. Is there a way to get response time metered for http requests inside ovirt instead of seen from apache ?
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

The request is indeed quite slow within ovirt, using the setup given by Juan: /ovirt-engine/sso/oauth/token-http-auth 7001ms I was not able to authenticate jboss-cli.sh, I don't know why: 'admin@internal-authz': No valid profile found in credentials. So I tried to modifie usr/share/ovirt-engine/services/ovirt-engine/ovirt-engine-logging.properties.in, adding: org.ovirt.engineextensions.aaa=ALL org.ovirt.engine.core.bll.aaa=ALL and then restart ovirt-engine. But that changed nothing. That's not the good syntax ?
Le 12 mai 2017 à 09:25, Ondra Machacek <omachace@redhat.com> a écrit :
I am not aware of anything, but debug log of all aaa stuff would help, to understand what takes the most time.
- org.ovirt.engineextensions.aaa.ldap - org.ovirt.engineextensions.aaa.misc - org.ovirt.engine.core.aaa - org.ovirt.engine.core.sso
To enable it in runtime, please follow:
https://github.com/oVirt/ovirt-engine-extension-aaa-ldap/blob/master/README#...
On Thu, May 11, 2017 at 7:24 PM, Fabrice Bacchella <fabrice.bacchella@orange.fr> wrote: I'm using kerberos authentication in ovirt for the URL /sso/oauth/token-http-auth, but kerberos is done in Apache using auth_gssapi_module and it's quite slow, about 6s for a request.
I'm trying to understand if it's apache or ovirt-engine that are slow. Is there a way to get response time metered for http requests inside ovirt instead of seen from apache ?
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

On Fri, May 12, 2017 at 1:18 PM, Fabrice Bacchella < fabrice.bacchella@orange.fr> wrote:
The request is indeed quite slow within ovirt, using the setup given by Juan:
/ovirt-engine/sso/oauth/token-http-auth 7001ms
I was not able to authenticate jboss-cli.sh, I don't know why: 'admin@internal-authz': No valid profile found in credentials.
It should be admin@internal.
So I tried to modifie usr/share/ovirt-engine/services/ovirt-engine/ovirt- engine-logging.properties.in, adding: org.ovirt.engineextensions.aaa=ALL org.ovirt.engine.core.bll.aaa=ALL and then restart ovirt-engine. But that changed nothing. That's not the good syntax ?
You must change the file in ovirt-engine.xml.in same file as Juan send above. See here: https://github.com/oVirt/ovirt-engine-extension-aaa-ldap/blob/ovirt-engine-e... But I think better to use JBoss CLI, you don't have to restart oVirt engine then.
Le 12 mai 2017 à 09:25, Ondra Machacek <omachace@redhat.com> a écrit :
I am not aware of anything, but debug log of all aaa stuff would help, to understand what takes the most time.
- org.ovirt.engineextensions.aaa.ldap - org.ovirt.engineextensions.aaa.misc - org.ovirt.engine.core.aaa - org.ovirt.engine.core.sso
To enable it in runtime, please follow:
https://github.com/oVirt/ovirt-engine-extension-aaa- ldap/blob/master/README#L469
On Thu, May 11, 2017 at 7:24 PM, Fabrice Bacchella < fabrice.bacchella@orange.fr> wrote: I'm using kerberos authentication in ovirt for the URL /sso/oauth/token-http-auth, but kerberos is done in Apache using auth_gssapi_module and it's quite slow, about 6s for a request.
I'm trying to understand if it's apache or ovirt-engine that are slow. Is there a way to get response time metered for http requests inside ovirt instead of seen from apache ?
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

--Apple-Mail=_B91BD8B0-FBC3-4086-AA27-63311A6333FB Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8
Le 12 mai 2017 =C3=A0 13:35, Ondra Machacek <omachace@redhat.com> a = =C3=A9crit : =20 =20 =20 On Fri, May 12, 2017 at 1:18 PM, Fabrice Bacchella = <fabrice.bacchella@orange.fr <mailto:fabrice.bacchella@orange.fr>> = wrote: The request is indeed quite slow within ovirt, using the setup given = by Juan: =20 /ovirt-engine/sso/oauth/token-http-auth 7001ms =20 I was not able to authenticate jboss-cli.sh, I don't know why: = 'admin@internal-authz': No valid profile found in credentials. =20 It should be admin@internal. =20
Indeed, but an export don't show that: <user = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4" = id=3D"0000001a-001a-001a-001a-0000000003b4"> <department></department> = <domain_entry_id>39323336363566612D373333622D346532612D396530632D316630396= 536643634636432</domain_entry_id> <email></email> <last_name></last_name> <name>admin</name> <namespace>*</namespace> <principal>admin</principal> <user_name>admin@internal-authz</user_name> <domain href=3D"/ovirt-engine/api/domains/696E7465726E616C2D617574687A" = id=3D"696E7465726E616C2D617574687A"> <name>internal-authz</name> </domain> <permissions = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4/permi= ssions"/> <roles = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4/roles= "/> <ssh_public_keys = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4/sshpu= blickeys"/> <tags = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4/tags"= /> </user> --Apple-Mail=_B91BD8B0-FBC3-4086-AA27-63311A6333FB Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8 <html><head><meta http-equiv=3D"Content-Type" content=3D"text/html = charset=3Dutf-8"></head><body style=3D"word-wrap: break-word; = -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" = class=3D""><br class=3D""><div><blockquote type=3D"cite" class=3D""><div = class=3D"">Le 12 mai 2017 =C3=A0 13:35, Ondra Machacek <<a = href=3D"mailto:omachace@redhat.com" class=3D"">omachace@redhat.com</a>>= a =C3=A9crit :</div><br class=3D"Apple-interchange-newline"><div = class=3D""><div dir=3D"ltr" class=3D""><br class=3D""><div = class=3D"gmail_extra"><br class=3D""><div class=3D"gmail_quote">On Fri, = May 12, 2017 at 1:18 PM, Fabrice Bacchella <span dir=3D"ltr" = class=3D""><<a href=3D"mailto:fabrice.bacchella@orange.fr" = target=3D"_blank" class=3D"">fabrice.bacchella@orange.fr</a>></span> = wrote:<br class=3D""><blockquote class=3D"gmail_quote" style=3D"margin:0px= 0px 0px 0.8ex;border-left:1px solid = rgb(204,204,204);padding-left:1ex">The request is indeed quite slow = within ovirt, using the setup given by Juan:<br class=3D""> <br class=3D""> /ovirt-engine/sso/oauth/token-<wbr class=3D"">http-auth 7001ms<br = class=3D""> <br class=3D""> I was not able to authenticate jboss-cli.sh, I don't know why: = 'admin@internal-authz': No valid profile found in credentials.<br = class=3D""></blockquote><div class=3D""><br class=3D""></div><div = class=3D"">It should be admin@internal.<br class=3D""></div><div = class=3D""> </div></div></div></div></div></blockquote><div><br = class=3D""></div>Indeed, but an export don't show that:</div><div><br = class=3D""></div><div><div style=3D"margin: 0px; font-size: 11px; = line-height: normal; font-family: Menlo;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""><user = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4" = id=3D"0000001a-001a-001a-001a-0000000003b4"></span></div><div = style=3D"margin: 0px; font-size: 11px; line-height: normal; font-family: = Menlo;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""> = <department></department></span></div><div style=3D"margin: = 0px; font-size: 11px; line-height: normal; font-family: Menlo;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""> = <domain_entry_id>39323336363566612D373333622D346532612D396530632D316= 630396536643634636432</domain_entry_id></span></div><div = style=3D"margin: 0px; font-size: 11px; line-height: normal; font-family: = Menlo;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""> = <email></email></span></div><div style=3D"margin: 0px; = font-size: 11px; line-height: normal; font-family: Menlo;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""> <last_name></last_name></span></div><div = style=3D"margin: 0px; font-size: 11px; line-height: normal; font-family: = Menlo;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""> = <name>admin</name></span></div><div style=3D"margin: 0px; = font-size: 11px; line-height: normal; font-family: Menlo;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""> <namespace>*</namespace></span></div><div = style=3D"margin: 0px; font-size: 11px; line-height: normal; font-family: = Menlo;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""> = <principal>admin</principal></span></div><div style=3D"margin:= 0px; font-size: 11px; line-height: normal; font-family: Menlo;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""> = <user_name>admin@internal-authz</user_name></span></div><div = style=3D"margin: 0px; font-size: 11px; line-height: normal; font-family: = Menlo;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""> <domain = href=3D"/ovirt-engine/api/domains/696E7465726E616C2D617574687A" = id=3D"696E7465726E616C2D617574687A"></span></div><div style=3D"margin: = 0px; font-size: 11px; line-height: normal; font-family: Menlo;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""> = <name>internal-authz</name></span></div><div style=3D"margin: = 0px; font-size: 11px; line-height: normal; font-family: Menlo;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""> </domain></span></div><div style=3D"margin: 0px; = font-size: 11px; line-height: normal; font-family: Menlo;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""> <permissions = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4/permi= ssions"/></span></div><div style=3D"margin: 0px; font-size: 11px; = line-height: normal; font-family: Menlo;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""> = <roles = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4/roles= "/></span></div><div style=3D"margin: 0px; font-size: 11px; = line-height: normal; font-family: Menlo;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""> = <ssh_public_keys = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4/sshpu= blickeys"/></span></div><div style=3D"margin: 0px; font-size: 11px; = line-height: normal; font-family: Menlo;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""> = <tags = href=3D"/ovirt-engine/api/users/0000001a-001a-001a-001a-0000000003b4/tags"= /></span></div><div style=3D"margin: 0px; font-size: 11px; = line-height: normal; font-family: Menlo;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""></user></span></div><div class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""><br = class=3D""></span></div></div><br class=3D""></body></html>= --Apple-Mail=_B91BD8B0-FBC3-4086-AA27-63311A6333FB--

--Apple-Mail=_3D3960C0-53C8-4BFF-B123-1BF2E0BD026A Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=us-ascii Ok, I found where it's slow, it's a ldapsearch on our AD: time ldapsearch -a never -E pr=3D100/noprompt -H ldap://ad1 -b DC=3D... = -s sub = '(&(groupType:1.2.840.113556.1.4.803:=3D2147483648)(&(objectCategory=3Dgro= up)(member:1.2.840.113556.1.4.1941:=3Duserdn)))' objectGUID name = description # numResponses: 70 # numEntries: 66 # numReferences: 3 real 0m10.801s user 0m0.007s sys 0m0.012s That matches the log line: 2017-05-12 14:22:17,413+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-2) [] = Performing SearchRequest 'SearchRequest(baseDN=3D'...', scope=3DSUB, = deref=3DNEVER, sizeLimit=3D0, timeLimit=3D0, = filter=3D'&(objectCategory=3Dgroup)(groupType:1.2.840.113556.1.4.803:=3D21= 47483648)(member:1.2.840.113556.1.4.1941:=3D...)', attrs=3D{objectGUID, = name, description}, controls=3D{SimplePagedResultsControl(pageSize=3D100, = isCritical=3Dfalse)})' request on server '...' 2017-05-12 14:22:24,456+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-1) [] = SearchResult: SearchResult(resultCode=3D0 (success), messageID=3D3, = entriesReturned=3D66, referencesReturned=3D0, = responseControls=3D{SimplePagedResultsControl(pageSize=3D0, = isCritical=3Dfalse)}) And without 1.2.840.113556.1.4.1941 # numResponses: 54 # numEntries: 50 # numReferences: 3 real 0m0.051s user 0m0.008s sys 0m0.007s So it's an AD problem. 1.2.840.113556.1.4.1941 make it slow, but without = it, the result is not the same. But I don't know if it's an AD or ovirt = problem. I'll keep investigating. Thank's for your help.= --Apple-Mail=_3D3960C0-53C8-4BFF-B123-1BF2E0BD026A Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=us-ascii <html><head><meta http-equiv=3D"Content-Type" content=3D"text/html = charset=3Dus-ascii"></head><body style=3D"word-wrap: break-word; = -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" = class=3D"">Ok, I found where it's slow, it's a ldapsearch on our AD:<div = class=3D""><br class=3D""></div><div class=3D""><div style=3D"margin: = 0px; font-size: 11px; line-height: normal; font-family: Menlo;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D"">time ldapsearch -a never -E pr=3D100/noprompt -H <a = href=3D"ldap://ad1" class=3D"">ldap://ad1</a> -b DC=3D... -s sub = '(&(groupType:1.2.840.113556.1.4.803:=3D2147483648)(&(objectCatego= ry=3Dgroup)(member:1.2.840.113556.1.4.1941:=3Duserdn)))' objectGUID name = description</span></div><br class=3D""></div><div class=3D""><div = style=3D"margin: 0px; line-height: normal;" class=3D""><div = style=3D"font-family: Menlo; font-size: 11px; margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""># numResponses: 70</span></div><div = style=3D"font-family: Menlo; font-size: 11px; margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""># numEntries: 66</span></div><div = style=3D"font-family: Menlo; font-size: 11px; margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""># numReferences: 3</span></div><div = style=3D"font-family: Menlo; font-size: 11px; margin: 0px; line-height: = normal; min-height: 13px;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""></span><br class=3D""></div><div style=3D"font-family: Menlo; = font-size: 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">real<span= class=3D"Apple-tab-span" style=3D"white-space:pre"> = </span>0m10.801s</span></div><div style=3D"font-family: Menlo; = font-size: 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">user<span= class=3D"Apple-tab-span" style=3D"white-space:pre"> = </span>0m0.007s</span></div><div style=3D"font-family: Menlo; font-size: = 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">sys<span = class=3D"Apple-tab-span" style=3D"white-space:pre"> = </span>0m0.012s</span></div><div style=3D"font-family: Menlo; font-size: = 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""><br = class=3D""></span></div><div style=3D"font-family: Menlo; font-size: = 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">That = matches the log line:</span></div><div style=3D"margin: 0px; = line-height: normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures;" class=3D""><div style=3D"margin: 0px; line-height: = normal;" class=3D""><font face=3D"Menlo" class=3D""><span = style=3D"font-size: 11px;" class=3D"">2017-05-12 14:22:17,413+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-2) [] = Performing SearchRequest 'SearchRequest(baseDN=3D'...', scope=3DSUB, = deref=3DNEVER, sizeLimit=3D0, timeLimit=3D0, = filter=3D'&(objectCategory=3Dgroup)(groupType:1.2.840.113556.1.4.803:=3D= 2147483648)(member:1.2.840.113556.1.4.1941:=3D...)', attrs=3D{objectGUID, = name, description}, con</span></font><span style=3D"font-size: 11px; = font-family: Menlo;" = class=3D"">trols=3D{SimplePagedResultsControl(pageSize=3D100, = isCritical=3Dfalse)})' request on server = '...'</span></div></span></div><div style=3D"margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures; font-size: 11px;" class=3D""><font face=3D"Menlo" = class=3D""><div style=3D"margin: 0px; line-height: normal;" = class=3D"">2017-05-12 14:22:24,456+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-1) [] = SearchResult: SearchResult(resultCode=3D0 (success), messageID=3D3, = entriesReturned=3D66, referencesReturned=3D0, = responseControls=3D{SimplePagedResultsControl(pageSize=3D0, = isCritical=3Dfalse)})</div></font></span></div><div style=3D"font-family: = Menlo; font-size: 11px;" class=3D""><span style=3D"font-variant-ligatures:= no-common-ligatures" class=3D""><br class=3D""></span></div><div = style=3D"font-family: Menlo; font-size: 11px;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""><br = class=3D""></span></div><div style=3D"font-family: Menlo; font-size: = 11px;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D"">And = without </span>1.2.840.113556.1.4.1941</div><div = style=3D"font-family: Menlo; font-size: 11px;" class=3D""><br = class=3D""></div><div style=3D"font-family: Menlo; font-size: 11px;" = class=3D""><div style=3D"margin: 0px; line-height: normal;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""># numResponses: 54</span></div><div style=3D"margin: 0px; = line-height: normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""># numEntries: 50</span></div><div = style=3D"margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""># = numReferences: 3</span></div><div style=3D"margin: 0px; line-height: = normal; min-height: 13px;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""></span><br class=3D""></div><div style=3D"margin: 0px; = line-height: normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D"">real<span class=3D"Apple-tab-span" = style=3D"white-space:pre"> </span>0m0.051s</span></div><div = style=3D"margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">user<span= class=3D"Apple-tab-span" style=3D"white-space:pre"> = </span>0m0.008s</span></div><div style=3D"margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D"">sys<span class=3D"Apple-tab-span" = style=3D"white-space:pre"> </span>0m0.007s</span></div><div = style=3D"margin: 0px; line-height: normal;" class=3D""><br = class=3D""></div></div><div style=3D"font-family: Menlo; font-size: = 11px; margin: 0px; line-height: normal;" class=3D"">So it's an AD = problem. 1.2.840.113556.1.4.1941 make it slow, but without it, the = result is not the same. But I don't know if it's an AD or ovirt problem. = I'll keep investigating.</div><div style=3D"font-family: Menlo; = font-size: 11px; margin: 0px; line-height: normal;" class=3D""><br = class=3D""></div><div style=3D"font-family: Menlo; font-size: 11px; = margin: 0px; line-height: normal;" class=3D"">Thank's for your = help.</div></div></div></body></html>= --Apple-Mail=_3D3960C0-53C8-4BFF-B123-1BF2E0BD026A--

--Apple-Mail=_1C19D31E-4C14-4940-8073-42031CD7C271 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 I found that: http://dunnry.com/blog/TransitiveLinkValueFilterEvaluation.aspx
Le 12 mai 2017 =C3=A0 14:44, Fabrice Bacchella = <fabrice.bacchella@orange.fr> a =C3=A9crit : =20 Ok, I found where it's slow, it's a ldapsearch on our AD: =20 time ldapsearch -a never -E pr=3D100/noprompt -H ldap://ad1 = <ldap://ad1> -b DC=3D... -s sub = '(&(groupType:1.2.840.113556.1.4.803:=3D2147483648)(&(objectCategory=3Dgro= up)(member:1.2.840.113556.1.4.1941:=3Duserdn)))' objectGUID name = description =20 # numResponses: 70 # numEntries: 66 # numReferences: 3 =20 real 0m10.801s user 0m0.007s sys 0m0.012s =20 That matches the log line: 2017-05-12 14:22:17,413+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-2) [] = Performing SearchRequest 'SearchRequest(baseDN=3D'...', scope=3DSUB, = deref=3DNEVER, sizeLimit=3D0, timeLimit=3D0, = filter=3D'&(objectCategory=3Dgroup)(groupType:1.2.840.113556.1.4.803:=3D21= 47483648)(member:1.2.840.113556.1.4.1941:=3D...)', attrs=3D{objectGUID, = name, description}, controls=3D{SimplePagedResultsControl(pageSize=3D100, = isCritical=3Dfalse)})' request on server '...' 2017-05-12 14:22:24,456+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-1) [] = SearchResult: SearchResult(resultCode=3D0 (success), messageID=3D3, = entriesReturned=3D66, referencesReturned=3D0, = responseControls=3D{SimplePagedResultsControl(pageSize=3D0, = isCritical=3Dfalse)}) =20 =20 And without 1.2.840.113556.1.4.1941 =20 # numResponses: 54 # numEntries: 50 # numReferences: 3 =20 real 0m0.051s user 0m0.008s sys 0m0.007s =20 So it's an AD problem. 1.2.840.113556.1.4.1941 make it slow, but = without it, the result is not the same. But I don't know if it's an AD = or ovirt problem. I'll keep investigating. =20 Thank's for your help. _______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
--Apple-Mail=_1C19D31E-4C14-4940-8073-42031CD7C271 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8 <html><head><meta http-equiv=3D"Content-Type" content=3D"text/html = charset=3Dutf-8"></head><body style=3D"word-wrap: break-word; = -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" = class=3D"">I found that:<div class=3D""><br class=3D""></div><div = class=3D""><a = href=3D"http://dunnry.com/blog/TransitiveLinkValueFilterEvaluation.aspx" = class=3D"">http://dunnry.com/blog/TransitiveLinkValueFilterEvaluation.aspx= </a></div><div class=3D""><br class=3D""></div><div class=3D""><br = class=3D""><div><blockquote type=3D"cite" class=3D""><div class=3D"">Le = 12 mai 2017 =C3=A0 14:44, Fabrice Bacchella <<a = href=3D"mailto:fabrice.bacchella@orange.fr" = class=3D"">fabrice.bacchella@orange.fr</a>> a =C3=A9crit :</div><br = class=3D"Apple-interchange-newline"><div class=3D""><meta = http-equiv=3D"Content-Type" content=3D"text/html charset=3Dus-ascii" = class=3D""><div style=3D"word-wrap: break-word; -webkit-nbsp-mode: = space; -webkit-line-break: after-white-space;" class=3D"">Ok, I found = where it's slow, it's a ldapsearch on our AD:<div class=3D""><br = class=3D""></div><div class=3D""><div style=3D"margin: 0px; font-size: = 11px; line-height: normal; font-family: Menlo;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">time = ldapsearch -a never -E pr=3D100/noprompt -H <a href=3D"ldap://ad1" = class=3D"">ldap://ad1</a> -b DC=3D... -s sub = '(&(groupType:1.2.840.113556.1.4.803:=3D2147483648)(&(objectCatego= ry=3Dgroup)(member:1.2.840.113556.1.4.1941:=3Duserdn)))' objectGUID name = description</span></div><br class=3D""></div><div class=3D""><div = style=3D"margin: 0px; line-height: normal;" class=3D""><div = style=3D"font-family: Menlo; font-size: 11px; margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""># numResponses: 70</span></div><div = style=3D"font-family: Menlo; font-size: 11px; margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""># numEntries: 66</span></div><div = style=3D"font-family: Menlo; font-size: 11px; margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""># numReferences: 3</span></div><div = style=3D"font-family: Menlo; font-size: 11px; margin: 0px; line-height: = normal; min-height: 13px;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""></span><br class=3D""></div><div style=3D"font-family: Menlo; = font-size: 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">real<span= class=3D"Apple-tab-span" style=3D"white-space:pre"> = </span>0m10.801s</span></div><div style=3D"font-family: Menlo; = font-size: 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">user<span= class=3D"Apple-tab-span" style=3D"white-space:pre"> = </span>0m0.007s</span></div><div style=3D"font-family: Menlo; font-size: = 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">sys<span = class=3D"Apple-tab-span" style=3D"white-space:pre"> = </span>0m0.012s</span></div><div style=3D"font-family: Menlo; font-size: = 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""><br = class=3D""></span></div><div style=3D"font-family: Menlo; font-size: = 11px; margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">That = matches the log line:</span></div><div style=3D"margin: 0px; = line-height: normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures;" class=3D""><div style=3D"margin: 0px; line-height: = normal;" class=3D""><font face=3D"Menlo" class=3D""><span = style=3D"font-size: 11px;" class=3D"">2017-05-12 14:22:17,413+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-2) [] = Performing SearchRequest 'SearchRequest(baseDN=3D'...', scope=3DSUB, = deref=3DNEVER, sizeLimit=3D0, timeLimit=3D0, = filter=3D'&(objectCategory=3Dgroup)(groupType:1.2.840.113556.1.4.803:=3D= 2147483648)(member:1.2.840.113556.1.4.1941:=3D...)', attrs=3D{objectGUID, = name, description}, con</span></font><span style=3D"font-size: 11px; = font-family: Menlo;" = class=3D"">trols=3D{SimplePagedResultsControl(pageSize=3D100, = isCritical=3Dfalse)})' request on server = '...'</span></div></span></div><div style=3D"margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures; font-size: 11px;" class=3D""><font face=3D"Menlo" = class=3D""><div style=3D"margin: 0px; line-height: normal;" = class=3D"">2017-05-12 14:22:24,456+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-1) [] = SearchResult: SearchResult(resultCode=3D0 (success), messageID=3D3, = entriesReturned=3D66, referencesReturned=3D0, = responseControls=3D{SimplePagedResultsControl(pageSize=3D0, = isCritical=3Dfalse)})</div></font></span></div><div style=3D"font-family: = Menlo; font-size: 11px;" class=3D""><span style=3D"font-variant-ligatures:= no-common-ligatures" class=3D""><br class=3D""></span></div><div = style=3D"font-family: Menlo; font-size: 11px;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""><br = class=3D""></span></div><div style=3D"font-family: Menlo; font-size: = 11px;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D"">And = without </span>1.2.840.113556.1.4.1941</div><div = style=3D"font-family: Menlo; font-size: 11px;" class=3D""><br = class=3D""></div><div style=3D"font-family: Menlo; font-size: 11px;" = class=3D""><div style=3D"margin: 0px; line-height: normal;" = class=3D""><span style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""># numResponses: 54</span></div><div style=3D"margin: 0px; = line-height: normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D""># numEntries: 50</span></div><div = style=3D"margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D""># = numReferences: 3</span></div><div style=3D"margin: 0px; line-height: = normal; min-height: 13px;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" = class=3D""></span><br class=3D""></div><div style=3D"margin: 0px; = line-height: normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D"">real<span class=3D"Apple-tab-span" = style=3D"white-space:pre"> </span>0m0.051s</span></div><div = style=3D"margin: 0px; line-height: normal;" class=3D""><span = style=3D"font-variant-ligatures: no-common-ligatures" class=3D"">user<span= class=3D"Apple-tab-span" style=3D"white-space:pre"> = </span>0m0.008s</span></div><div style=3D"margin: 0px; line-height: = normal;" class=3D""><span style=3D"font-variant-ligatures: = no-common-ligatures" class=3D"">sys<span class=3D"Apple-tab-span" = style=3D"white-space:pre"> </span>0m0.007s</span></div><div = style=3D"margin: 0px; line-height: normal;" class=3D""><br = class=3D""></div></div><div style=3D"font-family: Menlo; font-size: = 11px; margin: 0px; line-height: normal;" class=3D"">So it's an AD = problem. 1.2.840.113556.1.4.1941 make it slow, but without it, the = result is not the same. But I don't know if it's an AD or ovirt problem. = I'll keep investigating.</div><div style=3D"font-family: Menlo; = font-size: 11px; margin: 0px; line-height: normal;" class=3D""><br = class=3D""></div><div style=3D"font-family: Menlo; font-size: 11px; = margin: 0px; line-height: normal;" class=3D"">Thank's for your = help.</div></div></div></div>_____________________________________________= __<br class=3D"">Users mailing list<br class=3D""><a = href=3D"mailto:Users@ovirt.org" class=3D"">Users@ovirt.org</a><br = class=3D"">http://lists.ovirt.org/mailman/listinfo/users<br = class=3D""></div></blockquote></div><br class=3D""></div></body></html>= --Apple-Mail=_1C19D31E-4C14-4940-8073-42031CD7C271--

This is new feature in aaa-ldap tracked here[1]. By default for AD profiles we use this feature, and it should increase performance in most cases. But if this is not the case for you, can you just try to change the profile from: include = <ad.properties> to include = <ad-recursive.properties> And see if it will be better? [1] https://bugzilla.redhat.com/show_bug.cgi?id=1393407 On Fri, May 12, 2017 at 2:54 PM, Fabrice Bacchella < fabrice.bacchella@orange.fr> wrote:
I found that:
http://dunnry.com/blog/TransitiveLinkValueFilterEvaluation.aspx
Le 12 mai 2017 à 14:44, Fabrice Bacchella <fabrice.bacchella@orange.fr> a écrit :
Ok, I found where it's slow, it's a ldapsearch on our AD:
time ldapsearch -a never -E pr=100/noprompt -H ldap://ad1 -b DC=... -s sub '(&(groupType:1.2.840.113556.1.4.803:=2147483648 <(214)%20748-3648> )(&(objectCategory=group)(member:1.2.840.113556.1.4.1941:=userdn)))' objectGUID name description
# numResponses: 70 # numEntries: 66 # numReferences: 3
real 0m10.801s user 0m0.007s sys 0m0.012s
That matches the log line: 2017-05-12 14:22:17,413+02 DEBUG [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-2) [] Performing SearchRequest 'SearchRequest(baseDN='...', scope=SUB, deref=NEVER, sizeLimit=0, timeLimit=0, filter='&(objectCategory= group)(groupType:1.2.840.113556.1.4.803:=2147483648)( member:1.2.840.113556.1.4.1941:=...)', attrs={objectGUID, name, description}, controls={SimplePagedResultsControl(pageSize=100, isCritical=false)})' request on server '...' 2017-05-12 14:22:24,456+02 DEBUG [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-1) [] SearchResult: SearchResult(resultCode=0 (success), messageID=3, entriesReturned=66, referencesReturned=0, responseControls={ SimplePagedResultsControl(pageSize=0, isCritical=false)})
And without 1.2.840.113556.1.4.1941
# numResponses: 54 # numEntries: 50 # numReferences: 3
real 0m0.051s user 0m0.008s sys 0m0.007s
So it's an AD problem. 1.2.840.113556.1.4.1941 make it slow, but without it, the result is not the same. But I don't know if it's an AD or ovirt problem. I'll keep investigating.
Thank's for your help. _______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

Le 12 mai 2017 =C3=A0 15:58, Ondra Machacek <omachace@redhat.com> a = =C3=A9crit : =20 This is new feature in aaa-ldap tracked here[1]. By default for AD profiles we use this feature, and it should increase performance in most cases. =20 But if this is not the case for you, can you just try to change the =
--Apple-Mail=_53EF95BA-A328-418F-B475-452AAD552109 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 It works much better now. Goes from 6s to less than 500ms. Not blazing = fast but much more usable, thanks a lot. profile
from: =20 include =3D <ad.properties> =20 to =20 include =3D <ad-recursive.properties> =20 And see if it will be better? =20 [1] https://bugzilla.redhat.com/show_bug.cgi?id=3D1393407 = <https://bugzilla.redhat.com/show_bug.cgi?id=3D1393407> =20 On Fri, May 12, 2017 at 2:54 PM, Fabrice Bacchella = <fabrice.bacchella@orange.fr <mailto:fabrice.bacchella@orange.fr>> = wrote: I found that: =20 http://dunnry.com/blog/TransitiveLinkValueFilterEvaluation.aspx = <http://dunnry.com/blog/TransitiveLinkValueFilterEvaluation.aspx> =20 =20
Le 12 mai 2017 =C3=A0 14:44, Fabrice Bacchella = <fabrice.bacchella@orange.fr <mailto:fabrice.bacchella@orange.fr>> a = =C3=A9crit : =20 Ok, I found where it's slow, it's a ldapsearch on our AD: =20 time ldapsearch -a never -E pr=3D100/noprompt -H ldap://ad1 <> -b = DC=3D... -s sub '(&(groupType:1.2.840.113556.1.4.803:=3D2147483648 = <tel:(214)%20748-3648>)(&(objectCategory=3Dgroup)(member:1.2.840.113556.1.= 4.1941:=3Duserdn)))' objectGUID name description =20 # numResponses: 70 # numEntries: 66 # numReferences: 3 =20 real 0m10.801s user 0m0.007s sys 0m0.012s =20 That matches the log line: 2017-05-12 14:22:17,413+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-2) [] = Performing SearchRequest 'SearchRequest(baseDN=3D'...', scope=3DSUB, = deref=3DNEVER, sizeLimit=3D0, timeLimit=3D0, = filter=3D'&(objectCategory=3Dgroup)(groupType:1.2.840.113556.1.4.803:=3D21= 47483648)(member:1.2.840.113556.1.4.1941:=3D...)', attrs=3D{objectGUID, = name, description}, controls=3D{SimplePagedResultsControl(pageSize=3D100, = isCritical=3Dfalse)})' request on server '...' 2017-05-12 14:22:24,456+02 DEBUG = [org.ovirt.engineextensions.aaa.ldap.Framework] (pool-25-thread-1) [] = SearchResult: SearchResult(resultCode=3D0 (success), messageID=3D3, = entriesReturned=3D66, referencesReturned=3D0, = responseControls=3D{SimplePagedResultsControl(pageSize=3D0, = isCritical=3Dfalse)}) =20 =20 And without 1.2.840.113556.1.4.1941 =20 # numResponses: 54 # numEntries: 50 # numReferences: 3 =20 real 0m0.051s user 0m0.008s sys 0m0.007s =20 So it's an AD problem. 1.2.840.113556.1.4.1941 make it slow, but = without it, the result is not the same. But I don't know if it's an AD = or ovirt problem. I'll keep investigating. =20 Thank's for your help. _______________________________________________ Users mailing list Users@ovirt.org <mailto:Users@ovirt.org> http://lists.ovirt.org/mailman/listinfo/users = <http://lists.ovirt.org/mailman/listinfo/users> =20 =20
Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
--Apple-Mail=_53EF95BA-A328-418F-B475-452AAD552109 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8 <html><head><meta http-equiv=3D"Content-Type" content=3D"text/html = charset=3Dutf-8"></head><body style=3D"word-wrap: break-word; = -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" = class=3D"">It works much better now. Goes from 6s to less than 500ms. = Not blazing fast but much more usable, thanks a lot.<div class=3D""><br = class=3D""><div class=3D""><div><blockquote type=3D"cite" class=3D""><div = class=3D"">Le 12 mai 2017 =C3=A0 15:58, Ondra Machacek <<a = href=3D"mailto:omachace@redhat.com" class=3D"">omachace@redhat.com</a>>= a =C3=A9crit :</div><br class=3D"Apple-interchange-newline"><div = class=3D""><div dir=3D"ltr" class=3D""><div class=3D""><div = class=3D""><div class=3D""><div class=3D""><div class=3D""><div = class=3D"">This is new feature in aaa-ldap tracked here[1].<br = class=3D""></div>By default for AD profiles we use this feature, and it = should<br class=3D""></div>increase performance in most cases.<br = class=3D""><br class=3D""></div>But if this is not the case for you, can = you just try to change the profile<br class=3D""></div>from:<br = class=3D""><br class=3D""> include =3D <ad.properties><br = class=3D""><br class=3D""></div>to<br class=3D""><br = class=3D""> include =3D <ad-recursive.properties><br = class=3D""><br class=3D""></div>And see if it will be better?<br = class=3D""><div class=3D""><div class=3D""><div class=3D""><div = class=3D""><div class=3D""><div class=3D""><br class=3D"">[1] <a = href=3D"https://bugzilla.redhat.com/show_bug.cgi?id=3D1393407" = class=3D"">https://bugzilla.redhat.com/show_bug.cgi?id=3D1393407</a><br = class=3D""></div></div></div></div></div></div></div><div = class=3D"gmail_extra"><br class=3D""><div class=3D"gmail_quote">On Fri, = May 12, 2017 at 2:54 PM, Fabrice Bacchella <span dir=3D"ltr" = class=3D""><<a href=3D"mailto:fabrice.bacchella@orange.fr" = target=3D"_blank" class=3D"">fabrice.bacchella@orange.fr</a>></span> = wrote:<br class=3D""><blockquote class=3D"gmail_quote" style=3D"margin:0 = 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div = style=3D"word-wrap:break-word" class=3D"">I found that:<div class=3D""><br= class=3D""></div><div class=3D""><a = href=3D"http://dunnry.com/blog/TransitiveLinkValueFilterEvaluation.aspx" = target=3D"_blank" class=3D"">http://dunnry.com/blog/<wbr = class=3D"">TransitiveLinkValueFilterEvalu<wbr = class=3D"">ation.aspx</a></div><div class=3D""><br class=3D""></div><div = class=3D""><br class=3D""><div class=3D""><blockquote type=3D"cite" = class=3D""><div class=3D""><div class=3D"h5"><div class=3D"">Le 12 mai = 2017 =C3=A0 14:44, Fabrice Bacchella <<a = href=3D"mailto:fabrice.bacchella@orange.fr" target=3D"_blank" = class=3D"">fabrice.bacchella@orange.fr</a>> a =C3=A9crit :</div><br = class=3D"m_5720800219487051111Apple-interchange-newline"></div></div><div = class=3D""><div class=3D""><div class=3D"h5"><div = style=3D"word-wrap:break-word" class=3D"">Ok, I found where it's slow, = it's a ldapsearch on our AD:<div class=3D""><br class=3D""></div><div = class=3D""><div = style=3D"margin:0px;font-size:11px;line-height:normal;font-family:Menlo" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D"">time ldapsearch -a never -E pr=3D100/noprompt -H <a = class=3D"">ldap://ad1</a> -b DC=3D... -s sub = '(&(groupType:1.2.840.113556.<wbr class=3D"">1.4.803:=3D<a = href=3D"tel:(214)%20748-3648" value=3D"+12147483648" target=3D"_blank" = class=3D"">2147483648</a>)(&(<wbr = class=3D"">objectCategory=3Dgroup)(member:<wbr = class=3D"">1.2.840.113556.1.4.1941:=3D<wbr class=3D"">userdn)))' = objectGUID name description</span></div><br class=3D""></div><div = class=3D""><div style=3D"margin:0px;line-height:normal" class=3D""><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D""># numResponses: 70</span></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D""># numEntries: 66</span></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D""># numReferences: 3</span></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal;mi= n-height:13px" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures" class=3D""></span><br= class=3D""></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D"">real<span class=3D"m_5720800219487051111Apple-tab-span" = style=3D"white-space:pre-wrap"> </span>0m10.801s</span></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D"">user<span class=3D"m_5720800219487051111Apple-tab-span" = style=3D"white-space:pre-wrap"> </span>0m0.007s</span></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D"">sys<span class=3D"m_5720800219487051111Apple-tab-span" = style=3D"white-space:pre-wrap"> </span>0m0.012s</span></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D""><br class=3D""></span></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D"">That matches the log line:</span></div><div = style=3D"margin:0px;line-height:normal" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures" class=3D""><div = style=3D"margin:0px;line-height:normal" class=3D""><font face=3D"Menlo" = class=3D""><span style=3D"font-size:11px" class=3D"">2017-05-12 = 14:22:17,413+02 DEBUG [org.ovirt.engineextensions.<wbr = class=3D"">aaa.ldap.Framework] (pool-25-thread-2) [] Performing = SearchRequest 'SearchRequest(baseDN=3D'...', scope=3DSUB, deref=3DNEVER, = sizeLimit=3D0, timeLimit=3D0, filter=3D'&(objectCategory=3D<wbr = class=3D"">group)(groupType:1.2.840.<wbr = class=3D"">113556.1.4.803:=3D2147483648)(<wbr = class=3D"">member:1.2.840.113556.1.4.<wbr class=3D"">1941:=3D...)', = attrs=3D{objectGUID, name, description}, con</span></font><span = style=3D"font-size:11px;font-family:Menlo" class=3D"">trols=3D{<wbr = class=3D"">SimplePagedResultsControl(<wbr class=3D"">pageSize=3D100, = isCritical=3Dfalse)})' request on server = '...'</span></div></span></div><div = style=3D"margin:0px;line-height:normal" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures;font-size:11px" = class=3D""><font face=3D"Menlo" class=3D""><div = style=3D"margin:0px;line-height:normal" class=3D"">2017-05-12 = 14:22:24,456+02 DEBUG [org.ovirt.engineextensions.<wbr = class=3D"">aaa.ldap.Framework] (pool-25-thread-1) [] SearchResult: = SearchResult(resultCode=3D0 (success), messageID=3D3, = entriesReturned=3D66, referencesReturned=3D0, responseControls=3D{<wbr = class=3D"">SimplePagedResultsControl(<wbr class=3D"">pageSize=3D0, = isCritical=3Dfalse)})</div></font></span></div><div = style=3D"font-family:Menlo;font-size:11px" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures" class=3D""><br = class=3D""></span></div><div style=3D"font-family:Menlo;font-size:11px" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D""><br class=3D""></span></div><div = style=3D"font-family:Menlo;font-size:11px" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures" class=3D"">And = without </span>1.2.840.113556.1.4.<wbr class=3D"">1941</div><div = style=3D"font-family:Menlo;font-size:11px" class=3D""><br = class=3D""></div><div style=3D"font-family:Menlo;font-size:11px" = class=3D""><div style=3D"margin:0px;line-height:normal" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures" class=3D""># = numResponses: 54</span></div><div style=3D"margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D""># numEntries: 50</span></div><div = style=3D"margin:0px;line-height:normal" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures" class=3D""># = numReferences: 3</span></div><div = style=3D"margin:0px;line-height:normal;min-height:13px" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures" class=3D""></span><br= class=3D""></div><div style=3D"margin:0px;line-height:normal" = class=3D""><span style=3D"font-variant-ligatures:no-common-ligatures" = class=3D"">real<span class=3D"m_5720800219487051111Apple-tab-span" = style=3D"white-space:pre-wrap"> </span>0m0.051s</span></div><div = style=3D"margin:0px;line-height:normal" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures" class=3D"">user<span = class=3D"m_5720800219487051111Apple-tab-span" = style=3D"white-space:pre-wrap"> </span>0m0.008s</span></div><div = style=3D"margin:0px;line-height:normal" class=3D""><span = style=3D"font-variant-ligatures:no-common-ligatures" class=3D"">sys<span = class=3D"m_5720800219487051111Apple-tab-span" = style=3D"white-space:pre-wrap"> </span>0m0.007s</span></div><div = style=3D"margin:0px;line-height:normal" class=3D""><br = class=3D""></div></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D"">So it's an AD problem. 1.2.840.113556.1.4.1941 make it slow, = but without it, the result is not the same. But I don't know if it's an = AD or ovirt problem. I'll keep investigating.</div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D""><br class=3D""></div><div = style=3D"font-family:Menlo;font-size:11px;margin:0px;line-height:normal" = class=3D"">Thank's for your = help.</div></div></div></div></div></div><span = class=3D"">______________________________<wbr = class=3D"">_________________<br class=3D"">Users mailing list<br = class=3D""><a href=3D"mailto:Users@ovirt.org" target=3D"_blank" = class=3D"">Users@ovirt.org</a><br class=3D""><a = href=3D"http://lists.ovirt.org/mailman/listinfo/users" target=3D"_blank" = class=3D"">http://lists.ovirt.org/<wbr = class=3D"">mailman/listinfo/users</a><br = class=3D""></span></div></blockquote></div><br = class=3D""></div></div></blockquote></div><br class=3D""></div> _______________________________________________<br class=3D"">Users = mailing list<br class=3D""><a href=3D"mailto:Users@ovirt.org" = class=3D"">Users@ovirt.org</a><br = class=3D"">http://lists.ovirt.org/mailman/listinfo/users<br = class=3D""></div></blockquote></div><br = class=3D""></div></div></body></html>= --Apple-Mail=_53EF95BA-A328-418F-B475-452AAD552109--

On May 11, 2017 8:25 PM, "Fabrice Bacchella" <fabrice.bacchella@orange.fr> wrote: I'm using kerberos authentication in ovirt for the URL /sso/oauth/token-http-auth, but kerberos is done in Apache using auth_gssapi_module and it's quite slow, about 6s for a request. I'm trying to understand if it's apache or ovirt-engine that are slow. Is there a way to get response time metered for http requests inside ovirt instead of seen from apache ? In 4.1, look under /var/log/httpd, there should be an ovirt specific log file for exactly this - end to end latency of requests. Y. _______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

On 05/12/2017 10:04 AM, Yaniv Kaul wrote:
On May 11, 2017 8:25 PM, "Fabrice Bacchella" <fabrice.bacchella@orange.fr <mailto:fabrice.bacchella@orange.fr>> wrote:
I'm using kerberos authentication in ovirt for the URL /sso/oauth/token-http-auth, but kerberos is done in Apache using auth_gssapi_module and it's quite slow, about 6s for a request.
I'm trying to understand if it's apache or ovirt-engine that are slow. Is there a way to get response time metered for http requests inside ovirt instead of seen from apache ?
In 4.1, look under /var/log/httpd, there should be an ovirt specific log file for exactly this - end to end latency of requests. Y.
The name of that file is 'ovirt-requests-log', and it contains messages like this: [12/May/2017:11:09:30 +0200] 192.168.122.1 "Correlation-Id: 9e259b75-ee9e-4501-9737-b38d2c318123" "Duration: 393514us" "GET /ovirt-engine/api/vms HTTP/1.1" 2322 Note however that it is generated by the web server, so the reported time will include all the web server activities required to complete the request. If you need to get the same measurement from the point of view of the application server you can edit the /usr/share/ovirt-engine/services/ovirt-engine/ovirt-engine.xml.in file and do the following modifications: 1. Modify the AJP connector (the one that Apache talks to) so that it records the start time of the request: <ajp-listener name="ajp" socket-binding="ajp" redirect-socket="redirect" record-request-start-time="true" <-- This is new /> 2. Enable the access log: <host name="default-host" alias="localhost"> <filter-ref .../> <access-log pattern="%U %Dms" directory="/var/log/ovirt-engine" prefix="my" suffix=".log"/> <-- This is new </host> Then restart the engine. It will start to write to /var/log/ovirt-engine/my.log lines like this: /ovirt-engine/api/vms 801ms The format of the pattern is described here: http://undertow.io/javadoc/1.4.x/index.html Remember that the ovirt-engine.xml.in file isn't considered a configuration file, so your changes will be lost next time you update the engine RPMs.

On 05/12/2017 11:45 AM, Juan Hernández wrote:
On 05/12/2017 10:04 AM, Yaniv Kaul wrote:
On May 11, 2017 8:25 PM, "Fabrice Bacchella" <fabrice.bacchella@orange.fr <mailto:fabrice.bacchella@orange.fr>> wrote:
I'm using kerberos authentication in ovirt for the URL /sso/oauth/token-http-auth, but kerberos is done in Apache using auth_gssapi_module and it's quite slow, about 6s for a request.
I'm trying to understand if it's apache or ovirt-engine that are slow. Is there a way to get response time metered for http requests inside ovirt instead of seen from apache ?
In 4.1, look under /var/log/httpd, there should be an ovirt specific log file for exactly this - end to end latency of requests. Y.
The name of that file is 'ovirt-requests-log', and it contains messages like this:
[12/May/2017:11:09:30 +0200] 192.168.122.1 "Correlation-Id: 9e259b75-ee9e-4501-9737-b38d2c318123" "Duration: 393514us" "GET /ovirt-engine/api/vms HTTP/1.1" 2322
Note however that it is generated by the web server, so the reported time will include all the web server activities required to complete the request.
If you need to get the same measurement from the point of view of the application server you can edit the /usr/share/ovirt-engine/services/ovirt-engine/ovirt-engine.xml.in file and do the following modifications:
1. Modify the AJP connector (the one that Apache talks to) so that it records the start time of the request:
<ajp-listener name="ajp" socket-binding="ajp" redirect-socket="redirect" record-request-start-time="true" <-- This is new />
2. Enable the access log:
<host name="default-host" alias="localhost"> <filter-ref .../> <access-log pattern="%U %Dms" directory="/var/log/ovirt-engine" prefix="my" suffix=".log"/> <-- This is new </host>
Then restart the engine. It will start to write to /var/log/ovirt-engine/my.log lines like this:
/ovirt-engine/api/vms 801ms
The format of the pattern is described here:
Actually here: http://undertow.io/javadoc/1.4.x/io/undertow/server/handlers/accesslog/Acces...
Remember that the ovirt-engine.xml.in file isn't considered a configuration file, so your changes will be lost next time you update the engine RPMs.
participants (4)
-
Fabrice Bacchella
-
Juan Hernández
-
Ondra Machacek
-
Yaniv Kaul