Add read latency of the rocksDB index. #15
Comments
merlimat
pushed a commit
that referenced
this issue
Jan 5, 2024
### Motivation
The auditor didn't close the ledger manager and ledger under replication manager the thread will leak.
Run the test `AuditorPeriodicBookieCheckTest` and get the stack.
## Before this PR:
```
Full thread dump Java HotSpot(TM) 64-Bit Server VM (11.0.15+8-LTS-149 mixed mode):
Threads class SMR info:
_java_thread_list=0x0000600003e44460, length=16, elements={
0x00007fad34009000, 0x00007fad45032800, 0x00007fad14813800, 0x00007fad44010800,
0x00007fad44011800, 0x00007fad45037800, 0x00007fad3400a000, 0x00007fad45812800,
0x00007fad34944000, 0x00007fad4585f800, 0x00007fad45456000, 0x00007fad4444c000,
0x00007fad3431b800, 0x00007face5825800, 0x00007face5860800, 0x00007face4009800
}
"main" #1 prio=5 os_prio=31 cpu=1801.68ms elapsed=20.85s tid=0x00007fad34009000 nid=0x2a03 waiting on condition [0x000000030a10d000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079f26a8a0> (a java.util.concurrent.FutureTask)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.15/LockSupport.java:234)
at java.util.concurrent.FutureTask.awaitDone(java.base@11.0.15/FutureTask.java:444)
at java.util.concurrent.FutureTask.get(java.base@11.0.15/FutureTask.java:203)
at org.junit.internal.runners.statements.FailOnTimeout.getResult(FailOnTimeout.java:141)
at org.junit.internal.runners.statements.FailOnTimeout.evaluate(FailOnTimeout.java:127)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
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.junit.runner.JUnitCore.run(JUnitCore.java:137)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69)
at com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
at com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)
Locked ownable synchronizers:
- None
"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=2.14ms elapsed=20.82s tid=0x00007fad45032800 nid=0x4803 waiting on condition [0x000000030a823000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.15/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.15/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.15/Reference.java:213)
Locked ownable synchronizers:
- None
"Finalizer" #3 daemon prio=8 os_prio=31 cpu=1.33ms elapsed=20.82s tid=0x00007fad14813800 nid=0x5503 in Object.wait() [0x000000030a926000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.15/Native Method)
- waiting on <0x00000007801b6f18> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000007801b6f18> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.15/Finalizer.java:170)
Locked ownable synchronizers:
- None
"Signal Dispatcher" #4 daemon prio=9 os_prio=31 cpu=2.69ms elapsed=20.81s tid=0x00007fad44010800 nid=0x5b03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Service Thread" #5 daemon prio=9 os_prio=31 cpu=0.03ms elapsed=20.81s tid=0x00007fad44011800 nid=0x7403 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C2 CompilerThread0" #6 daemon prio=9 os_prio=31 cpu=1986.68ms elapsed=20.81s tid=0x00007fad45037800 nid=0x5d03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
Locked ownable synchronizers:
- None
"C1 CompilerThread0" #9 daemon prio=9 os_prio=31 cpu=769.61ms elapsed=20.81s tid=0x00007fad3400a000 nid=0x7003 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
Locked ownable synchronizers:
- None
"Sweeper thread" #10 daemon prio=9 os_prio=31 cpu=0.08ms elapsed=20.81s tid=0x00007fad45812800 nid=0x6e03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Common-Cleaner" #11 daemon prio=8 os_prio=31 cpu=11.62ms elapsed=20.73s tid=0x00007fad34944000 nid=0x6b03 in Object.wait() [0x000000030b049000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.15/Native Method)
- waiting on <0x00000007801b7550> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000007801b7550> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@11.0.15/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
at jdk.internal.misc.InnocuousThread.run(java.base@11.0.15/InnocuousThread.java:134)
Locked ownable synchronizers:
- None
"Monitor Ctrl-Break" #12 daemon prio=5 os_prio=31 cpu=21.16ms elapsed=20.65s tid=0x00007fad4585f800 nid=0x6a03 runnable [0x000000030b14c000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(java.base@11.0.15/Native Method)
at java.net.SocketInputStream.socketRead(java.base@11.0.15/SocketInputStream.java:115)
at java.net.SocketInputStream.read(java.base@11.0.15/SocketInputStream.java:168)
at java.net.SocketInputStream.read(java.base@11.0.15/SocketInputStream.java:140)
at sun.nio.cs.StreamDecoder.readBytes(java.base@11.0.15/StreamDecoder.java:284)
at sun.nio.cs.StreamDecoder.implRead(java.base@11.0.15/StreamDecoder.java:326)
at sun.nio.cs.StreamDecoder.read(java.base@11.0.15/StreamDecoder.java:178)
- locked <0x00000007801b81e8> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(java.base@11.0.15/InputStreamReader.java:181)
at java.io.BufferedReader.fill(java.base@11.0.15/BufferedReader.java:161)
at java.io.BufferedReader.readLine(java.base@11.0.15/BufferedReader.java:326)
- locked <0x00000007801b81e8> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(java.base@11.0.15/BufferedReader.java:392)
at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:56)
Locked ownable synchronizers:
- None
"Log4j2-TF-2-Scheduled-1" #13 daemon prio=5 os_prio=31 cpu=3.80ms elapsed=19.18s tid=0x00007fad45456000 nid=0x8c03 waiting on condition [0x000000030bb6a000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x00000007805c1f78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.15/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.15/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:1182)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.15/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.15/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.15/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"Time-limited test" #15 daemon prio=5 os_prio=31 cpu=1344.20ms elapsed=18.79s tid=0x00007fad4444c000 nid=0x9107 waiting on condition [0x000000030bd70000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.15/Native Method)
at org.apache.bookkeeper.replication.AuditorPeriodicBookieCheckTest.tearDown(AuditorPeriodicBookieCheckTest.java:81)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.15/Native Method)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.15/NativeMethodAccessorImpl.java:62)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.15/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.15/Method.java:566)
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.RunAfters.evaluate(RunAfters.java:33)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
at java.util.concurrent.FutureTask.run(java.base@11.0.15/FutureTask.java:264)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"ZkLedgerManagerScheduler-48-1" apache#165 prio=5 os_prio=31 cpu=9.25ms elapsed=16.04s tid=0x00007fad3431b800 nid=0x25b03 waiting on condition [0x0000000314d1a000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079db6aed0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.15/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.15/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:1170)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.15/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.15/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.15/ThreadPoolExecutor.java:628)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"ZkLedgerManagerScheduler-49-1" apache#166 prio=5 os_prio=31 cpu=1.01ms elapsed=16.04s tid=0x00007face5825800 nid=0x25903 waiting on condition [0x0000000314e1d000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079db6b3f0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.15/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.15/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:1170)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.15/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.15/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.15/ThreadPoolExecutor.java:628)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"ForkJoinPool.commonPool-worker-19" apache#187 daemon prio=5 os_prio=31 cpu=1.52ms elapsed=15.64s tid=0x00007face5860800 nid=0x2ca03 waiting on condition [0x0000000316259000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079ef3f6e8> (a java.util.concurrent.ForkJoinPool)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.15/LockSupport.java:194)
at java.util.concurrent.ForkJoinPool.runWorker(java.base@11.0.15/ForkJoinPool.java:1628)
at java.util.concurrent.ForkJoinWorkerThread.run(java.base@11.0.15/ForkJoinWorkerThread.java:183)
Locked ownable synchronizers:
- None
"Attach Listener" apache#313 daemon prio=9 os_prio=31 cpu=1.90ms elapsed=0.24s tid=0x00007face4009800 nid=0x3d53b waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"VM Thread" os_prio=31 cpu=122.89ms elapsed=20.84s tid=0x00007fad1405f000 nid=0x4e03 runnable
"GC Thread#0" os_prio=31 cpu=67.63ms elapsed=20.85s tid=0x00007fad3480c000 nid=0x3b03 runnable
"GC Thread#1" os_prio=31 cpu=60.78ms elapsed=20.16s tid=0x00007fad45203800 nid=0x8233 runnable
"GC Thread#2" os_prio=31 cpu=56.71ms elapsed=20.16s tid=0x00007fad45039800 nid=0x8403 runnable
"GC Thread#3" os_prio=31 cpu=59.80ms elapsed=20.16s tid=0x00007fad45341800 nid=0xa703 runnable
"GC Thread#4" os_prio=31 cpu=60.21ms elapsed=20.16s tid=0x00007fad45342000 nid=0x8503 runnable
"GC Thread#5" os_prio=31 cpu=60.89ms elapsed=20.16s tid=0x00007fad4536d000 nid=0xa503 runnable
"GC Thread#6" os_prio=31 cpu=57.91ms elapsed=20.16s tid=0x00007fad4594a800 nid=0x8803 runnable
"GC Thread#7" os_prio=31 cpu=56.48ms elapsed=20.16s tid=0x00007fad4594b800 nid=0xa403 runnable
"GC Thread#8" os_prio=31 cpu=56.38ms elapsed=20.16s tid=0x00007fad4536e000 nid=0x8a03 runnable
"G1 Main Marker" os_prio=31 cpu=2.03ms elapsed=20.85s tid=0x00007fad3482d000 nid=0x3a03 runnable
"G1 Conc#0" os_prio=31 cpu=12.67ms elapsed=20.85s tid=0x00007fad4500d800 nid=0x5403 runnable
"G1 Conc#1" os_prio=31 cpu=14.15ms elapsed=18.88s tid=0x00007fad45470800 nid=0x8d4f runnable
"G1 Refine#0" os_prio=31 cpu=2.03ms elapsed=20.84s tid=0x00007fad3492d800 nid=0x4103 runnable
"G1 Young RemSet Sampling" os_prio=31 cpu=5.41ms elapsed=20.84s tid=0x00007fad14008800 nid=0x5103 runnable
"VM Periodic Task Thread" os_prio=31 cpu=14.86ms elapsed=20.64s tid=0x00007fad3494b000 nid=0x680f waiting on condition
JNI global refs: 20, weak refs: 0
```
## After this PR:
```
Full thread dump Java HotSpot(TM) 64-Bit Server VM (11.0.15+8-LTS-149 mixed mode):
Threads class SMR info:
_java_thread_list=0x00006000020b8540, length=14, elements={
0x00007ff536808800, 0x00007ff53311f800, 0x00007ff533021800, 0x00007ff53485f000,
0x00007ff53500f000, 0x00007ff535010000, 0x00007ff53500c000, 0x00007ff53400d800,
0x00007ff536861800, 0x00007ff536053000, 0x00007ff53621c800, 0x00007ff536178800,
0x00007ff5357e2000, 0x00007ff4d3009800
}
"main" #1 prio=5 os_prio=31 cpu=1768.54ms elapsed=23.32s tid=0x00007ff536808800 nid=0x2a03 waiting on condition [0x000000030630b000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079f31ab80> (a java.util.concurrent.FutureTask)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.15/LockSupport.java:234)
at java.util.concurrent.FutureTask.awaitDone(java.base@11.0.15/FutureTask.java:444)
at java.util.concurrent.FutureTask.get(java.base@11.0.15/FutureTask.java:203)
at org.junit.internal.runners.statements.FailOnTimeout.getResult(FailOnTimeout.java:141)
at org.junit.internal.runners.statements.FailOnTimeout.evaluate(FailOnTimeout.java:127)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
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.junit.runner.JUnitCore.run(JUnitCore.java:137)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69)
at com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
at com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)
Locked ownable synchronizers:
- None
"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=1.79ms elapsed=23.29s tid=0x00007ff53311f800 nid=0x4d03 waiting on condition [0x0000000306a21000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.15/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.15/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.15/Reference.java:213)
Locked ownable synchronizers:
- None
"Finalizer" #3 daemon prio=8 os_prio=31 cpu=1.34ms elapsed=23.29s tid=0x00007ff533021800 nid=0x5503 in Object.wait() [0x0000000306b24000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.15/Native Method)
- waiting on <0x00000007801c5b68> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000007801c5b68> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.15/Finalizer.java:170)
Locked ownable synchronizers:
- None
"Signal Dispatcher" #4 daemon prio=9 os_prio=31 cpu=1.44ms elapsed=23.27s tid=0x00007ff53485f000 nid=0x5b03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Service Thread" #5 daemon prio=9 os_prio=31 cpu=0.03ms elapsed=23.27s tid=0x00007ff53500f000 nid=0x7503 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C2 CompilerThread0" #6 daemon prio=9 os_prio=31 cpu=1882.60ms elapsed=23.27s tid=0x00007ff535010000 nid=0x7403 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
Locked ownable synchronizers:
- None
"C1 CompilerThread0" #9 daemon prio=9 os_prio=31 cpu=768.63ms elapsed=23.27s tid=0x00007ff53500c000 nid=0x6003 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
Locked ownable synchronizers:
- None
"Sweeper thread" #10 daemon prio=9 os_prio=31 cpu=0.05ms elapsed=23.27s tid=0x00007ff53400d800 nid=0x6203 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Common-Cleaner" #11 daemon prio=8 os_prio=31 cpu=8.06ms elapsed=23.20s tid=0x00007ff536861800 nid=0x6403 in Object.wait() [0x0000000307245000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.15/Native Method)
- waiting on <0x00000007801c6678> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000007801c6678> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@11.0.15/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
at jdk.internal.misc.InnocuousThread.run(java.base@11.0.15/InnocuousThread.java:134)
Locked ownable synchronizers:
- None
"Monitor Ctrl-Break" #12 daemon prio=5 os_prio=31 cpu=19.84ms elapsed=23.11s tid=0x00007ff536053000 nid=0x6c03 runnable [0x0000000307348000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(java.base@11.0.15/Native Method)
at java.net.SocketInputStream.socketRead(java.base@11.0.15/SocketInputStream.java:115)
at java.net.SocketInputStream.read(java.base@11.0.15/SocketInputStream.java:168)
at java.net.SocketInputStream.read(java.base@11.0.15/SocketInputStream.java:140)
at sun.nio.cs.StreamDecoder.readBytes(java.base@11.0.15/StreamDecoder.java:284)
at sun.nio.cs.StreamDecoder.implRead(java.base@11.0.15/StreamDecoder.java:326)
at sun.nio.cs.StreamDecoder.read(java.base@11.0.15/StreamDecoder.java:178)
- locked <0x00000007801c7860> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(java.base@11.0.15/InputStreamReader.java:181)
at java.io.BufferedReader.fill(java.base@11.0.15/BufferedReader.java:161)
at java.io.BufferedReader.readLine(java.base@11.0.15/BufferedReader.java:326)
- locked <0x00000007801c7860> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(java.base@11.0.15/BufferedReader.java:392)
at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:56)
Locked ownable synchronizers:
- None
"Log4j2-TF-2-Scheduled-1" #13 daemon prio=5 os_prio=31 cpu=14.05ms elapsed=21.67s tid=0x00007ff53621c800 nid=0x9c03 waiting on condition [0x0000000307d66000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x00000007805a1378> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.15/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.15/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:1182)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.15/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.15/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.15/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"Time-limited test" #15 daemon prio=5 os_prio=31 cpu=1353.43ms elapsed=21.31s tid=0x00007ff536178800 nid=0x9603 waiting on condition [0x0000000307f6c000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.15/Native Method)
at org.apache.bookkeeper.replication.AuditorPeriodicBookieCheckTest.tearDown(AuditorPeriodicBookieCheckTest.java:81)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.15/Native Method)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.15/NativeMethodAccessorImpl.java:62)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.15/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.15/Method.java:566)
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.RunAfters.evaluate(RunAfters.java:33)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
at java.util.concurrent.FutureTask.run(java.base@11.0.15/FutureTask.java:264)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"ForkJoinPool.commonPool-worker-19" apache#187 daemon prio=5 os_prio=31 cpu=1.50ms elapsed=18.22s tid=0x00007ff5357e2000 nid=0x2d003 waiting on condition [0x0000000312455000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079f052a68> (a java.util.concurrent.ForkJoinPool)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.15/LockSupport.java:194)
at java.util.concurrent.ForkJoinPool.runWorker(java.base@11.0.15/ForkJoinPool.java:1628)
at java.util.concurrent.ForkJoinWorkerThread.run(java.base@11.0.15/ForkJoinWorkerThread.java:183)
Locked ownable synchronizers:
- None
"Attach Listener" apache#313 daemon prio=9 os_prio=31 cpu=1.42ms elapsed=0.25s tid=0x00007ff4d3009800 nid=0x2a767 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"VM Thread" os_prio=31 cpu=122.92ms elapsed=23.30s tid=0x00007ff536863800 nid=0x5003 runnable
"GC Thread#0" os_prio=31 cpu=62.12ms elapsed=23.31s tid=0x00007ff536815000 nid=0x3403 runnable
"GC Thread#1" os_prio=31 cpu=57.82ms elapsed=22.63s tid=0x00007ff53580c800 nid=0x8207 runnable
"GC Thread#2" os_prio=31 cpu=56.34ms elapsed=22.63s tid=0x00007ff535ad9800 nid=0xa703 runnable
"GC Thread#3" os_prio=31 cpu=59.35ms elapsed=22.63s tid=0x00007ff53516f000 nid=0xa603 runnable
"GC Thread#4" os_prio=31 cpu=57.35ms elapsed=22.63s tid=0x00007ff536015000 nid=0x8503 runnable
"GC Thread#5" os_prio=31 cpu=57.46ms elapsed=22.63s tid=0x00007ff5351b5000 nid=0x8603 runnable
"GC Thread#6" os_prio=31 cpu=52.34ms elapsed=22.63s tid=0x00007ff5351b6000 nid=0x8803 runnable
"GC Thread#7" os_prio=31 cpu=57.02ms elapsed=22.63s tid=0x00007ff5351b6800 nid=0x8a03 runnable
"GC Thread#8" os_prio=31 cpu=58.19ms elapsed=22.63s tid=0x00007ff5351b7800 nid=0xa403 runnable
"G1 Main Marker" os_prio=31 cpu=1.36ms elapsed=23.31s tid=0x00007ff53482e800 nid=0x3603 runnable
"G1 Conc#0" os_prio=31 cpu=11.69ms elapsed=23.31s tid=0x00007ff53482f000 nid=0x5403 runnable
"G1 Conc#1" os_prio=31 cpu=12.95ms elapsed=21.39s tid=0x00007ff53695b000 nid=0x9103 runnable
"G1 Refine#0" os_prio=31 cpu=2.18ms elapsed=23.31s tid=0x00007ff53311e800 nid=0x5303 runnable
"G1 Young RemSet Sampling" os_prio=31 cpu=6.12ms elapsed=23.31s tid=0x00007ff534854000 nid=0x4203 runnable
"VM Periodic Task Thread" os_prio=31 cpu=17.11ms elapsed=23.11s tid=0x00007ff535888000 nid=0x8003 waiting on condition
JNI global refs: 20, weak refs: 0
```
### You can see the executor `ZkLedgerManagerScheduler` shutdown correctly.
hangc0276
pushed a commit
that referenced
this issue
Jan 18, 2024
### Motivation
The auditor didn't close the ledger manager and ledger under replication manager the thread will leak.
Run the test `AuditorPeriodicBookieCheckTest` and get the stack.
## Before this PR:
```
Full thread dump Java HotSpot(TM) 64-Bit Server VM (11.0.15+8-LTS-149 mixed mode):
Threads class SMR info:
_java_thread_list=0x0000600003e44460, length=16, elements={
0x00007fad34009000, 0x00007fad45032800, 0x00007fad14813800, 0x00007fad44010800,
0x00007fad44011800, 0x00007fad45037800, 0x00007fad3400a000, 0x00007fad45812800,
0x00007fad34944000, 0x00007fad4585f800, 0x00007fad45456000, 0x00007fad4444c000,
0x00007fad3431b800, 0x00007face5825800, 0x00007face5860800, 0x00007face4009800
}
"main" #1 prio=5 os_prio=31 cpu=1801.68ms elapsed=20.85s tid=0x00007fad34009000 nid=0x2a03 waiting on condition [0x000000030a10d000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079f26a8a0> (a java.util.concurrent.FutureTask)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.15/LockSupport.java:234)
at java.util.concurrent.FutureTask.awaitDone(java.base@11.0.15/FutureTask.java:444)
at java.util.concurrent.FutureTask.get(java.base@11.0.15/FutureTask.java:203)
at org.junit.internal.runners.statements.FailOnTimeout.getResult(FailOnTimeout.java:141)
at org.junit.internal.runners.statements.FailOnTimeout.evaluate(FailOnTimeout.java:127)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
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.junit.runner.JUnitCore.run(JUnitCore.java:137)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69)
at com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
at com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)
Locked ownable synchronizers:
- None
"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=2.14ms elapsed=20.82s tid=0x00007fad45032800 nid=0x4803 waiting on condition [0x000000030a823000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.15/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.15/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.15/Reference.java:213)
Locked ownable synchronizers:
- None
"Finalizer" #3 daemon prio=8 os_prio=31 cpu=1.33ms elapsed=20.82s tid=0x00007fad14813800 nid=0x5503 in Object.wait() [0x000000030a926000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.15/Native Method)
- waiting on <0x00000007801b6f18> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000007801b6f18> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.15/Finalizer.java:170)
Locked ownable synchronizers:
- None
"Signal Dispatcher" #4 daemon prio=9 os_prio=31 cpu=2.69ms elapsed=20.81s tid=0x00007fad44010800 nid=0x5b03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Service Thread" #5 daemon prio=9 os_prio=31 cpu=0.03ms elapsed=20.81s tid=0x00007fad44011800 nid=0x7403 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C2 CompilerThread0" #6 daemon prio=9 os_prio=31 cpu=1986.68ms elapsed=20.81s tid=0x00007fad45037800 nid=0x5d03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
Locked ownable synchronizers:
- None
"C1 CompilerThread0" #9 daemon prio=9 os_prio=31 cpu=769.61ms elapsed=20.81s tid=0x00007fad3400a000 nid=0x7003 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
Locked ownable synchronizers:
- None
"Sweeper thread" #10 daemon prio=9 os_prio=31 cpu=0.08ms elapsed=20.81s tid=0x00007fad45812800 nid=0x6e03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Common-Cleaner" #11 daemon prio=8 os_prio=31 cpu=11.62ms elapsed=20.73s tid=0x00007fad34944000 nid=0x6b03 in Object.wait() [0x000000030b049000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.15/Native Method)
- waiting on <0x00000007801b7550> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000007801b7550> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@11.0.15/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
at jdk.internal.misc.InnocuousThread.run(java.base@11.0.15/InnocuousThread.java:134)
Locked ownable synchronizers:
- None
"Monitor Ctrl-Break" #12 daemon prio=5 os_prio=31 cpu=21.16ms elapsed=20.65s tid=0x00007fad4585f800 nid=0x6a03 runnable [0x000000030b14c000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(java.base@11.0.15/Native Method)
at java.net.SocketInputStream.socketRead(java.base@11.0.15/SocketInputStream.java:115)
at java.net.SocketInputStream.read(java.base@11.0.15/SocketInputStream.java:168)
at java.net.SocketInputStream.read(java.base@11.0.15/SocketInputStream.java:140)
at sun.nio.cs.StreamDecoder.readBytes(java.base@11.0.15/StreamDecoder.java:284)
at sun.nio.cs.StreamDecoder.implRead(java.base@11.0.15/StreamDecoder.java:326)
at sun.nio.cs.StreamDecoder.read(java.base@11.0.15/StreamDecoder.java:178)
- locked <0x00000007801b81e8> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(java.base@11.0.15/InputStreamReader.java:181)
at java.io.BufferedReader.fill(java.base@11.0.15/BufferedReader.java:161)
at java.io.BufferedReader.readLine(java.base@11.0.15/BufferedReader.java:326)
- locked <0x00000007801b81e8> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(java.base@11.0.15/BufferedReader.java:392)
at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:56)
Locked ownable synchronizers:
- None
"Log4j2-TF-2-Scheduled-1" #13 daemon prio=5 os_prio=31 cpu=3.80ms elapsed=19.18s tid=0x00007fad45456000 nid=0x8c03 waiting on condition [0x000000030bb6a000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x00000007805c1f78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.15/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.15/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:1182)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.15/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.15/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.15/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"Time-limited test" #15 daemon prio=5 os_prio=31 cpu=1344.20ms elapsed=18.79s tid=0x00007fad4444c000 nid=0x9107 waiting on condition [0x000000030bd70000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.15/Native Method)
at org.apache.bookkeeper.replication.AuditorPeriodicBookieCheckTest.tearDown(AuditorPeriodicBookieCheckTest.java:81)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.15/Native Method)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.15/NativeMethodAccessorImpl.java:62)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.15/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.15/Method.java:566)
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.RunAfters.evaluate(RunAfters.java:33)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
at java.util.concurrent.FutureTask.run(java.base@11.0.15/FutureTask.java:264)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"ZkLedgerManagerScheduler-48-1" apache#165 prio=5 os_prio=31 cpu=9.25ms elapsed=16.04s tid=0x00007fad3431b800 nid=0x25b03 waiting on condition [0x0000000314d1a000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079db6aed0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.15/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.15/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:1170)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.15/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.15/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.15/ThreadPoolExecutor.java:628)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"ZkLedgerManagerScheduler-49-1" apache#166 prio=5 os_prio=31 cpu=1.01ms elapsed=16.04s tid=0x00007face5825800 nid=0x25903 waiting on condition [0x0000000314e1d000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079db6b3f0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.15/LockSupport.java:194)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.15/AbstractQueuedSynchronizer.java:2081)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:1170)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.15/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.15/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.15/ThreadPoolExecutor.java:628)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"ForkJoinPool.commonPool-worker-19" apache#187 daemon prio=5 os_prio=31 cpu=1.52ms elapsed=15.64s tid=0x00007face5860800 nid=0x2ca03 waiting on condition [0x0000000316259000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079ef3f6e8> (a java.util.concurrent.ForkJoinPool)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.15/LockSupport.java:194)
at java.util.concurrent.ForkJoinPool.runWorker(java.base@11.0.15/ForkJoinPool.java:1628)
at java.util.concurrent.ForkJoinWorkerThread.run(java.base@11.0.15/ForkJoinWorkerThread.java:183)
Locked ownable synchronizers:
- None
"Attach Listener" apache#313 daemon prio=9 os_prio=31 cpu=1.90ms elapsed=0.24s tid=0x00007face4009800 nid=0x3d53b waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"VM Thread" os_prio=31 cpu=122.89ms elapsed=20.84s tid=0x00007fad1405f000 nid=0x4e03 runnable
"GC Thread#0" os_prio=31 cpu=67.63ms elapsed=20.85s tid=0x00007fad3480c000 nid=0x3b03 runnable
"GC Thread#1" os_prio=31 cpu=60.78ms elapsed=20.16s tid=0x00007fad45203800 nid=0x8233 runnable
"GC Thread#2" os_prio=31 cpu=56.71ms elapsed=20.16s tid=0x00007fad45039800 nid=0x8403 runnable
"GC Thread#3" os_prio=31 cpu=59.80ms elapsed=20.16s tid=0x00007fad45341800 nid=0xa703 runnable
"GC Thread#4" os_prio=31 cpu=60.21ms elapsed=20.16s tid=0x00007fad45342000 nid=0x8503 runnable
"GC Thread#5" os_prio=31 cpu=60.89ms elapsed=20.16s tid=0x00007fad4536d000 nid=0xa503 runnable
"GC Thread#6" os_prio=31 cpu=57.91ms elapsed=20.16s tid=0x00007fad4594a800 nid=0x8803 runnable
"GC Thread#7" os_prio=31 cpu=56.48ms elapsed=20.16s tid=0x00007fad4594b800 nid=0xa403 runnable
"GC Thread#8" os_prio=31 cpu=56.38ms elapsed=20.16s tid=0x00007fad4536e000 nid=0x8a03 runnable
"G1 Main Marker" os_prio=31 cpu=2.03ms elapsed=20.85s tid=0x00007fad3482d000 nid=0x3a03 runnable
"G1 Conc#0" os_prio=31 cpu=12.67ms elapsed=20.85s tid=0x00007fad4500d800 nid=0x5403 runnable
"G1 Conc#1" os_prio=31 cpu=14.15ms elapsed=18.88s tid=0x00007fad45470800 nid=0x8d4f runnable
"G1 Refine#0" os_prio=31 cpu=2.03ms elapsed=20.84s tid=0x00007fad3492d800 nid=0x4103 runnable
"G1 Young RemSet Sampling" os_prio=31 cpu=5.41ms elapsed=20.84s tid=0x00007fad14008800 nid=0x5103 runnable
"VM Periodic Task Thread" os_prio=31 cpu=14.86ms elapsed=20.64s tid=0x00007fad3494b000 nid=0x680f waiting on condition
JNI global refs: 20, weak refs: 0
```
## After this PR:
```
Full thread dump Java HotSpot(TM) 64-Bit Server VM (11.0.15+8-LTS-149 mixed mode):
Threads class SMR info:
_java_thread_list=0x00006000020b8540, length=14, elements={
0x00007ff536808800, 0x00007ff53311f800, 0x00007ff533021800, 0x00007ff53485f000,
0x00007ff53500f000, 0x00007ff535010000, 0x00007ff53500c000, 0x00007ff53400d800,
0x00007ff536861800, 0x00007ff536053000, 0x00007ff53621c800, 0x00007ff536178800,
0x00007ff5357e2000, 0x00007ff4d3009800
}
"main" #1 prio=5 os_prio=31 cpu=1768.54ms elapsed=23.32s tid=0x00007ff536808800 nid=0x2a03 waiting on condition [0x000000030630b000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079f31ab80> (a java.util.concurrent.FutureTask)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.15/LockSupport.java:234)
at java.util.concurrent.FutureTask.awaitDone(java.base@11.0.15/FutureTask.java:444)
at java.util.concurrent.FutureTask.get(java.base@11.0.15/FutureTask.java:203)
at org.junit.internal.runners.statements.FailOnTimeout.getResult(FailOnTimeout.java:141)
at org.junit.internal.runners.statements.FailOnTimeout.evaluate(FailOnTimeout.java:127)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
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.junit.runner.JUnitCore.run(JUnitCore.java:137)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69)
at com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
at com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)
Locked ownable synchronizers:
- None
"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=1.79ms elapsed=23.29s tid=0x00007ff53311f800 nid=0x4d03 waiting on condition [0x0000000306a21000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.15/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@11.0.15/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.15/Reference.java:213)
Locked ownable synchronizers:
- None
"Finalizer" #3 daemon prio=8 os_prio=31 cpu=1.34ms elapsed=23.29s tid=0x00007ff533021800 nid=0x5503 in Object.wait() [0x0000000306b24000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.15/Native Method)
- waiting on <0x00000007801c5b68> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000007801c5b68> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.15/Finalizer.java:170)
Locked ownable synchronizers:
- None
"Signal Dispatcher" #4 daemon prio=9 os_prio=31 cpu=1.44ms elapsed=23.27s tid=0x00007ff53485f000 nid=0x5b03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Service Thread" #5 daemon prio=9 os_prio=31 cpu=0.03ms elapsed=23.27s tid=0x00007ff53500f000 nid=0x7503 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C2 CompilerThread0" #6 daemon prio=9 os_prio=31 cpu=1882.60ms elapsed=23.27s tid=0x00007ff535010000 nid=0x7403 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
Locked ownable synchronizers:
- None
"C1 CompilerThread0" #9 daemon prio=9 os_prio=31 cpu=768.63ms elapsed=23.27s tid=0x00007ff53500c000 nid=0x6003 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
Locked ownable synchronizers:
- None
"Sweeper thread" #10 daemon prio=9 os_prio=31 cpu=0.05ms elapsed=23.27s tid=0x00007ff53400d800 nid=0x6203 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Common-Cleaner" #11 daemon prio=8 os_prio=31 cpu=8.06ms elapsed=23.20s tid=0x00007ff536861800 nid=0x6403 in Object.wait() [0x0000000307245000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.15/Native Method)
- waiting on <0x00000007801c6678> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.15/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000007801c6678> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@11.0.15/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
at jdk.internal.misc.InnocuousThread.run(java.base@11.0.15/InnocuousThread.java:134)
Locked ownable synchronizers:
- None
"Monitor Ctrl-Break" #12 daemon prio=5 os_prio=31 cpu=19.84ms elapsed=23.11s tid=0x00007ff536053000 nid=0x6c03 runnable [0x0000000307348000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(java.base@11.0.15/Native Method)
at java.net.SocketInputStream.socketRead(java.base@11.0.15/SocketInputStream.java:115)
at java.net.SocketInputStream.read(java.base@11.0.15/SocketInputStream.java:168)
at java.net.SocketInputStream.read(java.base@11.0.15/SocketInputStream.java:140)
at sun.nio.cs.StreamDecoder.readBytes(java.base@11.0.15/StreamDecoder.java:284)
at sun.nio.cs.StreamDecoder.implRead(java.base@11.0.15/StreamDecoder.java:326)
at sun.nio.cs.StreamDecoder.read(java.base@11.0.15/StreamDecoder.java:178)
- locked <0x00000007801c7860> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(java.base@11.0.15/InputStreamReader.java:181)
at java.io.BufferedReader.fill(java.base@11.0.15/BufferedReader.java:161)
at java.io.BufferedReader.readLine(java.base@11.0.15/BufferedReader.java:326)
- locked <0x00000007801c7860> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(java.base@11.0.15/BufferedReader.java:392)
at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:56)
Locked ownable synchronizers:
- None
"Log4j2-TF-2-Scheduled-1" #13 daemon prio=5 os_prio=31 cpu=14.05ms elapsed=21.67s tid=0x00007ff53621c800 nid=0x9c03 waiting on condition [0x0000000307d66000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x00000007805a1378> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.15/LockSupport.java:234)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.15/AbstractQueuedSynchronizer.java:2123)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:1182)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.15/ScheduledThreadPoolExecutor.java:899)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.15/ThreadPoolExecutor.java:1054)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.15/ThreadPoolExecutor.java:1114)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.15/ThreadPoolExecutor.java:628)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"Time-limited test" #15 daemon prio=5 os_prio=31 cpu=1353.43ms elapsed=21.31s tid=0x00007ff536178800 nid=0x9603 waiting on condition [0x0000000307f6c000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.15/Native Method)
at org.apache.bookkeeper.replication.AuditorPeriodicBookieCheckTest.tearDown(AuditorPeriodicBookieCheckTest.java:81)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.15/Native Method)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.15/NativeMethodAccessorImpl.java:62)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.15/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.15/Method.java:566)
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.RunAfters.evaluate(RunAfters.java:33)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
at java.util.concurrent.FutureTask.run(java.base@11.0.15/FutureTask.java:264)
at java.lang.Thread.run(java.base@11.0.15/Thread.java:834)
Locked ownable synchronizers:
- None
"ForkJoinPool.commonPool-worker-19" apache#187 daemon prio=5 os_prio=31 cpu=1.50ms elapsed=18.22s tid=0x00007ff5357e2000 nid=0x2d003 waiting on condition [0x0000000312455000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
- parking to wait for <0x000000079f052a68> (a java.util.concurrent.ForkJoinPool)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.15/LockSupport.java:194)
at java.util.concurrent.ForkJoinPool.runWorker(java.base@11.0.15/ForkJoinPool.java:1628)
at java.util.concurrent.ForkJoinWorkerThread.run(java.base@11.0.15/ForkJoinWorkerThread.java:183)
Locked ownable synchronizers:
- None
"Attach Listener" apache#313 daemon prio=9 os_prio=31 cpu=1.42ms elapsed=0.25s tid=0x00007ff4d3009800 nid=0x2a767 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"VM Thread" os_prio=31 cpu=122.92ms elapsed=23.30s tid=0x00007ff536863800 nid=0x5003 runnable
"GC Thread#0" os_prio=31 cpu=62.12ms elapsed=23.31s tid=0x00007ff536815000 nid=0x3403 runnable
"GC Thread#1" os_prio=31 cpu=57.82ms elapsed=22.63s tid=0x00007ff53580c800 nid=0x8207 runnable
"GC Thread#2" os_prio=31 cpu=56.34ms elapsed=22.63s tid=0x00007ff535ad9800 nid=0xa703 runnable
"GC Thread#3" os_prio=31 cpu=59.35ms elapsed=22.63s tid=0x00007ff53516f000 nid=0xa603 runnable
"GC Thread#4" os_prio=31 cpu=57.35ms elapsed=22.63s tid=0x00007ff536015000 nid=0x8503 runnable
"GC Thread#5" os_prio=31 cpu=57.46ms elapsed=22.63s tid=0x00007ff5351b5000 nid=0x8603 runnable
"GC Thread#6" os_prio=31 cpu=52.34ms elapsed=22.63s tid=0x00007ff5351b6000 nid=0x8803 runnable
"GC Thread#7" os_prio=31 cpu=57.02ms elapsed=22.63s tid=0x00007ff5351b6800 nid=0x8a03 runnable
"GC Thread#8" os_prio=31 cpu=58.19ms elapsed=22.63s tid=0x00007ff5351b7800 nid=0xa403 runnable
"G1 Main Marker" os_prio=31 cpu=1.36ms elapsed=23.31s tid=0x00007ff53482e800 nid=0x3603 runnable
"G1 Conc#0" os_prio=31 cpu=11.69ms elapsed=23.31s tid=0x00007ff53482f000 nid=0x5403 runnable
"G1 Conc#1" os_prio=31 cpu=12.95ms elapsed=21.39s tid=0x00007ff53695b000 nid=0x9103 runnable
"G1 Refine#0" os_prio=31 cpu=2.18ms elapsed=23.31s tid=0x00007ff53311e800 nid=0x5303 runnable
"G1 Young RemSet Sampling" os_prio=31 cpu=6.12ms elapsed=23.31s tid=0x00007ff534854000 nid=0x4203 runnable
"VM Periodic Task Thread" os_prio=31 cpu=17.11ms elapsed=23.11s tid=0x00007ff535888000 nid=0x8003 waiting on condition
JNI global refs: 20, weak refs: 0
```
### You can see the executor `ZkLedgerManagerScheduler` shutdown correctly.
(cherry picked from commit 1e3efa1)
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Motivation
We need the read rocksDB index latency to indicate whether the rocksDB cache is enough.
The text was updated successfully, but these errors were encountered: