Uploaded image for project: 'RHEL'
  1. RHEL
  2. RHEL-16277

LDAP connections are closed with code T2 before the IO block timeout is reached. [rhel-8.10.0.z]

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done-Errata
    • Icon: Major Major
    • rhel-8.10.z
    • rhel-8.8.0.z
    • 389-ds-base
    • None
    • None
    • rhel-sst-idm-ds
    • ssg_idm
    • 0
    • QE ack
    • False
    • Hide

      None

      Show
      None
    • None
    • None
    • None

      Upstream issue: https://github.com/389ds/389-ds-base/issues/6096

      What were you trying to do that didn't work?

      After upgrading IPA packages, customer is noticing more LDAP connections getting closed with closed IO timeout (nsslapd-ioblocktimeout) - T2

      The weird thing is that these connections were closed by the server way before the IOblock timeout would normally kick out.

      In the following log excerpt, the connection was closed after ~2 seconds while the IOblock timeout is set at 10 seconds:

      $ grep "conn=81714 "  access
[10/Nov/2023:11:36:28.008537037 +0100] conn=81714 fd=1207 slot=1207 connection from <CLIENT_IP> to <SERVER_IP>
[10/Nov/2023:11:36:28.009761098 +0100] conn=81714 op=0 SRCH base="" scope=0 filter="(objectClass=*)" attrs="* altServer namingContexts supportedControl supportedExtension supportedFeatures supportedLDAPVersion supportedSASLMechanisms domaincontrollerfunctionality defaultnamingcontext lastusn highestcommittedusn aci"
[10/Nov/2023:11:36:28.011306146 +0100] conn=81714 op=0 RESULT err=0 tag=101 nentries=1 wtime=0.000295198 optime=0.001545429 etime=0.001839160
[10/Nov/2023:11:36:28.104657885 +0100] conn=81714 op=1 BIND dn="" method=sasl version=3 mech=GSSAPI
[10/Nov/2023:11:36:29.716857610 +0100] conn=81714 op=1 RESULT err=14 tag=97 nentries=0 wtime=0.000077784 optime=1.612214193 etime=1.612290895, SASL bind in progress
[10/Nov/2023:11:36:29.723828025 +0100] conn=81714 op=2 BIND dn="" method=sasl version=3 mech=GSSAPI
[10/Nov/2023:11:36:29.960137105 +0100] conn=81714 op=2 RESULT err=14 tag=97 nentries=0 wtime=0.000093647 optime=0.236313819 etime=0.236405865, SASL bind in progress
[10/Nov/2023:11:36:29.961984390 +0100] conn=81714 op=3 BIND dn="" method=sasl version=3 mech=GSSAPI
[10/Nov/2023:11:36:29.963229265 +0100] conn=81714 op=3 RESULT err=0 tag=97 nentries=0 wtime=0.000083632 optime=0.001250999 etime=0.001333229 dn="fqdn=<HOSTNAME>,cn=computers,cn=accounts,dc=example,dc=com"
[10/Nov/2023:11:36:29.967481904 +0100] conn=81714 op=4 SRCH base="cn=accounts,dc=example,dc=com" scope=2 filter="(&(objectClass=ipaHost)(fqdn=<HOSTNAME>))" attrs="objectClass cn fqdn serverHostName memberOf ipaSshPubKey ipaUniqueID"
[10/Nov/2023:11:36:29.969232470 +0100] conn=81714 op=4 RESULT err=0 tag=101 nentries=1 wtime=0.002685963 optime=0.001752500 etime=0.004436367 notes=P details="Paged Search" pr_idx=0 pr_cookie=-1
[10/Nov/2023:11:36:29.975709236 +0100] conn=81714 op=5 SRCH base="fqdn=<HOSTNAME>,cn=computers,cn=accounts,dc=example,dc=com" scope=0 filter="(objectClass=*)" attrs="objectClass cn memberOf ipaUniqueID"
[10/Nov/2023:11:36:29.984908676 +0100] conn=81714 op=-1 fd=1207 closed IO timeout (nsslapd-ioblocktimeout) - T2
$

$ grep ioblocktimeout <SOS_REPORT>/etc/dirsrv/slapd-<INSTANCE>/dse.ldif nsslapd-ioblocktimeout: 10000
$

       

      Please provide the package NVR for which bug is seen:

       

      $ cat <SOS_REPORT>/etc/redhat-release 
Red Hat Enterprise Linux release 8.8 (Ootpa)
$
$ egrep "^ipa|389-ds" <SOS_REPORT>/installed-rpms 
389-ds-base-1.4.3.35-2.module+el8.8.0+19693+b24f535c.x86_64 Sun Oct 22 18:08:45 2023
389-ds-base-legacy-tools-1.4.3.35-2.module+el8.8.0+19693+b24f535c.x86_64 Sun Oct 22 18:09:53 2023
389-ds-base-libs-1.4.3.35-2.module+el8.8.0+19693+b24f535c.x86_64 Sun Oct 22 18:08:43 2023
ipa-client-4.9.11-7.module+el8.8.0+19639+24a8b95c.x86_64    Sun Oct 22 18:08:48 2023
ipa-client-common-4.9.11-7.module+el8.8.0+19639+24a8b95c.noarch Sun Oct 22 18:06:57 2023
ipa-common-4.9.11-7.module+el8.8.0+19639+24a8b95c.noarch    Sun Oct 22 18:07:34 2023
ipa-healthcheck-0.12-1.module+el8.8.0+17582+6bf5bf91.noarch Sun Jun 11 13:40:11 2023
ipa-healthcheck-core-0.12-1.module+el8.8.0+17582+6bf5bf91.noarch Sun Jun 11 13:36:58 2023
ipa-selinux-4.9.11-7.module+el8.8.0+19639+24a8b95c.noarch   Sun Oct 22 18:06:59 2023
ipa-server-4.9.11-7.module+el8.8.0+19639+24a8b95c.x86_64    Sun Oct 22 18:09:41 2023
ipa-server-common-4.9.11-7.module+el8.8.0+19639+24a8b95c.noarch Sun Oct 22 18:09:40 2023
ipa-server-dns-4.9.11-7.module+el8.8.0+19639+24a8b95c.noarch Sun Oct 22 18:09:51 2023
$
 

       

      How reproducible:

      At customer site.

      Steps to reproduce

      Issue was seen under normal operations with a large IPA deployment.

      Expected results

      Connections should not get closed by the server before the timeout has elapsed.

      Actual results

      Connections are getting closed before the IOblock timeout is over.

              jachapma James Chapman
              rhn-support-tmihinto Têko Mihinto
              IdM DS Dev IdM DS Dev
              IdM DS QE IdM DS QE
              Votes:
              0 Vote for this issue
              Watchers:
              9 Start watching this issue

                Created:
                Updated:
                Resolved: