JDK-8223600 : test/hotspot/jtreg/serviceability/dcmd/framework/HelpTest.java timeout
  • Type: Bug
  • Component: hotspot
  • Sub-Component: svc
  • Affected Version: 13
  • Priority: P3
  • Status: Resolved
  • Resolution: Duplicate
  • Submitted: 2019-05-09
  • Updated: 2019-06-21
  • Resolved: 2019-06-21
Related Reports
Duplicate :  
JDK-8220175 - serviceability/dcmd/framework/VMVersionTest.java fails with a timeout
Relates :  
JDK-8217351 - serviceability/dcmd/framework/InvalidCommandTest.java failed with timeout
Description
---------------- stdout ----------------
The following commands are available:
Compiler.CodeHeap_Analytics
Compiler.codecache
Compiler.codelist
Compiler.directives_add
Compiler.directives_clear
Compiler.directives_print
Compiler.directives_remove
Compiler.queue
GC.class_histogram
GC.class_stats
GC.finalizer_info
GC.heap_info
GC.run
GC.run_finalization
JFR.check
JFR.configure
JFR.dump
JFR.start
JFR.stop
JVMTI.agent_load
JVMTI.data_dump
Thread.print
VM.class_hierarchy
VM.classloader_stats
VM.classloaders
VM.command_line
VM.dynlibs
VM.flags
VM.info
VM.log
VM.metaspace
VM.native_memory
VM.print_touched_methods
VM.set_flag
VM.start_java_debugging
VM.stringtable
VM.symboltable
VM.system_properties
VM.systemdictionary
VM.uptime
VM.version
help

For more information about a specific command use 'help <command>'.

---------------- stderr ----------------

----------------------------------------

test HelpTest.jmx(): success
debugee.stdout> Test Java process started!
debugee.stdout> Waiting for the quit command from the test ...
Running DCMD 'help' through 'MainClassJcmdExecutor'
Executing command '[/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk-13-985/linux-x64-debug.jdk/jdk-13/fastdebug/bin/jcmd, HelpTest$Process, help]'
Timeout refired 480 times
Command returned with exit code 134
---------------- stdout ----------------

---------------- stderr ----------------

----------------------------------------

debugee.stdout> 'quit' received
test HelpTest.mainClass(): failure
java.lang.RuntimeException: 'The following commands are available' missing from stdout/stderr 

	at jdk.test.lib.process.OutputAnalyzer.shouldContain(OutputAnalyzer.java:162)
	at HelpTest.run(HelpTest.java:47)
	at HelpTest.mainClass(HelpTest.java:62)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:567)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:85)
	at org.testng.internal.Invoker.invokeMethod(Invoker.java:639)
	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:821)
	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1131)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:124)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:108)
	at org.testng.TestRunner.privateRun(TestRunner.java:773)
	at org.testng.TestRunner.run(TestRunner.java:623)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:357)
	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:352)
	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:310)
	at org.testng.SuiteRunner.run(SuiteRunner.java:259)
	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1185)
	at org.testng.TestNG.runSuitesLocally(TestNG.java:1110)
	at org.testng.TestNG.run(TestNG.java:1018)
	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94)
	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:567)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
	at java.base/java.lang.Thread.run(Thread.java:830)
Running DCMD 'help' through 'PidJcmdExecutor'
Executing command '[/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk-13-985/linux-x64-debug.jdk/jdk-13/fastdebug/bin/jcmd, 5325, help]'
Command returned with exit code 0
---------------- stdout ----------------
5325:
The following commands are available:
Compiler.CodeHeap_Analytics
Compiler.codecache
Compiler.codelist
Compiler.directives_add
Compiler.directives_clear
Compiler.directives_print
Compiler.directives_remove
Compiler.queue
GC.class_histogram
GC.class_stats
GC.finalizer_info
GC.heap_dump
GC.heap_info
GC.run
GC.run_finalization
JFR.check
JFR.configure
JFR.dump
JFR.start
JFR.stop
JVMTI.agent_load
JVMTI.data_dump
ManagementAgent.start
ManagementAgent.start_local
ManagementAgent.status
ManagementAgent.stop
Thread.print
VM.class_hierarchy
VM.classloader_stats
VM.classloaders
VM.command_line
VM.dynlibs
VM.flags
VM.info
VM.log
VM.metaspace
VM.native_memory
VM.print_touched_methods
VM.set_flag
VM.start_java_debugging
VM.stringtable
VM.symboltable
VM.system_properties
VM.systemdictionary
VM.uptime
VM.version
help

For more information about a specific command use 'help <command>'.

---------------- stderr ----------------

----------------------------------------

test HelpTest.pid(): success

===============================================
serviceability/dcmd/framework/HelpTest.java
Total tests run: 4, Failures: 1, Skips: 0
===============================================
Comments
This is the same cause as for JDK-8220175 . Closing this as a duplicate of JDK-8220175.
21-06-2019
I don't think lines can be removed from the status file as it seems to be a fixed set of data items - but the values can certainly change and I don't know how that is actually done if the "file" is being read. Though fscanf should return EOF if it hits EOF, not block AFAICS, but /proc is special. Might be worth writing a small test program that loops trying to extract the NSpid as get_namespace_pid() does.
09-05-2019
There's some inlining going on. Looks like the call sequence is: PerfMemory::attach() -> mmap_attach_shared() -> get_namespace_pid() -> fscanf() The get_namespace_pid() code is new as of: JDK-8193710: jcmd -l and jps commands do not list Java processes running in Docker containers I wonder if it is running into some issue because the "status" file is changing from underneath it. For example: while (!feof(fp)) { ret = fscanf(fp, "NSpid: %d %d", &pid, &nspid); What happens if after detecting that it is not EOF, one or more lines is removed from the "status" file, leaving you at EOF. I think the fscanf() call will block in this case.
09-05-2019
I spoke too soon about the expected message being present. I forgot that there are 4 subtests, and I only see the output for 3 of the 4.
09-05-2019
> Command returned with exit code 134 Looks like it crashed to me. [~ljiang] Leo: can you please add the mach5 job links. I suspect we may find a hs_err file if we dig into the artifactory files.
09-05-2019
The error is: java.lang.RuntimeException: 'The following commands are available' missing from stdout/stderr But clearly this message is in the output: ---------------- stdout ---------------- The following commands are available: Compiler.CodeHeap_Analytics ... We've had timeout issues with this test and the very similar InvalidCommandTest.java in the past that seem to be communcation related (not due to the test actually taking a long time). Some issues have been addressed, and failures are much less frequent now, but still pop up. This is probably a dup of JDK-8217351, but will leave open for now.
09-05-2019
Any chance the java options have an impact on this particular failure? -Dtest.java.opts='-XX:+UseParallelGC -XX:+UseParallelOldGC -XX:+UseNUMA -XX:+IgnoreUnrecognizedVMOptions' \\
09-05-2019