JDK-8260303 : vmTestbase/jit/escape/AdaptiveBlocking/AdaptiveBlocking001/AdaptiveBlocking001.java timed out
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: 17,18
  • Priority: P4
  • Status: In Progress
  • Resolution: Unresolved
  • OS: windows
  • CPU: x86_64
  • Submitted: 2021-01-22
  • Updated: 2022-01-26
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.
JDK 19
19Unresolved
Related Reports
Relates :  
Relates :  
Sub Tasks
JDK-8264662 :  
JDK-8278909 :  
Description
The following test timed out in the JDK17 CI:

vmTestbase/jit/escape/AdaptiveBlocking/AdaptiveBlocking001/AdaptiveBlocking001.java

Here's a snippet from the log file:

#section:driver
----------messages:(8/489)----------
command: driver ExecDriver --java -server -Xcomp -XX:+DoEscapeAnalysis jit.escape.AdaptiveBlocking.AdaptiveBlocking001.AdaptiveBlocking001 -numRounds 10
reason: User specified action: run driver/timeout=300 ExecDriver --java -server -Xcomp -XX:+DoEscapeAnalysis jit.escape.AdaptiveBlocking.AdaptiveBlocking001.AdaptiveBlocking001 -numRounds 10 
Mode: agentvm
Agent id: 5
Timeout refired 3000 times
Timeout information:
--- Timeout information end.
elapsed time (seconds): 4706.187
----------configuration:(15/1548)*----------
Boot Layer
  class path: C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\5.1\\b01\\bundles\\jtreg_bin-5.1.zip\\jtreg\\lib\\javatest.jar 
              C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\5.1\\b01\\bundles\\jtreg_bin-5.1.zip\\jtreg\\lib\\jtreg.jar 
              C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\5.1\\b01\\bundles\\jtreg_bin-5.1.zip\\jtreg\\lib\\junit.jar 
              C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\5.1\\b01\\bundles\\jtreg_bin-5.1.zip\\jtreg\\lib\\testng.jar 
  patch:      java.base T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_vm_compiler_quick\\patches\\java.base

Test Layer
  class path: T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_vm_compiler_quick\\classes\\2\\vmTestbase\\jit\\escape\\AdaptiveBlocking\\AdaptiveBlocking001\\AdaptiveBlocking001.d
              C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+6-358\\src.full\\open\\test\\hotspot\\jtreg\\vmTestbase\\jit\\escape\\AdaptiveBlocking\\AdaptiveBlocking001
              T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_vm_compiler_quick\\classes\\2\\vmTestbase
              C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+6-358\\src.full\\open\\test\\hotspot\\jtreg\\vmTestbase
              T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_vm_compiler_quick\\classes\\2\\test\\lib
              C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+6-358\\src.full\\open\\test\\lib

----------rerun:(37/6301)*----------

<snip>

----------System.out:(23/1638)*----------
exec [c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+6-358\\windows-x64-debug.jdk\\jdk-17\\fastdebug\\bin\\java, -XX:MaxRAMPercentage=6, -Djava.io.tmpdir=t:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_vm_compiler_quick\\tmp, -XX:+CreateCoredumpOnCrash, -XX:+UseZGC, -cp, T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_vm_compiler_quick\\classes\\2\\vmTestbase\\jit\\escape\\AdaptiveBlocking\\AdaptiveBlocking001\\AdaptiveBlocking001.d;T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_vm_compiler_quick\\classes\\2\\vmTestbase;T:\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_vm_compiler_quick\\classes\\2\\test\\lib, -Djava.library.path=c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+6-358\\windows-x64-debug.test\\hotspot\\jtreg\\native, -server, -Xcomp, -XX:+DoEscapeAnalysis, jit.escape.AdaptiveBlocking.AdaptiveBlocking001.AdaptiveBlocking001, -numRounds, 10]
Adaptive blocking test
round #0, latent locks: no...
round #0, latent locks: yes...
round #1, latent locks: no...
round #1, latent locks: yes...
round #2, latent locks: no...
round #2, latent locks: yes...
round #3, latent locks: no...
round #3, latent locks: yes...
round #4, latent locks: no...
round #4, latent locks: yes...
round #5, latent locks: no...
round #5, latent locks: yes...
round #6, latent locks: no...
round #6, latent locks: yes...
round #7, latent locks: no...
round #7, latent locks: yes...
round #8, latent locks: no...
round #8, latent locks: yes...
round #9, latent locks: no...
round #9, latent locks: yes...
TEST PASSED
----------System.err:(3/38)----------

JavaTest Message: Test complete.

result: Error. Agent error: java.lang.Exception: Agent 5 timed out with a timeout of 3000 seconds; check console log for any additional details

Please note that the test passed while the timeout handler was
running. The test executed for 78 minutes:

elapsed time (seconds): 4706.187

which is a pretty long time. The test is invoked with:

    run driver/timeout=300

and the typical timeoutFactor is 4 so this test should have
run for (4 * 300) => 1200 seconds before timeout. Instead
we see this:

Timeout refired 3000 times

which indicates that that the timeoutFactor is 10 for this
test task. Normally, I would check the task's log file, but
the test task is showing a state of "SCHEDULED" so I
think the test task is being rerun (for some reason).

Starting this bug off in hotspot/compiler since this is a
"jit/escape" test.
Comments
No new timeouts so far.
26-01-2022

All timeouts happens on Windows_10_Enterprise, VM.Standard.E2.4.
21-05-2021

This bug may very well relate to JDK-8260062 The windows machines are experiencing safepoint synchronization times up to 20 seconds due to thread starvation.
15-02-2021

Stuck on this one without more data. I will wait a bit to see if more timeouts happen.
03-02-2021

So why was it restarted? If this is the only failure - then I would expect that the restart was the cause of the timeout.
03-02-2021

The artifact of the test failure contains a different log than the one attached. Same test, same build but different contents and results. Can the testing of that build have been restarted?
03-02-2021

That's probably because the task was re-executed (as Daniel mentioned).
03-02-2021

The log file doesn't match the links in the first comment.
03-02-2021

ILW = Test times out, intermittent at tier6 with single test on Windows, no known workaround = MLH = P4
27-01-2021

Since the test task is scheduled to be rerun (for some reason), I've attached the log file for the failed run as: mach5-one-jdk-17+6-358-tier6-20210122-1257-17654483-tier6-gc-zgc-vmTestbase_vm_compiler_quick-windows-x64-debug-windows-x64-10-or-2019-350-1611331038-34.log
22-01-2021