-
Type:
Improvement
-
Resolution: Works as Designed
-
Priority:
Major - P3
-
None
-
Affects Version/s: 3.6.17
-
Component/s: Logging
-
None
-
Server Security
It seems that server is logging the "Performing" log line after receiving the LDAP query results. Here's the log output when the queryUser has a 4-second delay configured:
2020-02-15T15:41:33.673-0800 D ACCESS [conn22] LDAPAPIInfo: { ldapai_info_version: 1, ldapai_api_version: 3001, ldap_protocol_version: 3, ldapai_extension
s: [X_OPENLDAP], ldapai_vendor_name: OpenLDAP, ldapai_vendor_version: 20444}
2020-02-15T15:41:33.673-0800 D ACCESS [conn22] Binding to LDAP server "default" with bind parameters: {BindDN: uid=mdb,ou=Users,dc=acme,dc=qa, authenticationType: simple}
2020-02-15T15:41:33.673-0800 D ACCESS [conn22] Connected to LDAP server at 127.0.0.1:1389 with LDAP URL: ldap://127.0.0.1:1389
2020-02-15T15:41:37.674-0800 D ACCESS [conn22] Performing LDAP query: BaseDN: "ou=Groups,dc=ACME,dc=QA", Scope: "sub", Filter: "(member:=cn=user1,ou=Users,dc=acme,dc=qa)"
2020-02-15T15:41:37.675-0800 D ACCESS [conn22] From LDAP query result, got an entry with DN: cn=ReproGroup,ou=Groups,dc=acme,dc=qa
2020-02-15T15:41:37.675-0800 D ACCESS [conn22] From LDAP entry with DN cn=ReproGroup,ou=Groups,dc=acme,dc=qa, got attribute objectClass
2020-02-15T15:41:37.675-0800 D ACCESS [conn22] From LDAP entry with DN cn=ReproGroup,ou=Groups,dc=acme,dc=qa, got attribute cn
2020-02-15T15:41:37.675-0800 D ACCESS [conn22] From LDAP entry with DN cn=ReproGroup,ou=Groups,dc=acme,dc=qa, got attribute member
2020-02-15T15:41:37.675-0800 D ACCESS [conn22] Acquiring group DNs from entities which possess user as attribute
2020-02-15T15:41:37.676-0800 D ACCESS [conn22] Updated session cache of user information for cn=user1,ou=Users,dc=acme,dc=qa@$external
The actual LDAP query happened between the "Connected to LDAP server" line and the "Performing LDAP query" line which is confusing.
Having correct timestamps in the log files is crucial for post-mortem investigations, especially for ones involving the slow LDAP servers.