directory-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "akarypid@yahoo.gr" <akary...@yahoo.gr>
Subject Client API hangs spinning in MINA code, eating 100% CPU
Date Thu, 11 Feb 2016 16:31:28 GMT
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?  

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message