[
https://issues.apache.org/jira/browse/DIRAPI-236?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14513102#comment-14513102
]
Emmanuel Lecharny commented on DIRAPI-236:
------------------------------------------
Here is the stack trace when the client hangs :
{code}
2015-04-26 17:44:30
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.5-b02 mixed mode):
"YJPAgent-OOMESnapshotDetector" #29 daemon prio=10 os_prio=31
tid=0x00007fdd2b0b4800 nid=0x6a0b runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"YJPAgent-CPUSampler" #28 daemon prio=10 os_prio=31 tid=0x00007fdd2ba18800
nid=0x7207 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"YJPAgent-RequestListener" #27 daemon prio=1 os_prio=31 tid=0x00007fdd2b0b4000
nid=0x7007 runnable [0x00000001295e0000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at
java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404)
at java.net.ServerSocket.implAccept(ServerSocket.java:545)
at java.net.ServerSocket.accept(ServerSocket.java:513)
at com.yourkit.runtime.Core$4.run(Core.java:717)
at java.lang.Thread.null (Redefined)
"YJPAgent-Telemetry" #26 daemon prio=5 os_prio=31 tid=0x00007fdd2ca71800
nid=0x6e07 waiting on condition [0x00000001294dd000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at com.yourkit.util.Util.sleep(Util.java:60)
at com.yourkit.runtime.TelemetryThread.run(TelemetryThread.java:573)
"Attach Listener" #25 daemon prio=9 os_prio=31 tid=0x00007fdd2b0b3000
nid=0x5b07 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"NioSocketAcceptor-2" #19 prio=5 os_prio=31 tid=0x00007fdd2c8ef800 nid=0x440b
runnable [0x0000000127889000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:202)
at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
- locked <0x00000006c14d2518> (a sun.nio.ch.Util$2)
- locked <0x00000006c14d2508> (a java.util.Collections$UnmodifiableSet)
- locked <0x00000006c14d23d8> (a sun.nio.ch.KQueueSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
at
org.apache.mina.transport.socket.nio.NioSocketAcceptor.select(NioSocketAcceptor.java:281)
at
org.apache.mina.core.polling.AbstractPollingIoAcceptor$Acceptor.run(AbstractPollingIoAcceptor.java:452)
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.null (Redefined)
"NioSocketAcceptor-1" #18 prio=5 os_prio=31 tid=0x00007fdd2b8da000 nid=0x3b07
runnable [0x0000000127319000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:202)
at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
- locked <0x00000006c14e9e50> (a sun.nio.ch.Util$2)
- locked <0x00000006c14e9e40> (a java.util.Collections$UnmodifiableSet)
- locked <0x00000006c14e9d20> (a sun.nio.ch.KQueueSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
at
org.apache.mina.transport.socket.nio.NioSocketAcceptor.select(NioSocketAcceptor.java:281)
at
org.apache.mina.core.polling.AbstractPollingIoAcceptor$Acceptor.run(AbstractPollingIoAcceptor.java:452)
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.null (Redefined)
"kdc%0052eplay%0043ache.data" #16 prio=5 os_prio=31 tid=0x00007fdd2ba9f800
nid=0x6703 waiting on condition [0x0000000126e2c000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c026bd58> (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.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.null (Redefined)
"group%0043ache.data" #15 prio=5 os_prio=31 tid=0x00007fdd2ba9f000 nid=0x6503
waiting on condition [0x0000000126d29000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c026bfb8> (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.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.null (Redefined)
"ou=system.data" #14 prio=5 os_prio=31 tid=0x00007fdd2aa52800 nid=0x6303
waiting on condition [0x0000000126c26000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c026c1f8> (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.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.null (Redefined)
"Statistics Thread-2810fae9-ea58-4421-ba79-a6d5f38dfe3e-1" #13 daemon prio=5
os_prio=31 tid=0x00007fdd2aa0b000 nid=0x6103 waiting on condition
[0x0000000126b23000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c01edbb0> (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.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.null (Redefined)
"change%0050wd%0052eplay%0043ache.data" #12 prio=5 os_prio=31
tid=0x00007fdd2bac0000 nid=0x5f03 waiting on condition [0x0000000126a20000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c01fd6c0> (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.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.null (Redefined)
"2810fae9-ea58-4421-ba79-a6d5f38dfe3e" #11 daemon prio=5 os_prio=31
tid=0x00007fdd2aa10000 nid=0x5d03 in Object.wait() [0x0000000126133000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000006c0201690> (a java.util.TaskQueue)
at java.lang.Object.wait(Object.java:502)
at java.util.TimerThread.mainLoop(Timer.java:526)
- locked <0x00000006c0201690> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:505)
"Service Thread" #9 daemon prio=9 os_prio=31 tid=0x00007fdd2b002000 nid=0x5703
runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C1 CompilerThread3" #8 daemon prio=9 os_prio=31 tid=0x00007fdd2a869000
nid=0x5503 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread2" #7 daemon prio=9 os_prio=31 tid=0x00007fdd2a848000
nid=0x5303 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread1" #6 daemon prio=9 os_prio=31 tid=0x00007fdd2b823000
nid=0x5103 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #5 daemon prio=9 os_prio=31 tid=0x00007fdd2a018000
nid=0x4f03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007fdd2a017800
nid=0x4d03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007fdd2a846800 nid=0x3903 in
Object.wait() [0x0000000125240000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:142)
- locked <0x00000006c002fcf0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:158)
at java.lang.ref.Finalizer$FinalizerThread.null (Redefined)
"Reference Handler" #2 daemon prio=10 os_prio=31 tid=0x00007fdd2a845800
nid=0x3703 in Object.wait() [0x000000012513d000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference$ReferenceHandler.null (Redefined)
- locked <0x00000006c0030a70> (a java.lang.ref.Reference$Lock)
"main" #1 prio=5 os_prio=31 tid=0x00007fdd2c800800 nid=0x1903 waiting on
condition [0x000000010773e000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c1644d70> (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.shared.client.api.operations.bind.SimpleBindRequestTest.null
(Redefined)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at
org.apache.directory.server.core.integ.FrameworkRunner.runChild(FrameworkRunner.java:379)
at
org.apache.directory.server.core.integ.FrameworkRunner.runChild(FrameworkRunner.java:56)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at
org.apache.directory.server.core.integ.FrameworkRunner.run(FrameworkRunner.java:154)
at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.null
(Redefined)
at org.eclipse.jdt.internal.junit.runner.TestExecution.null (Redefined)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.null
(Redefined)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.null
(Redefined)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.null
(Redefined)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.null
(Redefined)
"VM Thread" os_prio=31 tid=0x00007fdd2a009800 nid=0x3503 runnable
"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007fdd2a81a800 nid=0x2503
runnable
"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007fdd2a81b000 nid=0x2703
runnable
"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007fdd2b807000 nid=0x2903
runnable
"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007fdd2b807800 nid=0x2b03
runnable
"GC task thread#4 (ParallelGC)" os_prio=31 tid=0x00007fdd2b808000 nid=0x2d03
runnable
"GC task thread#5 (ParallelGC)" os_prio=31 tid=0x00007fdd2b809000 nid=0x2f03
runnable
"GC task thread#6 (ParallelGC)" os_prio=31 tid=0x00007fdd2b809800 nid=0x3103
runnable
"GC task thread#7 (ParallelGC)" os_prio=31 tid=0x00007fdd2b80a000 nid=0x3303
runnable
"VM Periodic Task Thread" os_prio=31 tid=0x00007fdd2a063800 nid=0x5903 waiting
on condition
JNI global references: 573850
Heap
PSYoungGen total 72704K, used 17885K [0x000000076ab00000,
0x0000000770600000, 0x00000007c0000000)
eden space 67072K, 26% used
[0x000000076ab00000,0x000000076bc77510,0x000000076ec80000)
from space 5632K, 0% used
[0x000000076ec80000,0x000000076ec80000,0x000000076f200000)
to space 5632K, 0% used
[0x0000000770080000,0x0000000770080000,0x0000000770600000)
ParOldGen total 30720K, used 25061K [0x00000006c0000000,
0x00000006c1e00000, 0x000000076ab00000)
object space 30720K, 81% used
[0x00000006c0000000,0x00000006c18795e0,0x00000006c1e00000)
Metaspace used 22696K, capacity 22888K, committed 23344K, reserved
1069056K
class space used 2784K, capacity 2817K, committed 2944K, reserved 1048576K
{code}
It seems we are waiting on the {{SearchFuture}} forever. There is something
wrong in the Search/Unbind/Cursor.next() sequence handling...
> Unbind during search hangs
> --------------------------
>
> Key: DIRAPI-236
> URL: https://issues.apache.org/jira/browse/DIRAPI-236
> Project: Directory Client API
> Issue Type: Bug
> Affects Versions: 1.0.0-M29
> Reporter: Stefan Seelmann
> Fix For: 1.0.0-M30
>
>
> Calling LdapNetworkConnection.unbind() while iterating over an EntryCursor
> lets the iterator hang, either infinite (if timelimit is 0) or till the
> timeout occurs.
> Here is the part of a thread dump:
> {noformat}
> "main" prio=10 tid=0x00007f3e5400b800 nid=0x117f waiting on condition
> [0x00007f3e5c5ab000]
> java.lang.Thread.State: TIMED_WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for <0x00000000e310c000> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at
> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
> at
> java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
> at
> org.apache.directory.ldap.client.api.future.ResponseFuture.get(ResponseFuture.java:133)
> at
> org.apache.directory.ldap.client.api.future.SearchFuture.get(SearchFuture.java:69)
> at
> org.apache.directory.ldap.client.api.SearchCursorImpl.next(SearchCursorImpl.java:121)
> at
> org.apache.directory.ldap.client.api.EntryCursorImpl.next(EntryCursorImpl.java:90)
> at
> org.apache.directory.shared.client.api.operations.bind.SimpleBindRequestTest.testUnbindDuringSearch(SimpleBindRequestTest.java:635)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
