JDK-8244980 : Test serviceability/sa/ClhsdbSource.java and ClhsdbCDSJstackPrintAll.java fail: Common-cleaner missing from stdout/stderr
  • Type: Bug
  • Component: hotspot
  • Sub-Component: svc-agent
  • Affected Version: 15,16,18
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • OS: windows
  • CPU: x86_64
  • Submitted: 2020-05-14
  • Updated: 2021-07-09
  • Resolved: 2021-07-09
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
Other
tbdResolved
Related Reports
Duplicate :  
Relates :  
Relates :  
Relates :  
Relates :  
Description
Test started failing shortly after JDK-8235211 was pushed (unclear if there is any connection).

The list of threads from the thread dump ends at the AttachListenerThread. The Common-Cleaner thread is normally last.

Initially occured with serviceability/sa/ClhsdbSource.java, but later was also seen with serviceability/sa/ClhsdbCDSJstackPrintAll.

Doesn't seem to reproduce readily.


Comments
Closing as dup of JDK-8269830
09-07-2021

Yes, but I'd like to keep them open for filing new failures under until JDK-8269830 is fixed.
05-07-2021

So all these missing thread bugs should be closed as duplicates of JDK-8269830.
04-07-2021

This root cause of this CR is JDK-8269830. It causes SA to sometimes think that a JavaThread object is actually a CompilerThread object, and jstack intentionally does not include CompilerThread objects.
02-07-2021

Here's a log file snippet from the jdk-18+4-93-tier5 sighting: serviceability/sa/ClhsdbJstack.java#id0 stderr: [ + jstack -v Deadlock Detection: No deadlocks found. "main" #1 prio=5 tid=0x00007f9a85008820 nid=0x1703 waiting on condition [0x000070000f982000] java.lang.Thread.State: TIMED_WAITING (sleeping) JavaThread state: _thread_blocked - java.lang.Thread.sleep(long) @bci=0, pc=0x0000000121f434b8, Method*=0x000000012e0469a0 (Compiled frame; information may be imprecise) - jdk.test.lib.apps.LingeredApp.main(java.lang.String[]) @bci=158, line=599, pc=0x000000011a85b2cc, Method*=0x000000012e503818 (Compiled frame) - locked <0x000000078a7250f0> (a java.lang.Object) Locked ownable synchronizers: - None "Reference Handler" #2 daemon prio=10 tid=0x00007f9a86808220 nid=0x4403 waiting on condition [0x0000700010097000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked - java.lang.ref.Reference.waitForReferencePendingList() @bci=0, pc=0x000000011a28268b, Method*=0x000000012e0418c8 (Interpreted frame) - java.lang.ref.Reference.processPendingReferences() @bci=0, line=253, pc=0x000000011a27c5b0, Method*=0x000000012e041b28 (Interpreted frame) - java.lang.ref.Reference$ReferenceHandler.run() @bci=0, line=215, pc=0x000000011a27c5b0, Method*=0x000000012e1bc218 (Interpreted frame) Locked ownable synchronizers: - None "Finalizer" #3 daemon prio=8 tid=0x00007f9a84864a20 nid=0x3f03 in Object.wait() [0x000070001019a000] java.lang.Thread.State: WAITING (on object monitor) JavaThread state: _thread_blocked - java.lang.Object.wait(long) @bci=0, pc=0x000000011a28268b, Method*=0x000000012e000be8 (Interpreted frame) - waiting on <0x000000078a90bff0> (a java.lang.ref.ReferenceQueue$Lock) - java.lang.ref.ReferenceQueue.remove(long) @bci=59, line=155, pc=0x000000011a27c5b0, Method*=0x000000012e1bdda8 (Interpreted frame) - locked <0x000000078a90bff0> (a java.lang.ref.ReferenceQueue$Lock) - java.lang.ref.ReferenceQueue.remove() @bci=2, line=176, pc=0x000000011a27c3cc, Method*=0x000000012e1bde60 (Interpreted frame) - java.lang.ref.Finalizer$FinalizerThread.run() @bci=37, line=172, pc=0x000000011a27c3cc, Method*=0x000000012e1bfa78 (Interpreted frame) Locked ownable synchronizers: - None "Signal Dispatcher" #4 daemon prio=9 tid=0x00007f9a84865620 nid=0x5713 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Locked ownable synchronizers: - None "SteadyStateThread" #14 prio=5 tid=0x00007f9a34812c20 nid=0x6003 waiting for monitor entry [0x0000700010cbe000] java.lang.Thread.State: BLOCKED (on object monitor) JavaThread state: _thread_blocked - jdk.test.lib.apps.LingeredApp.steadyState(java.lang.Object) @bci=7, line=536, pc=0x000000011a949e62, Method*=0x000000012e503530 (Compiled frame) - waiting to lock <0x000000078a7250f0> (a java.lang.Object) - jdk.test.lib.apps.LingeredApp$1.run() @bci=4, line=543, pc=0x000000011a94a2e4, Method*=0x000000012e503d78 (Compiled frame) Locked ownable synchronizers: - None ] exitValue = -1 java.lang.RuntimeException: Test ERROR (with -Xcomp=true) java.lang.RuntimeException: 'Common\\-Cleaner' missing from stdout/stderr at ClhsdbJstack.testJstack(ClhsdbJstack.java:80) at ClhsdbJstack.main(ClhsdbJstack.java:89) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:833) Caused by: java.lang.RuntimeException: 'Common\\-Cleaner' missing from stdout/stderr at jdk.test.lib.process.OutputAnalyzer.shouldMatch(OutputAnalyzer.java:340) at ClhsdbLauncher.runCmd(ClhsdbLauncher.java:166) at ClhsdbLauncher.run(ClhsdbLauncher.java:203) at ClhsdbJstack.testJstack(ClhsdbJstack.java:76) ... 7 more JavaTest Message: Test threw exception: java.lang.RuntimeException: Test ERROR (with -Xcomp=true) java.lang.RuntimeException: 'Common\\-Cleaner' missing from stdout/stderr JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Test ERROR (with -Xcomp=true) java.lang.RuntimeException: 'Common\\-Cleaner' missing from stdout/stderr ----------rerun:(34/7130)*----------
27-06-2021

I just saw this during a run of ClhsdbCDCCore running on windows. The interesting thing about that test is that the target "process" is actually a core file. The crash is produced immediately on entry to main(): public static void main(String[] args) { Unsafe.getUnsafe().putInt(0L, 0); } So if the issue is the Common-Cleaner thread being a bit slow to "show up", I would think a test like this would reproduce it often, but this is the first I've seen it with this test. But then this issue has only shown up 8 times to date. Another possible explanation is for some reason the Common-Cleaner thread simply failed to start.
08-07-2020

If a class is loaded from the class path then we create the Common-Cleaner thread fairly early due to the use of java.io.FileCleanable. The timing is similar for a jar file but triggered through java.util.zip.ZipFile$CleanableResource. So it would be strange if the Cleaner was not yet initialized.
14-05-2020

JDK-8235211 modified the AttachListener thread and the AttachListener thread is the last one listed so potentially related at first glance.
14-05-2020

...and not related to JDK-8235211, which impacts the Attach API, not SA Attach.
14-05-2020

This could just be a case of a slight delay in the JVM startup is causing the SA to attach before the Common-Cleaner thread has been created. As pointed out, the Common-Cleaner is normally the last listed, so is probably the last created. However, it seems odd that LingeredApp is fully started and doing it's Thread.sleep() routine already, yet no code has referenced CleanerFactory to trigger the creation of Common-Cleaner.
14-05-2020