Dsee7 LDAP server goes unresponsive

User_76QBR

Hi ,

Considering a time period from 08:00 AM to 09:00 AM . In this time frame, in error logs we see similar unindexed searches(please see sample below) and  slapd_poll timed out errors

From 08:00 to 08: 12 there were unindexed searches in the error logs

From 08:12 to 08:45 there were no records in error logs and access logs.

08:45 -08:48 unindexed searches in the error logs

08:49 -09:03 - slapd_poll timed out errors.

13/Nov/2020:08:12:19 -0500] - WARNING<20805> - Backend Database - conn=-1 op=0 msgId=-1 - search is not indexed base='cn=changelog' filter='(&(0=uid=**,ou=people,dc=xxx,dc=com)(|(objectclass=*)(objectclass=ldapsubentry)))' scope='sub'

[13/Nov/2020:08:47:17 -0500] - WARNING<20805> - Backend Database - conn=-1 op=0 msgId=-1 - search is not indexed base='dc=com' filter='(&(0=uid=xxx,ou=people,dc=xxxx,dc=com)(|(objectclass=*)(objectclass=ldapsubentry)))' scope='sub'

[13/Nov/2020:08:50:41 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(513) timed out

[13/Nov/2020:08:50:50 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(533) timed out

[13/Nov/2020:08:50:57 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(551) timed out

[13/Nov/2020:08:51:10 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(576) timed out

[13/Nov/2020:08:51:16 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(591) timed out

[13/Nov/2020:08:51:25 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(611) timed out

[13/Nov/2020:08:51:34 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(632) timed out

[13/Nov/2020:08:51:41 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(652) timed out

[13/Nov/2020:08:51:53 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(675) timed out

[13/Nov/2020:08:51:58 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(691) timed out

[13/Nov/2020:08:52:09 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(712) timed out

[13/Nov/2020:08:52:16 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(733) timed out

[13/Nov/2020:08:52:26 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(755) timed out

[13/Nov/2020:08:52:36 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(778) timed out

[13/Nov/2020:08:52:42 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(793) timed out

[13/Nov/2020:08:52:53 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(812) timed out

[13/Nov/2020:08:52:57 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(832) timed out

[13/Nov/2020:08:53:10 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(855) timed out

[13/Nov/2020:08:53:19 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(878) timed out

[13/Nov/2020:09:00:45 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(1933) timed out

[13/Nov/2020:09:00:49 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(1943) timed out

[13/Nov/2020:09:00:55 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(1956) timed out

[13/Nov/2020:09:01:04 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(1974) timed out

[13/Nov/2020:09:01:11 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(1993) timed out

[13/Nov/2020:09:01:19 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2015) timed out

[13/Nov/2020:09:01:28 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2034) timed out

[13/Nov/2020:09:01:40 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2057) timed out

[13/Nov/2020:09:01:48 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2076) timed out

[13/Nov/2020:09:01:55 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2095) timed out

[13/Nov/2020:09:02:04 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2117) timed out

[13/Nov/2020:09:02:12 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2137) timed out

[13/Nov/2020:09:02:22 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2159) timed out

[13/Nov/2020:09:02:29 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2178) timed out

[13/Nov/2020:09:02:39 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2196) timed out

[13/Nov/2020:09:02:46 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2218) timed out

[13/Nov/2020:09:02:56 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2238) timed out

[13/Nov/2020:09:03:04 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2260) timed out

[13/Nov/2020:09:03:12 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2279) timed out

[13/Nov/2020:09:03:22 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2299) timed out

[13/Nov/2020:09:03:30 -0500] - DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(2322) timed out

[13/Nov/2020:09:03:33 -0500] - Preparing for shutdown.

Looking at the access logs ,these unindexed queries are triggered after a delete of user id happens. We are trying to figure out the reason for this unindexed search . Unable to track the user ID triggering it in the access logs.Looks like the query will not return valid search results as well.

Running the Ldapsearch around 08:50 AM did not work and at 09:03 AM we stopped the instance and then started it back again.This fixed the issue.

We trying to figure out the reason for server not responding in this time frame. Could you please let us know if the server was not responding due to the below reasons ? Thanks.

1. Unindexed queries
2. slapd_poll timed out errors

Could you please let us know the reason & fix for this ? Thanks.

stan25

Please check your 'referential integrity' plugin configuration whether you have added attribute in the arg and check to make sure it is indexed.

Make sure the attribute listed in 'nsslapd-pluginarg' are indexed.

For example:

dn: cn=referential integrity postoperation,cn=plugins,cn=config

objectClass: top

objectClass: nsSlapdPlugin

objectClass: ds-signedPlugin

objectClass: extensibleObject

cn: referential integrity postoperation

nsslapd-pluginPath: /ds7/binaries/dsee7/lib/referint-plugin.so

nsslapd-pluginInitfunc: referint_postop_init

nsslapd-pluginType: postoperation

nsslapd-plugin-depends-on-type: database

nsslapd-pluginarg0: 10

nsslapd-pluginarg2: 1

nsslapd-pluginarg3: memberof

nsslapd-pluginarg4: uniquemember

nsslapd-pluginarg5: clients

nsslapd-pluginarg8: profiles

nsslapd-pluginarg9: products

nsslapd-pluginarg1: /ds7/binaries/dsee7/slapd-userstore/logs/referint.log

nsslapd-pluginEnabled: on

User_76QBR

Hi Stan,

Thank you for the response and suggestion. We are seeing the attribute listed in 'nsslapd-pluginarg' already indexed. Please see below index details and the attribute details . Let me know if further information is required.Could you please recommend further steps to fix this ? Thanks.

Index Details:

ATTR_NAME       eq-enabled pres-enabled sub-enabled approx-enabled system

-------------------- ---------- ------------ ----------- -------------- ------

member        on     off      off     off       no

nsRoleDN       on     off      off     off       no

owner         on     off      off     off       no

seeAlso        on     off      off     off       no

uniquemember     on     off      off     off       no

Attribute Details:

nsslapd-pluginarg0: 0

nsslapd-plugin-depends-on-type: database

nsslapd-pluginarg1: 0

nsslapd-pluginarg2: /xxx/xx/xx/xx/xx/xx/dsee7/xxx/logs/xxx

nsslapd-pluginarg3: 0

nsslapd-pluginarg4: member

nsslapd-pluginarg5: uniquemember

nsslapd-pluginarg6: owner

nsslapd-pluginarg7: seeAlso

nsslapd-pluginarg8: nsroledn

DebA-Oracle

This KM could help to troubleshoot the issue:

ODSEE - Directory Server Seems to Hang at Undetermined Times and Errors Log Shows "DEBUG - conn=-1 op=-1 msgId=-1 - slapd_poll(nnnn) timed out" (Doc ID 1331812.1)