On Wed, 16 Mar 2022 02:57:20 GMT, Yi Yang <[email protected]> wrote:
>> When we use jcmd <pid> Thread.dump/jstack <pid>, we could dump all Java
>> thread stack trace, but unfortunately we are not able to print NonJavaThread
>> stack trace such as VMThread/GCWorker, etc. For these threads, we know
>> nothing about what are they doing/are they blocked in pthread condition from
>> jstack output. An alternative is to use pstack, it internally attaches
>> destination process and uses `thread apply all bt`, which introduces more
>> overhead and much more dangerous.
>>
>> ====== JStack Ouput(Currrent)
>>
>> ...
>> "ApplicationImpl pooled thread 441" #1478 prio=4 os_prio=31 cpu=11.71ms
>> elapsed=60.30s tid=0x00007f8d32171000 nid=0x22f23 waiting on condition
>> [0x0000700010d5d000]
>> java.lang.Thread.State: TIMED_WAITING (parking)
>> at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
>> - parking to wait for <0x00000007af851760> (a
>> java.util.concurrent.SynchronousQueue$TransferStack)
>> at
>> java.util.concurrent.locks.LockSupport.parkNanos([email protected]/LockSupport.java:234)
>> at
>> java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill([email protected]/SynchronousQueue.java:462)
>> at
>> java.util.concurrent.SynchronousQueue$TransferStack.transfer([email protected]/SynchronousQueue.java:361)
>> at
>> java.util.concurrent.SynchronousQueue.poll([email protected]/SynchronousQueue.java:937)
>> at
>> java.util.concurrent.ThreadPoolExecutor.getTask([email protected]/ThreadPoolExecutor.java:1053)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/ThreadPoolExecutor.java:1114)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/ThreadPoolExecutor.java:628)
>> at
>> java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run([email protected]/Executors.java:668)
>> at
>> java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run([email protected]/Executors.java:665)
>> at java.security.AccessController.doPrivileged([email protected]/Native
>> Method)
>> at
>> java.util.concurrent.Executors$PrivilegedThreadFactory$1.run([email protected]/Executors.java:665)
>> at java.lang.Thread.run([email protected]/Thread.java:829)
>>
>> "VM Thread" os_prio=31 cpu=31205.83ms elapsed=154131.15s
>> tid=0x00007f8d49046000 nid=0x4703 runnable
>>
>> "GC Thread#0" os_prio=31 cpu=3811.96ms elapsed=154131.18s
>> tid=0x00007f8d49809800 nid=0x3603 runnable
>>
>> "GC Thread#1" os_prio=31 cpu=3749.09ms elapsed=154130.24s
>> tid=0x00007f8d4a9b3000 nid=0x6103 runnable
>>
>> "GC Thread#2" os_prio=31 cpu=3745.73ms elapsed=154129.74s
>> tid=0x00007f8d48249000 nid=0x12f27 runnable
>>
>> "GC Thread#3" os_prio=31 cpu=3692.77ms elapsed=154129.74s
>> tid=0x00007f8d48b93000 nid=0xe50b runnable
>>
>> "GC Thread#4" os_prio=31 cpu=3728.57ms elapsed=154129.74s
>> tid=0x00007f8d47b0b000 nid=0xe603 runnable
>>
>> "GC Thread#5" os_prio=31 cpu=3726.08ms elapsed=154129.74s
>> tid=0x00007f8d47afc800 nid=0xe803 runnable
>>
>> "GC Thread#6" os_prio=31 cpu=3660.35ms elapsed=154129.02s
>> tid=0x00007f8d48de5800 nid=0x15d2f runnable
>>
>> "GC Thread#7" os_prio=31 cpu=3676.68ms elapsed=154129.02s
>> tid=0x00007f8d48dc4800 nid=0x16103 runnable
>>
>> "GC Thread#8" os_prio=31 cpu=3676.15ms elapsed=154128.31s
>> tid=0x00007f8d4849d800 nid=0x1f503 runnable
>>
>> "GC Thread#9" os_prio=31 cpu=3570.95ms elapsed=154128.31s
>> tid=0x00007f8d494ab000 nid=0x1f303 runnable
>>
>> "CMS Main Thread" os_prio=31 cpu=6715.33ms elapsed=154131.18s
>> tid=0x00007f8d4780f800 nid=0x4b03 runnable
>>
>> "CMS Thread#0" os_prio=31 cpu=2429.86ms elapsed=154131.18s
>> tid=0x00007f8d4900e000 nid=0x3703 runnable
>>
>> "CMS Thread#1" os_prio=31 cpu=2422.35ms elapsed=154129.72s
>> tid=0x00007f8d4d044000 nid=0x11a03 runnable
>>
>> "CMS Thread#2" os_prio=31 cpu=2418.81ms elapsed=154129.72s
>> tid=0x00007f8d48b93800 nid=0xea03 runnable
>>
>> "VM Periodic Task Thread" os_prio=31 cpu=10658.80ms elapsed=154130.41s
>> tid=0x00007f8d49035000 nid=0xa003 waiting on condition
>>
>> JNI global refs: 660, weak refs: 1217
>>
>>
>> Most of above information makes no sense for further debugging. I think we
>> can extend this functionality, e.g. add a new flag such as
>> DumpAllThreadStackTrace, to print non java thread stack trace:
>>
>> ====== JStack Ouput(Modified)
>>
>> 2022-03-16 10:46:55
>> Full thread dump OpenJDK 64-Bit Server VM
>> (19-internal-adhoc.qingfengyy.jdktip mixed mode, sharing):
>>
>> Threads class SMR info:
>> _java_thread_list=0x00007f15040015f0, length=22, elements={
>> 0x00007f159c0255b0, 0x00007f159c1babc0, 0x00007f159c1bc180,
>> 0x00007f159c1c21d0,
>> 0x00007f159c1c36a0, 0x00007f159c1c4bb0, 0x00007f159c1c6730,
>> 0x00007f159c1c7db0,
>> 0x00007f159c1c9330, 0x00007f159c1fc300, 0x00007f159c211a60,
>> 0x00007f159c213b60,
>> 0x00007f159c302960, 0x00007f14cc0319d0, 0x00007f14cc0375c0,
>> 0x00007f159c307e80,
>> 0x00007f159c30db30, 0x00007f159c3e6db0, 0x00007f159c647300,
>> 0x00007f159c64b600,
>> 0x00007f159c678910, 0x00007f1504000be0
>> }
>>
>> "main" #1 prio=5 os_prio=0 cpu=766.48ms elapsed=23.73s
>> tid=0x00007f159c0255b0 nid=115919 in Object.wait() [0x00007f15a3e58000]
>> java.lang.Thread.State: TIMED_WAITING (on object monitor)
>> at java.lang.Object.wait(java.base@19-internal/Native Method)
>> - waiting on <no object reference available>
>> at
>> jdk.internal.org.jline.utils.NonBlockingInputStreamImpl.read(jdk.internal.le@19-internal/NonBlockingInputStreamImpl.java:139)
>> - locked <0x00000000a2000368> (a
>> jdk.internal.jshell.tool.ConsoleIOContext$1)
>> at
>> jdk.internal.org.jline.utils.NonBlockingInputStream.read(jdk.internal.le@19-internal/NonBlockingInputStream.java:62)
>> at
>> jdk.internal.org.jline.utils.NonBlocking$NonBlockingInputStreamReader.read(jdk.internal.le@19-internal/NonBlocking.java:168)
>> at
>> jdk.internal.org.jline.utils.NonBlockingReader.read(jdk.internal.le@19-internal/NonBlockingReader.java:57)
>> at
>> jdk.internal.org.jline.keymap.BindingReader.readCharacter(jdk.internal.le@19-internal/BindingReader.java:160)
>> at
>> jdk.internal.org.jline.keymap.BindingReader.readBinding(jdk.internal.le@19-internal/BindingReader.java:110)
>> at
>> jdk.internal.org.jline.keymap.BindingReader.readBinding(jdk.internal.le@19-internal/BindingReader.java:61)
>> at
>> jdk.internal.org.jline.reader.impl.LineReaderImpl.doReadBinding(jdk.internal.le@19-internal/LineReaderImpl.java:923)
>> at
>> jdk.internal.org.jline.reader.impl.LineReaderImpl.readBinding(jdk.internal.le@19-internal/LineReaderImpl.java:956)
>> at
>> jdk.internal.jshell.tool.ConsoleIOContext$2.readBinding(jdk.jshell@19-internal/ConsoleIOContext.java:173)
>> at
>> jdk.internal.org.jline.reader.impl.LineReaderImpl.readLine(jdk.internal.le@19-internal/LineReaderImpl.java:651)
>> at
>> jdk.internal.org.jline.reader.impl.LineReaderImpl.readLine(jdk.internal.le@19-internal/LineReaderImpl.java:468)
>> at
>> jdk.internal.jshell.tool.ConsoleIOContext.readLine(jdk.jshell@19-internal/ConsoleIOContext.java:249)
>> at
>> jdk.internal.jshell.tool.JShellTool.getInput(jdk.jshell@19-internal/JShellTool.java:1281)
>> at
>> jdk.internal.jshell.tool.JShellTool.run(jdk.jshell@19-internal/JShellTool.java:1215)
>> at
>> jdk.internal.jshell.tool.JShellTool.start(jdk.jshell@19-internal/JShellTool.java:1001)
>> at
>> jdk.internal.jshell.tool.JShellToolBuilder.start(jdk.jshell@19-internal/JShellToolBuilder.java:261)
>> at
>> jdk.internal.jshell.tool.JShellToolProvider.main(jdk.jshell@19-internal/JShellToolProvider.java:120)
>>
>> "Reference Handler" #2 daemon prio=10 os_prio=0 cpu=1.04ms elapsed=23.72s
>> tid=0x00007f159c1babc0 nid=115926 waiting on condition [0x00007f1529302000]
>> java.lang.Thread.State: RUNNABLE
>> at
>> java.lang.ref.Reference.waitForReferencePendingList(java.base@19-internal/Native
>> Method)
>> at
>> java.lang.ref.Reference.processPendingReferences(java.base@19-internal/Reference.java:253)
>> at
>> java.lang.ref.Reference$ReferenceHandler.run(java.base@19-internal/Reference.java:215)
>>
>> "Finalizer" #3 daemon prio=8 os_prio=0 cpu=0.35ms elapsed=23.72s
>> tid=0x00007f159c1bc180 nid=115927 in Object.wait() [0x00007f1529201000]
>> java.lang.Thread.State: WAITING (on object monitor)
>> at java.lang.Object.wait(java.base@19-internal/Native Method)
>> - waiting on <0x00000000a00002e8> (a java.lang.ref.ReferenceQueue$Lock)
>> at
>> java.lang.ref.ReferenceQueue.remove(java.base@19-internal/ReferenceQueue.java:155)
>> - locked <0x00000000a00002e8> (a java.lang.ref.ReferenceQueue$Lock)
>> at
>> java.lang.ref.ReferenceQueue.remove(java.base@19-internal/ReferenceQueue.java:176)
>> at
>> java.lang.ref.Finalizer$FinalizerThread.run(java.base@19-internal/Finalizer.java:183)
>>
>> "Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=0.24ms elapsed=23.71s
>> tid=0x00007f159c1c21d0 nid=115928 waiting on condition [0x0000000000000000]
>> java.lang.Thread.State: RUNNABLE
>>
>> "Service Thread" #5 daemon prio=9 os_prio=0 cpu=0.20ms elapsed=23.71s
>> tid=0x00007f159c1c36a0 nid=115929 runnable [0x0000000000000000]
>> java.lang.Thread.State: RUNNABLE
>>
>> "Monitor Deflation Thread" #6 daemon prio=9 os_prio=0 cpu=0.24ms
>> elapsed=23.71s tid=0x00007f159c1c4bb0 nid=115930 runnable
>> [0x0000000000000000]
>> java.lang.Thread.State: RUNNABLE
>>
>> "C2 CompilerThread0" #7 daemon prio=9 os_prio=0 cpu=527.71ms elapsed=23.71s
>> tid=0x00007f159c1c6730 nid=115931 waiting on condition [0x0000000000000000]
>> java.lang.Thread.State: RUNNABLE
>> No compile task
>>
>> "C1 CompilerThread0" #19 daemon prio=9 os_prio=0 cpu=216.87ms elapsed=23.71s
>> tid=0x00007f159c1c7db0 nid=115932 waiting on condition [0x0000000000000000]
>> java.lang.Thread.State: RUNNABLE
>> No compile task
>>
>> "Sweeper thread" #25 daemon prio=9 os_prio=0 cpu=0.04ms elapsed=23.71s
>> tid=0x00007f159c1c9330 nid=115933 runnable [0x0000000000000000]
>> java.lang.Thread.State: RUNNABLE
>>
>> "Notification Thread" #26 daemon prio=9 os_prio=0 cpu=0.05ms elapsed=23.70s
>> tid=0x00007f159c1fc300 nid=115936 runnable [0x0000000000000000]
>> java.lang.Thread.State: RUNNABLE
>>
>> "Common-Cleaner" #27 daemon prio=8 os_prio=0 cpu=0.99ms elapsed=23.68s
>> tid=0x00007f159c211a60 nid=115938 in Object.wait() [0x00007f15282d2000]
>> java.lang.Thread.State: TIMED_WAITING (on object monitor)
>> at java.lang.Object.wait(java.base@19-internal/Native Method)
>> - waiting on <no object reference available>
>> at
>> java.lang.ref.ReferenceQueue.remove(java.base@19-internal/ReferenceQueue.java:155)
>> - locked <0x00000000a0000628> (a java.lang.ref.ReferenceQueue$Lock)
>> at
>> jdk.internal.ref.CleanerImpl.run(java.base@19-internal/CleanerImpl.java:140)
>> at java.lang.Thread.run(java.base@19-internal/Thread.java:828)
>> at
>> jdk.internal.misc.InnocuousThread.run(java.base@19-internal/InnocuousThread.java:162)
>>
>> "Timer-0" #28 daemon prio=5 os_prio=0 cpu=0.10ms elapsed=23.68s
>> tid=0x00007f159c213b60 nid=115939 in Object.wait() [0x00007f15281d1000]
>> java.lang.Thread.State: TIMED_WAITING (on object monitor)
>> at java.lang.Object.wait(java.base@19-internal/Native Method)
>> - waiting on <0x00000000a00007e8> (a java.util.TaskQueue)
>> at java.util.TimerThread.mainLoop(java.base@19-internal/Timer.java:563)
>> - locked <0x00000000a00007e8> (a java.util.TaskQueue)
>> at java.util.TimerThread.run(java.base@19-internal/Timer.java:516)
>>
>> "process reaper" #30 daemon prio=10 os_prio=0 cpu=0.17ms elapsed=23.53s
>> tid=0x00007f159c302960 nid=115944 runnable [0x00007f15a3c9e000]
>> java.lang.Thread.State: RUNNABLE
>> at
>> java.lang.ProcessHandleImpl.waitForProcessExit0(java.base@19-internal/Native
>> Method)
>> at
>> java.lang.ProcessHandleImpl$1.run(java.base@19-internal/ProcessHandleImpl.java:147)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@19-internal/ThreadPoolExecutor.java:1136)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@19-internal/ThreadPoolExecutor.java:635)
>> at java.lang.Thread.run(java.base@19-internal/Thread.java:828)
>>
>> "JDI Internal Event Handler" #34 daemon prio=5 os_prio=0 cpu=14.16ms
>> elapsed=23.49s tid=0x00007f14cc0319d0 nid=115971 in Object.wait()
>> [0x00007f15096b7000]
>> java.lang.Thread.State: WAITING (on object monitor)
>> at java.lang.Object.wait(java.base@19-internal/Native Method)
>> - waiting on <no object reference available>
>> at java.lang.Object.wait(java.base@19-internal/Object.java:338)
>> at
>> com.sun.tools.jdi.EventQueueImpl.removeUnfiltered(jdk.jdi@19-internal/EventQueueImpl.java:190)
>> - locked <0x00000000a0000e80> (a com.sun.tools.jdi.EventQueueImpl)
>> at
>> com.sun.tools.jdi.EventQueueImpl.removeInternal(jdk.jdi@19-internal/EventQueueImpl.java:125)
>> at
>> com.sun.tools.jdi.InternalEventHandler.run(jdk.jdi@19-internal/InternalEventHandler.java:61)
>> at java.lang.Thread.run(java.base@19-internal/Thread.java:828)
>>
>> "JDI Target VM Interface" #33 daemon prio=5 os_prio=0 cpu=16.02ms
>> elapsed=23.49s tid=0x00007f14cc0375c0 nid=115972 runnable
>> [0x00007f15095b6000]
>> java.lang.Thread.State: RUNNABLE
>> at sun.nio.ch.SocketDispatcher.read0(java.base@19-internal/Native
>> Method)
>> at
>> sun.nio.ch.SocketDispatcher.read(java.base@19-internal/SocketDispatcher.java:47)
>> at
>> sun.nio.ch.NioSocketImpl.tryRead(java.base@19-internal/NioSocketImpl.java:258)
>> at
>> sun.nio.ch.NioSocketImpl.implRead(java.base@19-internal/NioSocketImpl.java:309)
>> at
>> sun.nio.ch.NioSocketImpl.read(java.base@19-internal/NioSocketImpl.java:347)
>> at
>> sun.nio.ch.NioSocketImpl$1.read(java.base@19-internal/NioSocketImpl.java:800)
>> at
>> java.net.Socket$SocketInputStream.read(java.base@19-internal/Socket.java:966)
>> at
>> java.net.Socket$SocketInputStream.read(java.base@19-internal/Socket.java:961)
>> at
>> com.sun.tools.jdi.SocketConnection.readPacket(jdk.jdi@19-internal/SocketConnection.java:82)
>> - locked <0x00000000a00012e0> (a java.lang.Object)
>> at com.sun.tools.jdi.TargetVM.run(jdk.jdi@19-internal/TargetVM.java:123)
>> at java.lang.Thread.run(java.base@19-internal/Thread.java:828)
>>
>> "event-handler" #35 daemon prio=5 os_prio=0 cpu=8.29ms elapsed=23.48s
>> tid=0x00007f159c307e80 nid=115973 in Object.wait() [0x00007f15098b9000]
>> java.lang.Thread.State: WAITING (on object monitor)
>> at java.lang.Object.wait(java.base@19-internal/Native Method)
>> - waiting on <no object reference available>
>> at java.lang.Object.wait(java.base@19-internal/Object.java:338)
>> at
>> com.sun.tools.jdi.EventQueueImpl.removeUnfiltered(jdk.jdi@19-internal/EventQueueImpl.java:190)
>> - locked <0x00000000a0001e98> (a com.sun.tools.jdi.EventQueueImpl)
>> at
>> com.sun.tools.jdi.EventQueueImpl.remove(jdk.jdi@19-internal/EventQueueImpl.java:97)
>> at
>> com.sun.tools.jdi.EventQueueImpl.remove(jdk.jdi@19-internal/EventQueueImpl.java:83)
>> at
>> jdk.jshell.execution.JdiEventHandler.run(jdk.jshell@19-internal/JdiEventHandler.java:79)
>> at java.lang.Thread.run(java.base@19-internal/Thread.java:828)
>>
>> "output reader" #36 daemon prio=5 os_prio=0 cpu=0.30ms elapsed=23.44s
>> tid=0x00007f159c30db30 nid=115990 runnable [0x00007f15097b8000]
>> java.lang.Thread.State: RUNNABLE
>> at sun.nio.ch.SocketDispatcher.read0(java.base@19-internal/Native
>> Method)
>> at
>> sun.nio.ch.SocketDispatcher.read(java.base@19-internal/SocketDispatcher.java:47)
>> at
>> sun.nio.ch.NioSocketImpl.tryRead(java.base@19-internal/NioSocketImpl.java:258)
>> at
>> sun.nio.ch.NioSocketImpl.implRead(java.base@19-internal/NioSocketImpl.java:309)
>> at
>> sun.nio.ch.NioSocketImpl.read(java.base@19-internal/NioSocketImpl.java:347)
>> at
>> sun.nio.ch.NioSocketImpl$1.read(java.base@19-internal/NioSocketImpl.java:800)
>> at
>> java.net.Socket$SocketInputStream.read(java.base@19-internal/Socket.java:966)
>> at
>> java.net.Socket$SocketInputStream.read(java.base@19-internal/Socket.java:961)
>> at
>> java.io.FilterInputStream.read(java.base@19-internal/FilterInputStream.java:79)
>> at
>> jdk.jshell.execution.DemultiplexInput.run(jdk.jshell@19-internal/DemultiplexInput.java:60)
>>
>> "Thread-1" #38 daemon prio=5 os_prio=0 cpu=222.19ms elapsed=23.37s
>> tid=0x00007f159c3e6db0 nid=115995 waiting on condition [0x00007f15094b5000]
>> java.lang.Thread.State: WAITING (parking)
>> at jdk.internal.misc.Unsafe.park(java.base@19-internal/Native Method)
>> - parking to wait for <0x00000000a007a880> (a
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
>> at
>> java.util.concurrent.locks.LockSupport.park(java.base@19-internal/LockSupport.java:341)
>> at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(java.base@19-internal/AbstractQueuedSynchronizer.java:506)
>> at
>> java.util.concurrent.ForkJoinPool.unmanagedBlock(java.base@19-internal/ForkJoinPool.java:3464)
>> at
>> java.util.concurrent.ForkJoinPool.managedBlock(java.base@19-internal/ForkJoinPool.java:3435)
>> at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@19-internal/AbstractQueuedSynchronizer.java:1623)
>> at
>> java.util.concurrent.LinkedBlockingQueue.take(java.base@19-internal/LinkedBlockingQueue.java:435)
>> at
>> java.util.concurrent.ThreadPoolExecutor.getTask(java.base@19-internal/ThreadPoolExecutor.java:1062)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@19-internal/ThreadPoolExecutor.java:1122)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@19-internal/ThreadPoolExecutor.java:635)
>> at java.lang.Thread.run(java.base@19-internal/Thread.java:828)
>>
>> "process reaper" #40 daemon prio=10 os_prio=0 cpu=1.83ms elapsed=22.94s
>> tid=0x00007f159c647300 nid=116044 waiting on condition [0x00007f15280d0000]
>> java.lang.Thread.State: TIMED_WAITING (parking)
>> at jdk.internal.misc.Unsafe.park(java.base@19-internal/Native Method)
>> - parking to wait for <0x00000000a0079fb0> (a
>> java.util.concurrent.SynchronousQueue$TransferStack)
>> at
>> java.util.concurrent.locks.LockSupport.parkNanos(java.base@19-internal/LockSupport.java:252)
>> at
>> java.util.concurrent.SynchronousQueue$TransferStack.transfer(java.base@19-internal/SynchronousQueue.java:401)
>> at
>> java.util.concurrent.SynchronousQueue.poll(java.base@19-internal/SynchronousQueue.java:903)
>> at
>> java.util.concurrent.ThreadPoolExecutor.getTask(java.base@19-internal/ThreadPoolExecutor.java:1061)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@19-internal/ThreadPoolExecutor.java:1122)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@19-internal/ThreadPoolExecutor.java:635)
>> at java.lang.Thread.run(java.base@19-internal/Thread.java:828)
>>
>> "Thread-3" #41 daemon prio=5 os_prio=0 cpu=1.39ms elapsed=22.94s
>> tid=0x00007f159c64b600 nid=116045 runnable [0x00007f14734ed000]
>> java.lang.Thread.State: RUNNABLE
>> at java.io.FileInputStream.read0(java.base@19-internal/Native Method)
>> at
>> java.io.FileInputStream.read(java.base@19-internal/FileInputStream.java:228)
>> at
>> jdk.internal.org.jline.terminal.impl.AbstractPty$PtyInputStream.read(jdk.internal.le@19-internal/AbstractPty.java:73)
>> at
>> jdk.internal.org.jline.utils.NonBlockingInputStream.read(jdk.internal.le@19-internal/NonBlockingInputStream.java:62)
>> at
>> jdk.internal.jshell.tool.StopDetectingInputStream.lambda$setInputStream$0(jdk.jshell@19-internal/StopDetectingInputStream.java:74)
>> at
>> jdk.internal.jshell.tool.StopDetectingInputStream$$Lambda$355/0x0000000800dd68d0.run(jdk.jshell@19-internal/Unknown
>> Source)
>> at java.lang.Thread.run(java.base@19-internal/Thread.java:828)
>>
>> "null non blocking reader thread" #43 daemon prio=5 os_prio=0 cpu=0.15ms
>> elapsed=22.78s tid=0x00007f159c678910 nid=116063 in Object.wait()
>> [0x00007f1472ee6000]
>> java.lang.Thread.State: WAITING (on object monitor)
>> at java.lang.Object.wait(java.base@19-internal/Native Method)
>> - waiting on <no object reference available>
>> at java.lang.Object.wait(java.base@19-internal/Object.java:338)
>> at
>> jdk.internal.jshell.tool.StopDetectingInputStream.read(jdk.jshell@19-internal/StopDetectingInputStream.java:111)
>> - locked <0x00000000a2000908> (a
>> jdk.internal.jshell.tool.StopDetectingInputStream)
>> at
>> jdk.internal.org.jline.utils.NonBlockingInputStreamImpl.run(jdk.internal.le@19-internal/NonBlockingInputStreamImpl.java:216)
>> at
>> jdk.internal.org.jline.utils.NonBlockingInputStreamImpl$$Lambda$530/0x0000000800dfde40.run(jdk.internal.le@19-internal/Unknown
>> Source)
>> at java.lang.Thread.run(java.base@19-internal/Thread.java:828)
>>
>> "Attach Listener" #44 daemon prio=9 os_prio=0 cpu=0.17ms elapsed=0.10s
>> tid=0x00007f1504000be0 nid=116383 waiting on condition [0x0000000000000000]
>> java.lang.Thread.State: RUNNABLE
>>
>> "VM Thread" os_prio=0 cpu=8.31ms elapsed=23.72s tid=0x00007f159c1b78f0
>> nid=115925 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> V [libjvm.so+0xf21ec5] VM_PrintThreads::doit()+0x25
>> V [libjvm.so+0xf225aa] VM_Operation::evaluate()+0xea
>> V [libjvm.so+0xf23f18] VMThread::evaluate_operation(VM_Operation*)+0xb8
>> V [libjvm.so+0xf245c7] VMThread::inner_execute(VM_Operation*)+0x3a7
>> V [libjvm.so+0xf24877] VMThread::run()+0xb7
>> V [libjvm.so+0xe99770] Thread::call_run()+0xc0
>> V [libjvm.so+0xc37a08] thread_native_entry(Thread*)+0xd8
>>
>> "GC Thread#0" os_prio=0 cpu=39.19ms elapsed=23.73s tid=0x00007f159c066a10
>> nid=115920 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "GC Thread#1" os_prio=0 cpu=9.75ms elapsed=23.16s tid=0x00007f15180140e0
>> nid=116014 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "GC Thread#2" os_prio=0 cpu=0.48ms elapsed=23.15s tid=0x00007f151801b730
>> nid=116015 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "GC Thread#3" os_prio=0 cpu=11.09ms elapsed=23.15s tid=0x00007f151801c160
>> nid=116016 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "GC Thread#4" os_prio=0 cpu=24.95ms elapsed=23.15s tid=0x00007f151801ccc0
>> nid=116017 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "GC Thread#5" os_prio=0 cpu=0.58ms elapsed=23.15s tid=0x00007f151801d820
>> nid=116018 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "GC Thread#6" os_prio=0 cpu=35.58ms elapsed=23.15s tid=0x00007f151801e380
>> nid=116019 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "GC Thread#7" os_prio=0 cpu=13.88ms elapsed=22.98s tid=0x00007f151801b050
>> nid=116042 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "GC Thread#8" os_prio=0 cpu=12.97ms elapsed=22.92s tid=0x00007f1518021950
>> nid=116047 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Main Marker" os_prio=0 cpu=0.84ms elapsed=23.73s tid=0x00007f159c076ed0
>> nid=115921 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xba33] pthread_cond_wait+0xc3
>> V [libjvm.so+0xbf1589] Monitor::wait_without_safepoint_check(long)+0x39
>> V [libjvm.so+0x725fda] G1ConcurrentMarkThread::wait_for_next_cycle()+0x3a
>> V [libjvm.so+0x7270bb] G1ConcurrentMarkThread::run_service()+0xdb
>> V [libjvm.so+0x60be0b] ConcurrentGCThread::run()+0x1b
>> V [libjvm.so+0xe99770] Thread::call_run()+0xc0
>> V [libjvm.so+0xc37a08] thread_native_entry(Thread*)+0xd8
>>
>> "G1 Conc#0" os_prio=0 cpu=6.39ms elapsed=23.73s tid=0x00007f159c077f50
>> nid=115922 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#1" os_prio=0 cpu=1.74ms elapsed=23.05s tid=0x00007f152c000960
>> nid=116022 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#2" os_prio=0 cpu=1.23ms elapsed=23.05s tid=0x00007f152c001490
>> nid=116023 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#3" os_prio=0 cpu=2.04ms elapsed=23.05s tid=0x00007f152c001ff0
>> nid=116024 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#4" os_prio=0 cpu=1.28ms elapsed=23.05s tid=0x00007f152c002b50
>> nid=116025 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#5" os_prio=0 cpu=1.60ms elapsed=23.05s tid=0x00007f152c0036b0
>> nid=116026 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#6" os_prio=0 cpu=1.61ms elapsed=23.05s tid=0x00007f152c004210
>> nid=116027 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#7" os_prio=0 cpu=2.00ms elapsed=23.05s tid=0x00007f152c005160
>> nid=116028 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#8" os_prio=0 cpu=1.58ms elapsed=23.05s tid=0x00007f152c0060b0
>> nid=116029 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#9" os_prio=0 cpu=1.26ms elapsed=23.05s tid=0x00007f152c007000
>> nid=116030 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#10" os_prio=0 cpu=1.61ms elapsed=23.05s tid=0x00007f152c007f50
>> nid=116031 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#11" os_prio=0 cpu=1.52ms elapsed=23.05s tid=0x00007f152c008ea0
>> nid=116032 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#12" os_prio=0 cpu=1.17ms elapsed=23.05s tid=0x00007f152c009df0
>> nid=116033 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#13" os_prio=0 cpu=1.88ms elapsed=23.05s tid=0x00007f152c00ad40
>> nid=116034 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#14" os_prio=0 cpu=1.31ms elapsed=23.05s tid=0x00007f152c00bc90
>> nid=116035 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Conc#15" os_prio=0 cpu=1.52ms elapsed=23.05s tid=0x00007f152c00cbe0
>> nid=116036 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Refine#0" os_prio=0 cpu=0.03ms elapsed=23.73s tid=0x00007f159c1881d0
>> nid=115923 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
>>
>> "G1 Service" os_prio=0 cpu=0.72ms elapsed=23.73s tid=0x00007f159c189290
>> nid=115924 runnable
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xbde2] pthread_cond_timedwait+0x132
>> V [libjvm.so+0xbf1589] Monitor::wait_without_safepoint_check(long)+0x39
>> V [libjvm.so+0x77d208] G1ServiceThread::wait_for_task()+0xf8
>> V [libjvm.so+0x77d600] G1ServiceThread::run_service()+0x20
>> V [libjvm.so+0x60be0b] ConcurrentGCThread::run()+0x1b
>> V [libjvm.so+0xe99770] Thread::call_run()+0xc0
>> V [libjvm.so+0xc37a08] thread_native_entry(Thread*)+0xd8
>>
>> "VM Periodic Task Thread" os_prio=0 cpu=4.05ms elapsed=23.71s
>> tid=0x00007f159c1fddf0 nid=115937 waiting on condition
>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native
>> code)
>> C [libpthread.so.0+0xbde2] pthread_cond_timedwait+0x132
>> V [libjvm.so+0xbf1589] Monitor::wait_without_safepoint_check(long)+0x39
>> V [libjvm.so+0xc07015] WatcherThread::sleep() const+0xa5
>> V [libjvm.so+0xc070e5] WatcherThread::run()+0x35
>> V [libjvm.so+0xe99770] Thread::call_run()+0xc0
>> V [libjvm.so+0xc37a08] thread_native_entry(Thread*)+0xd8
>>
>> JNI global refs: 28, weak refs: 0
>
> Yi Yang has refreshed the contents of this pull request, and previous commits
> have been removed. The incremental views will show differences compared to
> the previous content of the PR. The pull request contains one new commit
> since the last revision:
>
> 8283147: Include NonJavaThread stacktrace during thread dump
Clarification on why there are some one-line frame:
VMError::print_native_stack output
"G1 Conc#7" os_prio=0 cpu=2.33ms elapsed=11.39s tid=0x00007f635c004d70
nid=71098 runnable
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
C [libpthread.so.0+0xdb39] do_futex_wait.constprop.1+0x29
pstack outpout
Thread 40 (Thread 0x7f62b3bf7700 (LWP 71098)):
#0 0x00007f63d32a6b3b in do_futex_wait.constprop () from /lib64/libpthread.so.0
#1 0x00007f63d32a6bcf in __new_sem_wait_slow.constprop.0 () from
/lib64/libpthread.so.0
#2 0x00007f63d32a6c6b in sem_wait@@GLIBC_2.2.5 () from /lib64/libpthread.so.0
#3 0x00007f63d23f7c32 in PosixSemaphore::wait (this=this@entry=0x7f63cc077e78)
at /home/qingfeng.yy/jdktip/src/hotspot/os/posix/semaphore_posix.cpp:65
#4 0x00007f63d265b81b in Semaphore::wait (this=0x7f63cc077e78) at
/home/qingfeng.yy/jdktip/src/hotspot/share/runtime/semaphore.hpp:55
#5 WorkerTaskDispatcher::worker_run_task (this=0x7f63cc077e68) at
/home/qingfeng.yy/jdktip/src/hotspot/share/gc/shared/workerThread.cpp:60
#6 WorkerThread::run (this=0x7f635c004d70) at
/home/qingfeng.yy/jdktip/src/hotspot/share/gc/shared/workerThread.cpp:163
#7 0x00007f63d25aa790 in Thread::call_run (this=this@entry=0x7f635c004d70) at
/home/qingfeng.yy/jdktip/src/hotspot/share/runtime/thread.cpp:357
#8 0x00007f63d2348a28 in thread_native_entry (thread=0x7f635c004d70) at
/home/qingfeng.yy/jdktip/src/hotspot/os/linux/os_linux.cpp:706
#9 0x00007f63d32a0ea5 in start_thread () from /lib64/libpthread.so.0
#10 0x00007f63d2dc58dd in clone () from /lib64/libc.so.6
The top frame is as follows:
C frame (sp=0x00007f6338ca0d90 unextended sp=0x00007f6338ca0d90,
fp=0x00007f63cc0667c8, real_fp=0x00007f63cc0667c8, pc=0x00007f63d32a6b39
link=0x0000000900000000)
do_futex_wait.constprop don't have a valid link/last_frame_pointer, because
libpthread has some novel assembly code:
000000000000db10 <do_futex_wait.constprop.1>:
db10: 55 push %rbp
db11: 48 89 fd mov %rdi,%rbp
db14: 53 push %rbx
db15: 48 83 ec 08 sub $0x8,%rsp
db19: 8b 5f 08 mov 0x8(%rdi),%ebx
db1c: e8 1f 09 00 00 callq e440
<__pthread_enable_asynccancel>
db21: 45 31 d2 xor %r10d,%r10d
db24: 41 89 c0 mov %eax,%r8d
db27: 31 d2 xor %edx,%edx
db29: 89 de mov %ebx,%esi
db2b: bb ca 00 00 00 mov $0xca,%ebx
db30: 48 89 ef mov %rbp,%rdi
db33: 40 80 f6 80 xor $0x80,%sil
db37: 89 d8 mov %ebx,%eax
db39: 0f 05 syscall
db3b: 89 c3 mov %eax,%ebx
....
000000000000db80 <__new_sem_wait_slow.constprop.0>:
db80: 41 54 push %r12
db82: 48 b8 00 00 00 00 01 movabs $0x100000000,%rax
db89: 00 00 00
db8c: 55 push %rbp
db8d: 53 push %rbx
db8e: 48 89 fb mov %rdi,%rbx
db91: 48 83 ec 30 sub $0x30,%rsp
db95: f0 48 0f c1 07 lock xadd %rax,(%rdi)
db9a: 48 8d 35 5f ff ff ff lea -0xa1(%rip),%rsi # db00
<__sem_wait_cleanup>
dba1: 49 bc ff ff ff ff fe movabs $0xfffffffeffffffff,%r12
dba8: ff ff ff
dbab: 48 8d 6c 24 10 lea 0x10(%rsp),%rbp
dbb0: 48 89 fa mov %rdi,%rdx
dbb3: 48 89 04 24 mov %rax,(%rsp)
dbb7: 48 89 ef mov %rbp,%rdi
dbba: e8 b1 04 00 00 callq e070 <_pthread_cleanup_push>
dbbf: 48 8b 04 24 mov (%rsp),%rax
dbc3: 85 c0 test %eax,%eax
....
So os::is_first_C_frame returns earlier. To support walking pthread library, I
don't think it requires huge efforts, though.
-------------
PR: https://git.openjdk.java.net/jdk/pull/7833
