JDK-8288846 : misc tests fail "assert(ms < 1000) failed: Un-interruptable sleep, short time use only"
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jfr
  • Affected Version: 19,20
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2022-06-21
  • Updated: 2024-02-23
  • Resolved: 2022-06-22
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 17 JDK 19 JDK 20
17.0.11Fixed 19 b28Fixed 20Fixed
Related Reports
Duplicate :  
Relates :  
Relates :  
Relates :  
Description
The following test failed in the JDK19 CI:

vmTestbase/nsk/jvmti/scenarios/hotswap/HS302/hs302t002/hs302t002.java

Here's a snippet from the log file:

#section:main
----------messages:(4/435)----------
command: main -agentlib:hs302t002=pathToNewByteCode=./bin,-waittime=5,package=nsk,samples=100,mode=compiled nsk.jvmti.scenarios.hotswap.HS302.hs302t002.hs302t002
reason: User specified action: run main/othervm/native -agentlib:hs302t002=pathToNewByteCode=./bin,-waittime=5,package=nsk,samples=100,mode=compiled nsk.jvmti.scenarios.hotswap.HS302.hs302t002.hs302t002 
Mode: othervm [/othervm specified]
elapsed time (seconds): 4.085
----------configuration:(0/0)----------
----------System.out:(30/1899)*----------
Agent:: VM.. Started..
 Enabled. noftification..[2.238s][info][jfr,startup] Started recording 1. No limit specified, using maxsize=250MB as default.
[2.238s][info][jfr,startup] 
[2.238s][info][jfr,startup] Use jcmd 81124 JFR.dump name=1 filename=FILEPATH to copy recording data to file.
# info :: File = ./bin/newclass00/nsk/jvmti/scenarios/hotswap/HS302/hs302t002/MyClass.class 
#  info **Agent:: opening file ./bin/newclass00/nsk/jvmti/scenarios/hotswap/HS302/hs302t002/MyClass.class 
# info file size= 728
 File red completely 
# error occured while redefining JVMTI_ERROR_UNSUPPORTED_REDEFINITION_METHOD_MODIFIERS_CHANGED Redefine failed ..     
 Constructor..
 cls.toString() public
 Passed ..
# To suppress the following error report, specify this argument
# after -XX: or in .hotspotrc:  SuppressErrorAt=\\os_windows.cpp:3762
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (c:\\sb\\prod\\1655746817\\workspace\\open\\src\\hotspot\\os\\windows\\os_windows.cpp:3762), pid=81124, tid=64432
#  assert(ms < 1000) failed: Un-interruptable sleep, short time use only
#
# JRE version: Java(TM) SE Runtime Environment (19.0+28) (fastdebug build 19-ea+28-2096)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 19-ea+28-2096, mixed mode, sharing, tiered, compressed oops, compressed class ptrs, g1 gc, windows-amd64)
# Core dump will be written. Default location: C:\\sb\\prod\\1655809690\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_nsk_jvmti_quick\\scratch\\3\\hs_err_pid81124.mdmp
#
# An error report file with more information is saved as:
# C:\\sb\\prod\\1655809690\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_vmTestbase_nsk_jvmti_quick\\scratch\\3\\hs_err_pid81124.log
#
# If you would like to submit a bug report, please visit:
#   https://bugreport.java.com/bugreport/crash.jsp
#
----------System.err:(0/0)----------
----------rerun:(40/7054)*----------

Here's the crashing thread's stack:

---------------  T H R E A D  ---------------

Current thread (0x000001e407df7db0):  JfrThreadSampler "JFR Thread Sampler" [stack: 0x0000000f9d500000,0x0000000f9d600000] [id=64432]

Stack: [0x0000000f9d500000,0x0000000f9d600000]
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [jvm.dll+0xc84f41]  os::platform_print_native_stack+0xf1  (os_windows_x86.cpp:235)
V  [jvm.dll+0xee66eb]  VMError::report+0x10eb  (vmError.cpp:835)
V  [jvm.dll+0xee822e]  VMError::report_and_die+0x7fe  (vmError.cpp:1687)
V  [jvm.dll+0xee89b4]  VMError::report_and_die+0x64  (vmError.cpp:1468)
V  [jvm.dll+0x5a7137]  report_vm_error+0xb7  (debug.cpp:283)
V  [jvm.dll+0xc7fb13]  os::naked_short_sleep+0x33  (os_windows.cpp:3762)
V  [jvm.dll+0x86b489]  JfrThreadSampler::run+0x159  (jfrThreadSampler.cpp:527)
V  [jvm.dll+0xe58e0c]  Thread::call_run+0x1ac  (thread.cpp:365)
V  [jvm.dll+0xc837e9]  thread_native_entry+0xb9  (os_windows.cpp:545)
C  [ucrtbase.dll+0x1fb80]
C  [KERNEL32.DLL+0x84d4]
C  [ntdll.dll+0x51791]


Comments
Fix request [17u] I backport this to fix an issue brought by backport of JDK-8288663 we see in our CI. Low risk, touches jfr. Must have, as it is a follow up to a previous backport to this release (17.0.11). Clean backport. Test passes. SAP nightly testing passed.
23-02-2024

A pull request was submitted for review. URL: https://git.openjdk.org/jdk17u-dev/pull/2219 Date: 2024-02-22 09:57:27 +0000
22-02-2024

The fix for this bug was sync'ed into JDK20 in jdk-20+3-107.
23-06-2022

The fix for this bug is integrated in jdk-19+28-2110.
22-06-2022

Changeset: 6037ccdd Author: Markus Grönlund <mgronlun@openjdk.org> Date: 2022-06-22 13:29:44 +0000 URL: https://git.openjdk.org/jdk19/commit/6037ccdd50acd5424a46120028738b811dff064a
22-06-2022

A pull request was submitted for review. URL: https://git.openjdk.org/jdk19/pull/57 Date: 2022-06-22 10:59:27 +0000
22-06-2022

The assertion is a consequence of JDK-8288748, in that when the sampler is disenrolling, both fields are now set to 0, and that implies max_jlong. The problem has always existed and can be provoked by setting the period to something that will ensure the sleep_to_next value to be > 1000. For example: <event name="jdk.ExecutionSample"> <setting name="enabled" control="method-sampling-enabled">true</setting> <setting name="period" control="method-sampling-java-interval">1000 ms</setting> </event>
22-06-2022