From 1e3efa112b66aa597def7cc247a1ffa9e7732301 Mon Sep 17 00:00:00 2001 From: Yan Zhao Date: Mon, 25 Dec 2023 10:32:46 +0800 Subject: [PATCH] Fix auditor thread leak problem. (#4162) ### 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" #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" #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" #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" #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" #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" #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. --- .../java/org/apache/bookkeeper/replication/Auditor.java | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/bookkeeper-server/src/main/java/org/apache/bookkeeper/replication/Auditor.java b/bookkeeper-server/src/main/java/org/apache/bookkeeper/replication/Auditor.java index 93810280189..13b10cf927c 100644 --- a/bookkeeper-server/src/main/java/org/apache/bookkeeper/replication/Auditor.java +++ b/bookkeeper-server/src/main/java/org/apache/bookkeeper/replication/Auditor.java @@ -618,10 +618,16 @@ public void shutdown() { if (ownBkc) { bkc.close(); } + if (ledgerManager != null) { + ledgerManager.close(); + } + if (ledgerUnderreplicationManager != null) { + ledgerUnderreplicationManager.close(); + } } catch (InterruptedException ie) { Thread.currentThread().interrupt(); LOG.warn("Interrupted while shutting down auditor bookie", ie); - } catch (BKException bke) { + } catch (UnavailableException | IOException | BKException bke) { LOG.warn("Exception while shutting down auditor bookie", bke); } }