Directory ApacheDS
  1. Directory ApacheDS
  2. DIRSERVER-1556

Error message: ERR_00004 The PDU buffer size is too small !

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: 1.5.7
    • Fix Version/s: 2.0.0-M11
    • Component/s: None
    • Labels:
      None
    • Environment:
      Windows Server 2003 SP2 / Sun JRE 6 update 21

      Description

      We're currently testing Apache Directory Server (ADS) in a custom environment for a customer of ours. In this environment ADS is used to store certificates and certificate revocation lists. At first everything seemed to be working fine, but we encounter an error that seems to randomly occur every now. When adding an object, viewing an object in Directory Studio or adding attributes (the certificate) to an existing object this fails with the following message in apacheds-rolling.log: ERR_00004 The PDU buffer size is too small !. After encountering this error I twice raised the max PDU buffer size in server.xml to:

      maxPDUSize="40000000"

      And restarted the server. Unfortunately the error still occurs every now and then. The issue occurs seemingly randomly, independent of the accessed object or the LDAP client that is used. If ADS is restarted and Directory Studio reconnects the same object can be viewed normally.

      I'd appreciate if someone could explain why this occurs and, if possible, how this can be fixed. A log fragment is below. The company name as it occurs in the log file has been modified.

      Log fragment:

      [16:58:09] ERROR [org.apache.directory.shared.ldap.codec.LdapEncoder] - ERR_04065 Ldap encoder failed to encode object: Search Result Entry
      entry
      ServerEntry
      dn[n]: cn=Test 01 User+givenName=Test 01+mail=test01user@test.lan+sn=User,organizationalUnitName=Test,o=Test Bedrijf, c=NL
      objectClass: organizationalPerson
      objectClass: person
      objectClass: inetOrgPerson
      objectClass: top
      sn: User
      mail: test01user@test.lan
      givenName: Test 01
      cn: Test 01 User
      x500uniqueidentifier: '0011001100111001011001100011010100110011011001100110010001100100001101110011011001100100001100110011001100110111001101000011011000110101001110010110000101100011001100000110011001100011001101000011011100110111011000100011001100110000001110000110000100110111'B
      businesscategory: Valid
      userCertificate;binary: '0x30 0x82 0x06 0xD6 0x30 0x82 0x04 0xBE 0xA0 0x03 0x02 0x01 0x02 0x02 0x10 0x39 ...'
      , error : ERR_00004 The PDU buffer size is too small !
      [16:58:09] WARN [org.apache.directory.server.ldap.LdapProtocolHandler] - Unexpected exception forcing session to close: sending disconnect notice to client.
      org.apache.mina.filter.codec.ProtocolEncoderException: org.apache.directory.shared.ldap.message.spi.ProviderException: ERR_04065 Ldap encoder failed to encode object: Search Result Entry
      entry
      ServerEntry
      dn[n]: cn=Test 01 User+givenName=Test 01+mail=test01user@test.lan+sn=User,organizationalUnitName=Test,o=Test Bedrijf, c=NL
      objectClass: organizationalPerson
      objectClass: person
      objectClass: inetOrgPerson
      objectClass: top
      sn: User
      mail: test01user@test.lan
      givenName: Test 01
      cn: Test 01 User
      x500uniqueidentifier: '0011001100111001011001100011010100110011011001100110010001100100001101110011011001100100001100110011001100110111001101000011011000110101001110010110000101100011001100000110011001100011001101000011011100110111011000100011001100110000001110000110000100110111'B
      businesscategory: Valid
      userCertificate;binary: '0x30 0x82 0x06 0xD6 0x30 0x82 0x04 0xBE 0xA0 0x03 0x02 0x01 0x02 0x02 0x10 0x39 ...'
      , error : ERR_00004 The PDU buffer size is too small !
      at org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:313)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:506)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1400(DefaultIoFilterChain.java:46)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:805)
      at org.apache.mina.filter.executor.ExecutorFilter.filterWrite(ExecutorFilter.java:706)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:506)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1400(DefaultIoFilterChain.java:46)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:805)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.filterWrite(DefaultIoFilterChain.java:731)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:506)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:498)
      at org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:428)
      at org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:369)
      at org.apache.directory.server.ldap.handlers.SearchHandler.readResults(SearchHandler.java:334)
      at org.apache.directory.server.ldap.handlers.SearchHandler.doSimpleSearch(SearchHandler.java:749)
      at org.apache.directory.server.ldap.handlers.SearchHandler.handleIgnoringReferrals(SearchHandler.java:978)
      at org.apache.directory.server.ldap.handlers.SearchHandler.handleWithReferrals(SearchHandler.java:1054)
      at org.apache.directory.server.ldap.handlers.SearchHandler.handleWithReferrals(SearchHandler.java:78)
      at org.apache.directory.server.ldap.handlers.ReferralAwareRequestHandler.handle(ReferralAwareRequestHandler.java:94)
      at org.apache.directory.server.ldap.handlers.ReferralAwareRequestHandler.handle(ReferralAwareRequestHandler.java:57)
      at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:208)
      at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:58)
      at org.apache.mina.handler.demux.DemuxingIoHandler.messageReceived(DemuxingIoHandler.java:232)
      at org.apache.directory.server.ldap.LdapProtocolHandler.messageReceived(LdapProtocolHandler.java:193)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:713)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:793)
      at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:71)
      at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)
      at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.runTask(UnorderedThreadPoolExecutor.java:480)
      at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.run(UnorderedThreadPoolExecutor.java:434)
      at java.lang.Thread.run(Unknown Source)
      Caused by: org.apache.directory.shared.ldap.message.spi.ProviderException: ERR_04065 Ldap encoder failed to encode object: Search Result Entry
      entry
      ServerEntry
      dn[n]: cn=Test 01 User+givenName=Test 01+mail=test01user@test.lan+sn=User,organizationalUnitName=Test,o=Test Bedrijf, c=NL
      objectClass: organizationalPerson
      objectClass: person
      objectClass: inetOrgPerson
      objectClass: top
      sn: User
      mail: test01user@test.lan
      givenName: Test 01
      cn: Test 01 User
      x500uniqueidentifier: '0011001100111001011001100011010100110011011001100110010001100100001101110011011001100100001100110011001100110111001101000011011000110101001110010110000101100011001100000110011001100011001101000011011100110111011000100011001100110000001110000110000100110111'B
      businesscategory: Valid
      userCertificate;binary: '0x30 0x82 0x06 0xD6 0x30 0x82 0x04 0xBE 0xA0 0x03 0x02 0x01 0x02 0x02 0x10 0x39 ...'
      , error : ERR_00004 The PDU buffer size is too small !
      at org.apache.directory.shared.ldap.codec.LdapEncoder.encodeBlocking(LdapEncoder.java:139)
      at org.apache.directory.shared.ldap.codec.LdapEncoder.encode(LdapEncoder.java:200)
      at org.apache.directory.shared.ldap.message.MessageEncoder.encode(MessageEncoder.java:125)
      at org.apache.directory.shared.asn1.codec.Asn1CodecEncoder.encode(Asn1CodecEncoder.java:58)
      at org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:298)
      ... 32 more
      [16:58:09] WARN [org.apache.directory.shared.asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer.
      [16:58:09] WARN [org.apache.directory.server.ldap.LdapProtocolHandler] - Null LdapSession given to cleanUpSession.
      [16:58:09] ERROR [org.apache.directory.shared.ldap.codec.LdapEncoder] - ERR_04065 Ldap encoder failed to encode object: Search Result Entry
      entry
      ServerEntry
      dn[n]: cn=Test 01 User+givenName=Test 01+mail=test01user@test.lan+sn=User,organizationalUnitName=Test,o=Test Bedrijf, c=NL
      objectClass: organizationalPerson
      objectClass: person
      objectClass: inetOrgPerson
      objectClass: top
      sn: User
      mail: test01user@test.lan
      givenName: Test 01
      cn: Test 01 User
      x500uniqueidentifier: '0011001100111001011001100011010100110011011001100110010001100100001101110011011001100100001100110011001100110111001101000011011000110101001110010110000101100011001100000110011001100011001101000011011100110111011000100011001100110000001110000110000100110111'B
      businesscategory: Valid
      userCertificate;binary: '0x30 0x82 0x06 0xD6 0x30 0x82 0x04 0xBE 0xA0 0x03 0x02 0x01 0x02 0x02 0x10 0x39 ...'
      , error : ERR_00004 The PDU buffer size is too small !
      [16:58:09] WARN [org.apache.directory.server.ldap.LdapProtocolHandler] - Unexpected exception forcing session to close: sending disconnect notice to client.
      org.apache.mina.filter.codec.ProtocolEncoderException: org.apache.directory.shared.ldap.message.spi.ProviderException: ERR_04065 Ldap encoder failed to encode object: Search Result Entry
      entry
      ServerEntry
      dn[n]: cn=Test 01 User+givenName=Test 01+mail=test01user@test.lan+sn=User,organizationalUnitName=Test,o=Test Bedrijf, c=NL
      objectClass: organizationalPerson
      objectClass: person
      objectClass: inetOrgPerson
      objectClass: top
      sn: User
      mail: test01user@test.lan
      givenName: Test 01
      cn: Test 01 User
      x500uniqueidentifier: '0011001100111001011001100011010100110011011001100110010001100100001101110011011001100100001100110011001100110111001101000011011000110101001110010110000101100011001100000110011001100011001101000011011100110111011000100011001100110000001110000110000100110111'B
      businesscategory: Valid
      userCertificate;binary: '0x30 0x82 0x06 0xD6 0x30 0x82 0x04 0xBE 0xA0 0x03 0x02 0x01 0x02 0x02 0x10 0x39 ...'
      , error : ERR_00004 The PDU buffer size is too small !
      at org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:313)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:506)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1400(DefaultIoFilterChain.java:46)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:805)
      at org.apache.mina.filter.executor.ExecutorFilter.filterWrite(ExecutorFilter.java:706)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:506)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1400(DefaultIoFilterChain.java:46)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterWrite(DefaultIoFilterChain.java:805)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.filterWrite(DefaultIoFilterChain.java:731)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterWrite(DefaultIoFilterChain.java:506)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterWrite(DefaultIoFilterChain.java:498)
      at org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:428)
      at org.apache.mina.core.session.AbstractIoSession.write(AbstractIoSession.java:369)
      at org.apache.directory.server.ldap.handlers.SearchHandler.readResults(SearchHandler.java:334)
      at org.apache.directory.server.ldap.handlers.SearchHandler.doSimpleSearch(SearchHandler.java:749)
      at org.apache.directory.server.ldap.handlers.SearchHandler.handleIgnoringReferrals(SearchHandler.java:978)
      at org.apache.directory.server.ldap.handlers.SearchHandler.handleWithReferrals(SearchHandler.java:1054)
      at org.apache.directory.server.ldap.handlers.SearchHandler.handleWithReferrals(SearchHandler.java:78)
      at org.apache.directory.server.ldap.handlers.ReferralAwareRequestHandler.handle(ReferralAwareRequestHandler.java:94)
      at org.apache.directory.server.ldap.handlers.ReferralAwareRequestHandler.handle(ReferralAwareRequestHandler.java:57)
      at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:208)
      at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:58)
      at org.apache.mina.handler.demux.DemuxingIoHandler.messageReceived(DemuxingIoHandler.java:232)
      at org.apache.directory.server.ldap.LdapProtocolHandler.messageReceived(LdapProtocolHandler.java:193)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:713)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
      at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:793)
      at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:71)
      at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)
      at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.runTask(UnorderedThreadPoolExecutor.java:480)
      at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.run(UnorderedThreadPoolExecutor.java:434)
      at java.lang.Thread.run(Unknown Source)
      Caused by: org.apache.directory.shared.ldap.message.spi.ProviderException: ERR_04065 Ldap encoder failed to encode object: Search Result Entry
      entry
      ServerEntry
      dn[n]: cn=Test 01 User+givenName=Test 01+mail=test01user@test.lan+sn=User,organizationalUnitName=Test,o=Test Bedrijf, c=NL
      objectClass: organizationalPerson
      objectClass: person
      objectClass: inetOrgPerson
      objectClass: top
      sn: User
      mail: test01user@test.lan
      givenName: Test 01
      cn: Test 01 User
      x500uniqueidentifier: '0011001100111001011001100011010100110011011001100110010001100100001101110011011001100100001100110011001100110111001101000011011000110101001110010110000101100011001100000110011001100011001101000011011100110111011000100011001100110000001110000110000100110111'B
      businesscategory: Valid
      userCertificate;binary: '0x30 0x82 0x06 0xD6 0x30 0x82 0x04 0xBE 0xA0 0x03 0x02 0x01 0x02 0x02 0x10 0x39 ...'
      , error : ERR_00004 The PDU buffer size is too small !
      at org.apache.directory.shared.ldap.codec.LdapEncoder.encodeBlocking(LdapEncoder.java:139)
      at org.apache.directory.shared.ldap.codec.LdapEncoder.encode(LdapEncoder.java:200)
      at org.apache.directory.shared.ldap.message.MessageEncoder.encode(MessageEncoder.java:125)
      at org.apache.directory.shared.asn1.codec.Asn1CodecEncoder.encode(Asn1CodecEncoder.java:58)
      at org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:298)
      ... 32 more

        Activity

        Hide
        Emmanuel Lecharny added a comment -

        (Sorry for the late answer)

        I think the issue can com from the way we deal with BitString AttributeType (x500uniqueidentifier), which, in some cases, might require an extra byte to store the number of unused bits in the last bytes.
        In this case, we will allocate a PDU one byte short, thus the error message.

        The BitString class has been fixed 2 weeks ago, it should now work better, but it's in trunk.

        Show
        Emmanuel Lecharny added a comment - (Sorry for the late answer) I think the issue can com from the way we deal with BitString AttributeType (x500uniqueidentifier), which, in some cases, might require an extra byte to store the number of unused bits in the last bytes. In this case, we will allocate a PDU one byte short, thus the error message. The BitString class has been fixed 2 weeks ago, it should now work better, but it's in trunk.
        Hide
        Emmanuel Lecharny added a comment -

        This is nothing close the a BitString issue.

        if you get a random error when fetching this entry, that means another thread is processing another request for the same session, at the same time.

        I have to check this point, but I think it has been solved in trunk.

        Show
        Emmanuel Lecharny added a comment - This is nothing close the a BitString issue. if you get a random error when fetching this entry, that means another thread is processing another request for the same session, at the same time. I have to check this point, but I think it has been solved in trunk.
        Hide
        Emmanuel Lecharny added a comment -

        After some moe investigation, there is only one reason for such a strange behavior : that the entry being returned is modified while being encoded. Let me explain :
        when we build the list of entries to be returned, we grab them one by one from the backend storage and send them one by one to the client.
        During the send, we process the entry to first compute the length of the PDU that will be transmitted, then we transform the entry to a byte[].
        if the entry is being modified after the length of the byte[] has been computed but before the byte[] itself is generated, then the error message (PDU-buffer size is too small) might be generated.

        This is supposed not to happen, and one reason why it could have happened in 1.5.7 is that the entry we read from the backend was not correctly and entirely copied
        (we don't manipulate the entry itself, we copy it before generating the byte[], because this entry is likely to be found in a cache, and used by another thread). Once this copy has been
        done, there is only one thread that can use it.

        I'll check if the entry is correctly copied, but we may have modified this since 1.5.7. Anyway, this is an critical issue that need to be checked.

        Show
        Emmanuel Lecharny added a comment - After some moe investigation, there is only one reason for such a strange behavior : that the entry being returned is modified while being encoded. Let me explain : when we build the list of entries to be returned, we grab them one by one from the backend storage and send them one by one to the client. During the send, we process the entry to first compute the length of the PDU that will be transmitted, then we transform the entry to a byte[]. if the entry is being modified after the length of the byte[] has been computed but before the byte[] itself is generated, then the error message (PDU-buffer size is too small) might be generated. This is supposed not to happen, and one reason why it could have happened in 1.5.7 is that the entry we read from the backend was not correctly and entirely copied (we don't manipulate the entry itself, we copy it before generating the byte[], because this entry is likely to be found in a cache, and used by another thread). Once this copy has been done, there is only one thread that can use it. I'll check if the entry is correctly copied, but we may have modified this since 1.5.7. Anyway, this is an critical issue that need to be checked.
        Hide
        Néher Márton added a comment -

        Same error here as well, with userCertificate (multi valued binary field), ApacheDS 1.5.7 and Ubuntu Linux.
        This happens both storing or deleting certificate.

        Show
        Néher Márton added a comment - Same error here as well, with userCertificate (multi valued binary field), ApacheDS 1.5.7 and Ubuntu Linux. This happens both storing or deleting certificate.
        Hide
        Emmanuel Lecharny added a comment -

        Is it possible that you attache the entry with the certificate that makes the server having trouble ? (of course, not your certificate, but a faked one)

        Show
        Emmanuel Lecharny added a comment - Is it possible that you attache the entry with the certificate that makes the server having trouble ? (of course, not your certificate, but a faked one)
        Hide
        Néher Márton added a comment -

        Sure.
        I uploaded the log here: http://pastebin.com/4uF0QsZ1
        The certificate is the following: http://pastebin.com/Ea0HDenM the difference is that it gets to the LDAP DER encoded, not PEM.
        I commented out a few bytes, that is way more simple than changeing my ca cert/key.
        I cannot really provide LDIF, because I am accessing Apache Direcotry Server with DataNucleus LDAP module.

        Show
        Néher Márton added a comment - Sure. I uploaded the log here: http://pastebin.com/4uF0QsZ1 The certificate is the following: http://pastebin.com/Ea0HDenM the difference is that it gets to the LDAP DER encoded, not PEM. I commented out a few bytes, that is way more simple than changeing my ca cert/key. I cannot really provide LDIF, because I am accessing Apache Direcotry Server with DataNucleus LDAP module.
        Hide
        Emmanuel Lecharny added a comment -

        I tried to reproduce the error, with a certificate I have (because otherwise the cretificate is rejected by studio), and I have no problem.

        I'm afraid that we have to find a way to analyze what's going on on your server, as I can't reproduce the problem.

        You may contact me directly (elecharny@apache.org) to see how we can proceed...

        Show
        Emmanuel Lecharny added a comment - I tried to reproduce the error, with a certificate I have (because otherwise the cretificate is rejected by studio), and I have no problem. I'm afraid that we have to find a way to analyze what's going on on your server, as I can't reproduce the problem. You may contact me directly (elecharny@apache.org) to see how we can proceed...
        Hide
        Pierre-Arnaud Marcelot added a comment -

        Version 2.0.0-M1 has been released.
        Moving all related non-resolved issues to the next version.

        Show
        Pierre-Arnaud Marcelot added a comment - Version 2.0.0-M1 has been released. Moving all related non-resolved issues to the next version.
        Hide
        Pierre-Arnaud Marcelot added a comment -

        Version 2.0.0-M3 has been released a couple months ago.

        Assigned the remaining opened JIRA to the next iteration (2.0.0-M4).

        Show
        Pierre-Arnaud Marcelot added a comment - Version 2.0.0-M3 has been released a couple months ago. Assigned the remaining opened JIRA to the next iteration (2.0.0-M4).
        Hide
        Emmanuel Lecharny added a comment -

        This is not n error, and the log level was wrong. I downgraded it to DEBUG.

        Show
        Emmanuel Lecharny added a comment - This is not n error, and the log level was wrong. I downgraded it to DEBUG.

          People

          • Assignee:
            Unassigned
            Reporter:
            Ewald Wasscher
          • Votes:
            1 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development