Hi, I have come across a problem when using the client API to interact with the
server. When iterating through a cursor, the client hangs in the library code,
consuming 100% of a CPU core. I am using a 64-bit Oracle JDK version 1.8.0_73,
to run ApacheDS 2.0.0-M20 as the server. The same JDK is used to run my client
application, which has the following maven dependency for interacting with the
server: <dependency>
<groupId>org.apache.directory.server</groupId>
<artifactId>apacheds-core-api</artifactId>
<version>2.0.0-M20</version> </dependency> Now, the piece of code
that causes the problem is this: EntryCursor allGroupsCursor = null;
try { allGroupsCursor =
ldapConn.search(GlobalContext.getLdapGroupsBaseDn(),
GlobalContext.getLdapGroupsFilter(), GlobalContext.getLdapGroupsScope());
for (Entry groupEntry : allGroupsCursor) { String dn =
groupEntry.getDn().getName(); Group group =
loadGroupFromEntry(groupEntry); model.allGroups.put(dn, group);
} } finally { if (allGroupsCursor != null)
allGroupsCursor.close(); } Here is the thread that executes this
code: "RepeatingExecutorService Thread 1" #22 prio=5 os_prio=0
tid=0x00000000239ab000 nid=0xea8 waiting on condition [0x00002ab39ec3f000]
java.lang.Thread.State: TIMED_WAITING (parking) at
sun.misc.Unsafe.park(Native Method) - parking to wait for
<0x00000000866c1e88> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at
java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
at
org.apache.directory.ldap.client.api.future.ResponseFuture.get(ResponseFuture.java:130)
at
org.apache.directory.ldap.client.api.future.SearchFuture.get(SearchFuture.java:69)
at
org.apache.directory.ldap.client.api.SearchCursorImpl.next(SearchCursorImpl.java:119)
at
org.apache.directory.ldap.client.api.EntryCursorImpl.next(EntryCursorImpl.java:90)
at
org.apache.directory.api.ldap.model.cursor.CursorIterator.next(CursorIterator.java:81)
at com.playground.ModelService.loadAllGroups(ModelService.java:127) So
my understanding is that the client thread is parked waiting for another “I/O
worker” thread to fetch the next entry in the cursor. Looking at all the
threads from my dump, it has to be this one: "NioProcessor-35" #95 prio=5
os_prio=0 tid=0x0000000013536000 nid=0x2924 runnable [0x00002ab39fa09000]
java.lang.Thread.State: RUNNABLE at
sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) - locked
<0x00000000867943f0> (a java.lang.Object) at
javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) at
org.apache.mina.filter.ssl.SslHandler.unwrap(SslHandler.java:743) at
org.apache.mina.filter.ssl.SslHandler.messageReceived(SslHandler.java:359)
at org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:489)
- locked <0x00000000867942f8> (a org.apache.mina.filter.ssl.SslHandler)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:542)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:48)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:943)
at
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:109)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:542)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:535)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:718)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:672)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:661)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1130)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745) I’ve taken several stack dumps
and this thread has been stuck there for hours. I’ve tried running “kill -3
PID” in quick succession and the thread seems to allways be there, inside the
JDK’s SSL unwrap method, but it does seem to spin fast and I once managed catch
it when advancing to the next message: "NioProcessor-35" #95 prio=5 os_prio=0
tid=0x0000000013536000 nid=0x2924 runnable [0x00002ab39fa09000]
java.lang.Thread.State: RUNNABLE at
sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) - locked
<0x00000000867943f0> (a java.lang.Object) at
javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) at
org.apache.mina.filter.ssl.SslHandler.unwrap(SslHandler.java:743) at
org.apache.mina.filter.ssl.SslHandler.messageReceived(SslHandler.java:359)
at org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:489)
- locked <0x00000000867942f8> (a
org.apache.mina.filter.ssl.SslHandler)--"NioProcessor-35" #95 prio=5 os_prio=0
tid=0x0000000013536000 nid=0x2924 runnable [0x00002ab39fa09000]
java.lang.Thread.State: RUNNABLE at
org.apache.mina.filter.ssl.SslHandler.unwrap(SslHandler.java:756) at
org.apache.mina.filter.ssl.SslHandler.messageReceived(SslHandler.java:359)
at org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:489)
- locked <0x00000000867942f8> (a org.apache.mina.filter.ssl.SslHandler)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:542)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:48)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:943)
I seems to me like the MINA code may be caught in an endless loop, because the
application is not running out of memory (if the server was actually sending an
endless list of items, I’d expect that heap usage would grow until I get an
OutOfMemory error). Furthermore, there is no indication that the server is
actually sending out tons of data (server process is at 0% usage). Is there
anything I can do to track down the source of this so that it may be fixed? Any
debug logging I can enable (on the client or server or both) that may help shed
some light on what’s happening?
