directory-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Emmanuel Lecharny (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (DIRAPI-236) Unbind during search hangs
Date Sun, 26 Apr 2015 15:50:38 GMT

    [ 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)

Mime
View raw message