javaldapconnection-poolingopenldapapache-directory

LDAP Pooled Connection from Apache Java Library - Do We Need to unbind

We are connecting to an LDAP (OpenLDAP) service from a Java (Spring Boot) application. We are having issues with TLS and with memory usage.

Background

Memory Issues

We are getting out-of-memory errors on the Java service. The stack trace looks like:

Exception in thread "pool-2454-thread-1" java.lang.OutOfMemoryError: Java heap space
    at java.util.HashMap.resize(HashMap.java:704)
    at java.util.HashMap.putVal(HashMap.java:629)
    at java.util.HashMap.put(HashMap.java:612)
    at sun.security.util.MemoryCache.put(Cache.java:365)
    at sun.security.ssl.SSLSessionContextImpl.put(SSLSessionContextImpl.java:181)
    at sun.security.ssl.ClientHandshaker.serverFinished(ClientHandshaker.java:1293)
    at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:379)
    at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1082)
    at sun.security.ssl.Handshaker.process_record(Handshaker.java:1010)
    at sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:1032)
    at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:913)
    at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:783)
    at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:626)
    at org.apache.mina.filter.ssl.SslHandler.unwrap(SslHandler.java:774)
    at org.apache.mina.filter.ssl.SslHandler.unwrapHandshake(SslHandler.java:710)
    at org.apache.mina.filter.ssl.SslHandler.handshake(SslHandler.java:596)
    at org.apache.mina.filter.ssl.SslHandler.messageReceived(SslHandler.java:355)
    at org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:517)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128)
    at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:643)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:539)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$1200(AbstractPollingIoProcessor.java:68)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1222)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1211)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:683)
    at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-10-13 10:03:23.388677637+03:00 Starting: /etc/alternatives/jre/bin/java -Xms128M -Xmx256M -Dlogging.config=/services/registry.svc/log4j2.json -jar

My colleague debugged a simple API with 128m memory on the JVM and the LDAP pool looked to be using a lot of memory for not doing much: memory usage of LDAP connection pool

I noticed that the code was doing unbind after making the queries. This smelt wrong - we are not binding as each user, we have a single (read-only) user that the API services connect as that allows them to read details on the user connecting and another (read-write) user for the synch service. As I understand it, bind is like login and from using other connection pools that's what you don't do each time. I wondered if by unbinding but not closing we were leaving zombie connections and eating memory?

SSL Issues

However, if we don't unbind we get the following error appearing quite a lot in the logs, without any reasonable way to find where it comes from. Haven't found much on it:

2020-10-14 11:08:57.817 [NioProcessor-3] WARN  org.apache.directory.ldap.client.api.LdapNetworkConnection - Outbound done [MDC: {}]
javax.net.ssl.SSLException: Outbound done
    at org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:513) ~[mina-core-2.1.3.jar:?]
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:643) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:539) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$1200(AbstractPollingIoProcessor.java:68) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1222) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1211) [mina-core-2.1.3.jar:?]
    at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:683) [mina-core-2.1.3.jar:?]
    at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64) [mina-core-2.1.3.jar:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:1.8.0_261]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:1.8.0_261]
    at java.lang.Thread.run(Unknown Source) [?:1.8.0_261]

Possible Work-Around

I did find some examples online that suggested a pattern like:

if (connection.isConnected() && connection.isAuthenticated()) {
    connection.bind();
try {
    // do stuff
} finally {
    connection.unBind();
}

But this feels wrong - or at least a work-around

Question

So, two parts to my question:

  1. Should we be binding and unbinding each query (even though we are always authenticated as the same user), or are we losing the benefit of the pool then?
  2. Does anyone have any info on the javax.net.ssl.SSLException: Outbound done exception? is it related and how to solve it?
Solution

  • So, it seems I was wrong to close the connection. I assumed that, when getting a connection from a pool if I "close" the connection it returned it to the pool. Seems it closed it but kept it in the pool (maybe left borrowed, maybe just unusable, didn't investigate that far). It seems I need instead to return it to the pool, and to keep a reference to the pool for that.

    I had a function (actually an injected service) that handles the pool and returns a connection. What I was trying to do was:

    try (final LdapConnection connection = ldapService.getConnection()) {
   // Do stuff with connection
}

    What I ended up doing was defining a class like:

    /**
 * Wraps a connection from a connection pool such that close with release it back to the pool.
 *
 * <p>You need a reference to the pool in order to release it, so using a wrapper</p>
 */
public class PooledLdapConnection implements Closeable {

  private final LdapConnection connection;
  private final LdapConnectionPool pool;

  public PooledLdapConnection(final LdapConnection connection, final LdapConnectionPool pool) {
    this.connection = connection;
    this.pool = pool;
  }

  public LdapConnection getConnection() {
    return connection;
  }

  @Override
  public void close() throws IOException {
    if (pool != null) {
      try {
        pool.releaseConnection(connection);
      } catch (final LdapException e) {
        throw new IOException(e.getMessage(), e);
      }
    }
  }
}

    Then my LDAP service now returns that - in the function, instead of just returning pool.getConnection() I return new PooledLdapConnection(pool.getConnection(), pool)

    Then I can

    try (final PooledLdapConnection connection = ldapService.getConnection()) {
   // Do stuff with connection.getConnection()
}

    and when it completes and "closes" it actually just returns to the pool. I could have implemented the LdapConnection interface with my PooledLdapConnection and simply proxied the implementation of all the functions except close directly to my underlying connection object, but this was easier, and also won't need refactoring if the interface is ever updated.

    I do feel this is what the library should have done for me! The implementation returned by the pool should be a different object than the one returned by getting a single connection, with the difference being in what the auto-close does. But this seems to work.

    I have one remaining issue. We had a misconfiguration of the DNS in our development environment, so it pointed at the wrong server for trying to connect to an LDAP. In this case, it still ate connections until we hit the java file limit. Haven't investigated that further yet