Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log all LDAP operation time to separate log #107

Closed
yurem opened this issue Jan 22, 2019 · 3 comments

Comments

@yurem
Copy link
Contributor

commented Jan 22, 2019

We need to add new logger to log all add/search/etc total execution time to allow admin inspect it periodically and tune indexes if needed.

@yurem yurem self-assigned this Jan 22, 2019

@yurem yurem added this to the 4.0 milestone Jan 22, 2019

@yurem yurem modified the milestones: 4.0, 3.1.6 Jan 31, 2019

@yurem

This comment has been minimized.

Copy link
Contributor Author

commented Feb 8, 2019

In documentation we need to mention that oxAuth/oxTrust have new log files oxauth_persistence_duration.log/oxtrust_persistence_duration.log

Here is sample output:

2019-02-08 12:06:17,508 DEBUG [ForkJoinPool.commonPool-worker-4] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: lookup, duration: PT0.001S, dn: inum=@!0FE0.2588.1855.C98A!0002!E17F.D858,ou=appliances,o=gluu, attributes: [oxIDPAuthentication]
2019-02-08 12:06:17,508 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: search, duration: PT0.001S, dn: ou=pct,ou=uma,o=@!0FE0.2588.1855.C98A!0001!4290.85E1,o=gluu, filter: (&(&(objectClass=top)(objectClass=oxAuthUmaPCT))(oxAuthExpiration<=20190208090617.495Z)), scope: SUB, batchOperation: org.xdi.oxauth.uma.service.UmaPctService$1@1d8360b3, startIndex: 0, searchLimit: 25, sizeLimit: 25, controls: null, attributes: [oxAuthenticationMode, oxClaimValues, oxAuthClientId, oxAuthTokenCode, oxAuthCreation, oxAuthExpiration]
2019-02-08 12:06:17,509 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: lookup, duration: PT0.001S, dn: ou=resources,ou=uma,o=@!0FE0.2588.1855.C98A!0001!4290.85E1,o=gluu, attributes: null
2019-02-08 12:06:17,510 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: search, duration: PT0.001S, dn: ou=resources,ou=uma,o=@!0FE0.2588.1855.C98A!0001!4290.85E1,o=gluu, filter: (&(&(objectClass=top)(objectClass=oxUmaResource))(oxAuthExpiration<=20190208090617.495Z)), scope: SUB, batchOperation: org.xdi.oxauth.uma.service.UmaResourceService$1@1c19df79, startIndex: 0, searchLimit: 0, sizeLimit: 25, controls: null, attributes: []
2019-02-08 12:06:17,511 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: search, duration: PT0S, dn: ou=u2f,o=@!0FE0.2588.1855.C98A!0001!4290.85E1,o=gluu, filter: (&(&(objectClass=top)(objectClass=oxU2fRequest))(creationDate<=20190208090447.510Z)), scope: SUB, batchOperation: org.xdi.oxauth.service.CleanerTimer$2@4c069e89, startIndex: 0, searchLimit: 25, sizeLimit: 25, controls: null, attributes: [creationDate, oxId, oxRequestId, oxSessionStateId, personInum]
2019-02-08 12:06:17,513 DEBUG [ForkJoinPool.commonPool-worker-4] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: lookup, duration: PT0.001S, dn: inum=@!0FE0.2588.1855.C98A!0002!E17F.D858,ou=appliances,o=gluu, attributes: [oxAuthenticationMode]
2019-02-08 12:06:17,513 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: search, duration: PT0.001S, dn: ou=registered_devices,ou=u2f,o=@!0FE0.2588.1855.C98A!0001!4290.85E1,o=gluu, filter: (&(&(objectClass=top)(objectClass=oxDeviceRegistration))(creationDate<=20190208090447.512Z)), scope: SUB, batchOperation: org.xdi.oxauth.service.CleanerTimer$3@29b890ec, startIndex: 0, searchLimit: 25, sizeLimit: 25, controls: null, attributes: [oxApplication, oxCounter, creationDate, description, oxDeviceData, oxDeviceNotificationConf, oxDeviceRegistrationConf, displayName, oxId, oxDeviceKeyHandle, oxDeviceHashCode, oxLastAccessTime, oxNickName, oxStatus]
2019-02-08 12:06:17,542 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: search, duration: PT0.029S, dn: ou=people,o=@!0FE0.2588.1855.C98A!0001!4290.85E1,o=gluu, filter: (&(&(objectClass=top)(objectClass=oxFido2RegistrationEntry))(&(!(oxStatus=registered))(creationDate<=20190208090417.513Z))), scope: SUB, batchOperation: org.gluu.oxauth.fido2.persist.RegistrationPersistenceService$1@2c85086e, startIndex: 0, searchLimit: 25, sizeLimit: 25, controls: null, attributes: [oxCodeChallenge, creationDate]
2019-02-08 12:06:17,616 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: search, duration: PT0.074S, dn: ou=people,o=@!0FE0.2588.1855.C98A!0001!4290.85E1,o=gluu, filter: (&(&(objectClass=top)(objectClass=organizationalUnit))(&(ou=fido2_register)(|(numsubordinates=0)(hasSubordinates=FALSE)))), scope: SUB, batchOperation: org.gluu.oxauth.fido2.persist.RegistrationPersistenceService$2@79b06dff, startIndex: 0, searchLimit: 25, sizeLimit: 25, controls: null, attributes: [ou]
2019-02-08 12:06:17,617 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: search, duration: PT0.001S, dn: ou=people,o=@!0FE0.2588.1855.C98A!0001!4290.85E1,o=gluu, filter: (&(&(objectClass=top)(objectClass=oxFido2AuthenticationEntry))(|(&(!(oxStatus=authenticated))(creationDate<=20190208090417.616Z))(&(oxStatus=authenticated)(creationDate<=20190124090617.616Z)))), scope: SUB, batchOperation: org.gluu.oxauth.fido2.persist.AuthenticationPersistenceService$1@50e5cacd, startIndex: 0, searchLimit: 25, sizeLimit: 25, controls: null, attributes: [oxCodeChallenge, creationDate]
2019-02-08 12:06:17,680 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: search, duration: PT0.063S, dn: ou=people,o=@!0FE0.2588.1855.C98A!0001!4290.85E1,o=gluu, filter: (&(&(objectClass=top)(objectClass=organizationalUnit))(&(ou=fido2_auth)(|(numsubordinates=0)(hasSubordinates=FALSE)))), scope: SUB, batchOperation: org.gluu.oxauth.fido2.persist.AuthenticationPersistenceService$2@2ba0b9ac, startIndex: 0, searchLimit: 25, sizeLimit: 25, controls: null, attributes: [ou]
2019-02-08 12:06:17,681 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: lookup, duration: PT0S, dn: ou=oxauth,ou=@!0FE0.2588.1855.C98A!0002!E17F.D858,ou=statistic,o=metric, attributes: null
2019-02-08 12:06:17,682 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: lookup, duration: PT0.001S, dn: ou=@!0FE0.2588.1855.C98A!0002!E17F.D858,ou=statistic,o=metric, attributes: null
2019-02-08 12:06:17,683 DEBUG [ForkJoinPool.commonPool-worker-5] [org.gluu.site.watch.DurationUtil] (DurationUtil.java:33) - LDAP operation: lookup, duration: PT0.001S, dn: ou=@!0FE0.2588.1855.C98A!0002!E17F.D858,ou=statistic,o=metric, attributes: null

@yurem

This comment has been minimized.

Copy link
Contributor Author

commented Feb 8, 2019

Also these are debug log messages. Hence they are not affect production environment performance. Adim can enable/disable logs in oxAuth/oxTrust on the fly via JSON config.

@yurem

This comment has been minimized.

Copy link
Contributor Author

commented Feb 8, 2019

Implemented

@yurem yurem closed this Feb 8, 2019

shmorri added a commit to GluuFederation/docs-ce-prod that referenced this issue Mar 4, 2019

Added LDAP operation time log
Added information from oxCore issue [#107](GluuFederation/oxCore#107)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
1 participant
You can’t perform that action at this time.