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 We are using the Apache Directory LDAP API (v2) library for the connection. We are using a pooled connection to the LDAP server. We are using StartTLS to secure the connections between the Java service

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

We are using the Apache Directory LDAP API (v2) library for the connection.
We are using a pooled connection to the LDAP server.
We are using StartTLS to secure the connections between the Java service and the LDAP server.
We are not actually authenticating against the LDAP server from here!
- Our API gateway handles authentication (against the same LDAP service).
- We are doing two thing in our code:
  - Fetching more data on the user (when receiving API requests) and
  - Updating the LDPA from a service that keeps it synchronised with another source.

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:

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:

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?
Does anyone have any info on the javax.net.ssl.SSLException: Outbound done exception? is it related and how to solve it?

Answer

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

Advertisement

Answer