Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8315795

runtime/Safepoint/TestAbortVMOnSafepointTimeout.java fails after JDK-8305507

    XMLWordPrintable

Details

    • b15
    • x86_64
    • windows
    • Verified

    Description

      The following test failed in the JDK22 CI:

      runtime/Safepoint/TestAbortVMOnSafepointTimeout.java

      Here's a snippet from the log file:

      #section:driver
      ----------messages:(7/260)----------
      command: driver TestAbortVMOnSafepointTimeout
      reason: User specified action: run driver TestAbortVMOnSafepointTimeout
      started: Tue Sep 05 23:27:38 UTC 2023
      Mode: agentvm
      Agent id: 45
      finished: Tue Sep 05 23:27:41 UTC 2023
      elapsed time (seconds): 3.969
      ----------configuration:(16/1689)*----------

      <snip>

      ----------System.out:(8/3627)*----------
      Command line: [c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-22+14-1021\\windows-x64-debug.jdk\\jdk-22\\fastdebug\\bin\\java.exe -cp C:\\sb\\prod\\1693955935\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_runtime\\classes\\1\\runtime\\Safepoint\\TestAbortVMOnSafepointTimeout.d;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-22+14-1021\\src.full\\open\\test\\hotspot\\jtreg\\runtime\\Safepoint;C:\\sb\\prod\\1693955935\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_runtime\\classes\\1\\testlibrary;C:\\sb\\prod\\1693955935\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_runtime\\classes\\1\\test\\lib;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\jtreg.jar;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\junit-platform-console-standalone-1.9.2.jar;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\testng-7.3.0.jar;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\jcommander-1.82.jar;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\guice-5.1.0.jar -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -XX:+SafepointTimeout -XX:+SafepointALot -XX:+AbortVMOnSafepointTimeout -XX:SafepointTimeoutDelay=50 -XX:GuaranteedSafepointInterval=1 -XX:-CreateCoredumpOnCrash -Xms64m TestAbortVMOnSafepointTimeout$Test 999 ]
      [2023-09-05T23:27:38.062973700Z] Gathering output for process 9824
      [2023-09-05T23:27:38.916360Z] Waiting for completion for process 9824
      [2023-09-05T23:27:38.932021200Z] Waiting for completion finished for process 9824
      Command line: [c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-22+14-1021\\windows-x64-debug.jdk\\jdk-22\\fastdebug\\bin\\java.exe -cp C:\\sb\\prod\\1693955935\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_runtime\\classes\\1\\runtime\\Safepoint\\TestAbortVMOnSafepointTimeout.d;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-22+14-1021\\src.full\\open\\test\\hotspot\\jtreg\\runtime\\Safepoint;C:\\sb\\prod\\1693955935\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_runtime\\classes\\1\\testlibrary;C:\\sb\\prod\\1693955935\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_runtime\\classes\\1\\test\\lib;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\jtreg.jar;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\junit-platform-console-standalone-1.9.2.jar;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\testng-7.3.0.jar;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\jcommander-1.82.jar;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.3.1\\1\\bundles\\jtreg-7.3.1+1.zip\\jtreg\\lib\\guice-5.1.0.jar -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -XX:+SafepointTimeout -XX:+SafepointALot -XX:+AbortVMOnSafepointTimeout -XX:AbortVMOnSafepointTimeoutDelay=2500 -XX:SafepointTimeoutDelay=50 -XX:GuaranteedSafepointInterval=1 -XX:-CreateCoredumpOnCrash -Xms64m TestAbortVMOnSafepointTimeout$TestWithDelay ]
      [2023-09-05T23:27:38.932021200Z] Gathering output for process 47860
      [2023-09-05T23:27:41.724038600Z] Waiting for completion for process 47860
      [2023-09-05T23:27:41.739681500Z] Waiting for completion finished for process 47860
      ----------System.err:(55/3512)*----------
       stdout: [[0.530s][warning][safepoint]
      [0.531s][warning][safepoint] # SafepointSynchronize::begin: Timeout detected:
      [0.531s][warning][safepoint] # SafepointSynchronize::begin: Timed out while spinning to reach a safepoint.
      [0.531s][warning][safepoint] # SafepointSynchronize::begin: Threads which did not reach the safepoint:
      [0.531s][warning][safepoint] # "main" #1 [53624] prio=5 os_prio=0 cpu=187.50ms elapsed=0.49s tid=0x000001f5c77c2980 nid=53624 runnable [0x00000001ab5fd000]
      [0.531s][warning][safepoint] java.lang.Thread.State: RUNNABLE
      [0.531s][warning][safepoint] Thread: 0x000001f5c77c2980 [0xd178] State: _running _at_poll_safepoint 0
      [0.531s][warning][safepoint] JavaThread state: _thread_in_vm
      [0.531s][warning][safepoint]
      [0.531s][warning][safepoint] # SafepointSynchronize::begin: (End of list)
      [0.743s][warning][safepoint] # SafepointSynchronize: Finished after 281 ms
      [1.013s][warning][safepoint]
      [1.013s][warning][safepoint] # SafepointSynchronize::begin: Timeout detected:
      [1.013s][warning][safepoint] # SafepointSynchronize::begin: Timed out while spinning to reach a safepoint.
      [1.013s][warning][safepoint] # SafepointSynchronize::begin: Threads which did not reach the safepoint:
      [1.013s][warning][safepoint] # "main" #1 [53624] prio=5 os_prio=0 cpu=250.00ms elapsed=0.97s tid=0x000001f5c77c2980 nid=53624 runnable [0x00000001ab5ff000]
      [1.013s][warning][safepoint] java.lang.Thread.State: RUNNABLE
      [1.013s][warning][safepoint] Thread: 0x000001f5c77c2980 [0xd178] State: _running _at_poll_safepoint 0
      [1.013s][warning][safepoint] JavaThread state: _thread_in_vm
      [1.013s][warning][safepoint]
      [1.013s][warning][safepoint] # SafepointSynchronize::begin: (End of list)
      #
      # A fatal error has been detected by the Java Runtime Environment:
      #
      # Internal Error (c:\\sb\\prod\\1693954293\\workspace\\open\\src\\hotspot\\share\\runtime\\safepoint.cpp:823), pid=47860, tid=60696
      # fatal error: Safepoint sync time longer than 50.000000 ms detected when executing SafepointALot.
      #
      # JRE version: Java(TM) SE Runtime Environment (22.0+14) (fastdebug build 22-ea+14-1021)
      # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 22-ea+14-1021, mixed mode, sharing, tiered, compressed oops, compressed class ptrs, g1 gc, windows-amd64)
      # CreateCoredumpOnCrash turned off, no core file dumped
      #
      Unsupported internal testing APIs have been used.

      # An error report file with more information is saved as:
      # C:\\sb\\prod\\1693955935\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_runtime\\scratch\\4\\hs_err_pid47860.log
      #
      # If you would like to submit a bug report, please visit:
      # https://bugreport.java.com/bugreport/crash.jsp
      #
      ];
       stderr: []
       exitValue = 1

      java.lang.RuntimeException: 'THE FOLLOWING STALL SHOULD BE CAPTURED' missing from stdout/stderr
      at jdk.test.lib.process.OutputAnalyzer.shouldContain(OutputAnalyzer.java:221)
      at TestAbortVMOnSafepointTimeout.testGracePeriodAppliedBeforeVmAbort(TestAbortVMOnSafepointTimeout.java:80)
      at TestAbortVMOnSafepointTimeout.main(TestAbortVMOnSafepointTimeout.java:102)
      at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
      at java.base/java.lang.reflect.Method.invoke(Method.java:580)
      at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
      at java.base/java.lang.Thread.run(Thread.java:1570)

      JavaTest Message: Test threw exception: java.lang.RuntimeException
      JavaTest Message: shutting down test

      result: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: 'THE FOLLOWING STALL SHOULD BE CAPTURED' missing from stdout/stderr

      The failing error mesg was added by the following fix:

      JDK-8305507 Add support for grace period before AbortVMOnSafepointTimeout triggers

      so it looks like JDK-8305507 has caused a regression so I'm starting
      this bug off as a P2. The fix for JDK-8305507 was integrated in
      jdk-22+14-1015 and this first sighting happened in jdk-22+14-1021-tier1.

      Attachments

        Issue Links

          Activity

            People

              pchilanomate Patricio Chilano Mateo
              dcubed Daniel Daugherty
              Votes:
              0 Vote for this issue
              Watchers:
              8 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: