JDK-8245126 : Kitchensink fails with: assert(!method->is_old()) failed: Should not be installing old methods
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jvmti
  • Affected Version: 15
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2020-05-15
  • Updated: 2020-07-02
  • Resolved: 2020-06-11
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 15 JDK 16
15 b27Fixed 16Fixed
Related Reports
Relates :  
JDK-8245128 - Kitchensink fails with: assert(destination == (address)-1 || destination == entry) failed: b) MT-unsafe modification of inline cache
Relates :  
JDK-8222005 - ClassRedefinition crashes with: guarantee(false) failed: OLD and/or OBSOLETE method(s) found
Description
Kitchensink test with the Instrumentation module enabled can fail with the following assert in the compiled code:

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (/opt/mach5/mesos/work_dir/slaves/805146e6-8fdb-4552-bf9e-385b73cf7129-S235/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/c5812956-db92-4493-b2ef-110650bcdca6/runs/9f403178-bf07-4927-851f-76543ee49c1d/workspace/open/src/hotspot/share/code/nmethod.cpp:2328), pid=17594, tid=17608
#  assert(!method->is_old()) failed: Should not be installing old methods
#
# JRE version: Java(TM) SE Runtime Environment (15.0) (fastdebug build 15-internal+0-2020-05-15-1614430.serguei.spitsyn.jdk15.2)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 15-internal+0-2020-05-15-1614430.serguei.spitsyn.jdk15.2, compiled mode, sharing, compressed oops, g1 gc, linux-amd64)
# Problematic frame:
# V  [libjvm.so+0x1325fc4]  nmethod::metadata_do(MetadataClosure*)+0x7b4
#
# Core dump will be written. Default location: Core dumps may be processed with "/opt/core.sh %p" (or dumping to /opt/mach5/mesos/work_dir/slaves/805146e6-8fdb-4552-bf9e-385b73cf7129-S289/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/45a8c92b-127f-4604-a23c-44c322d60174/runs/6244c07e-518c-4ba5-b079-722ac9cbf54e/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_kitchensink_Kitchensink_java/scratch/0/core.17594)
#
# If you would like to submit a bug report, please visit:
#   https://bugreport.java.com/bugreport/crash.jsp
#

---------------  S U M M A R Y ------------

Command Line: -Xbootclasspath/a:/opt/mach5/mesos/work_dir/slaves/805146e6-8fdb-4552-bf9e-385b73cf7129-S289/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/45a8c92b-127f-4604-a23c-44c322d60174/runs/6244c07e-518c-4ba5-b079-722ac9cbf54e/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_kitchensink_Kitchensink_java/scratch/0/wb.jar -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -XX:MaxRAMPercentage=6 -Xlog:class+redefine*=info -Xcomp -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -XX:-TieredCompilation -XX:+CreateCoredumpOnCrash -XX:MaxRAMPercentage=50 -XX:MaxMetaspaceSize=512m -XX:+HeapDumpOnOutOfMemoryError -XX:+CrashOnOutOfMemoryError -Djava.net.preferIPv6Addresses=false -XX:+DisplayVMOutputToStderr -Xlog:gc*,gc+heap=debug:gc.log:uptime,timemillis,level,tags -XX:+DisableExplicitGC -XX:+StartAttachListener --illegal-access=deny --add-modules=jdk.incubator.foreign --add-exports=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.lang=ALL-UNNAMED --add-exports=java.base/jdk.internal.org.objectweb.asm=ALL-UNNAMED --add-exports=java.xml/com.sun.org.apache.xerces.internal.parsers=ALL-UNNAMED --add-exports=java.xml/com.sun.org.apache.xerces.internal.util=ALL-UNNAMED -Djava.io.tmpdir=/opt/mach5/mesos/work_dir/slaves/805146e6-8fdb-4552-bf9e-385b73cf7129-S289/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/45a8c92b-127f-4604-a23c-44c322d60174/runs/6244c07e-518c-4ba5-b079-722ac9cbf54e/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_kitchensink_Kitchensink_java/scratch/0/java.io.tmpdir -Duser.home=/opt/mach5/mesos/work_dir/slaves/805146e6-8fdb-4552-bf9e-385b73cf7129-S289/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/45a8c92b-127f-4604-a23c-44c322d60174/runs/6244c07e-518c-4ba5-b079-722ac9cbf54e/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_kitchensink_Kitchensink_java/scratch/0/user.home -agentpath:/opt/mach5/mesos/work_dir/jib-master/install/2020-05-15-1614430.serguei.spitsyn.jdk15.2/linux-x64-debug.test/hotspot/jtreg/native/libJvmtiStressModule.so -Xverify:all -javaagent:redefineagent.jar -XX:NativeMemoryTracking=detail -Djdk.test.lib.random.seed=1910729248517374629 applications.kitchensink.process.stress.Main /opt/mach5/mesos/work_dir/slaves/805146e6-8fdb-4552-bf9e-385b73cf7129-S289/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/45a8c92b-127f-4604-a23c-44c322d60174/runs/6244c07e-518c-4ba5-b079-722ac9cbf54e/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_kitchensink_Kitchensink_java/scratch/0/kitchensink.final.properties

Host: ol7-build-test-205274, Intel(R) Xeon(R) Platinum 8167M CPU @ 2.00GHz, 8 cores, 58G, Oracle Linux Server release 7.8
Time: Fri May 15 17:19:41 2020 UTC elapsed time: 1224.225740 seconds (0d 0h 20m 24s)

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

Current thread (0x00007f447831b800):  JavaThread "C2 CompilerThread0" daemon [_thread_in_vm, id=17608, stack(0x00007f442477a000,0x00007f442487b000)]


Current CompileTask:
C2:1224225 71066    b        java.lang.ref.Reference::get (5 bytes)

Stack: [0x00007f442477a000,0x00007f442487b000],  sp=0x00007f4424875fb0,  free space=1007k
Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x1325fc4]  nmethod::metadata_do(MetadataClosure*)+0x7b4
V  [libjvm.so+0x132ef14]  nmethod::verify()+0x3f4
V  [libjvm.so+0x1328afd]  nmethod::new_nmethod(methodHandle const&, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int, char*, int, int, char const*, FailedSpeculation**)+0x3dd
V  [libjvm.so+0x7d146b]  ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, bool, bool, RTMState)+0x56b
V  [libjvm.so+0x13d37ad]  PhaseOutput::install_code(ciMethod*, int, AbstractCompiler*, bool, bool, RTMState)+0x17d
V  [libjvm.so+0x13d39a4]  PhaseOutput::install()+0x164
V  [libjvm.so+0x8fa111]  Compile::Code_Gen()+0x461
V  [libjvm.so+0x901a43]  Compile::Compile(ciEnv*, ciMethod*, int, bool, bool, bool, DirectiveSet*)+0x1763
V  [libjvm.so+0x74aa25]  C2Compiler::compile_method(ciEnv*, ciMethod*, int, DirectiveSet*)+0x175
V  [libjvm.so+0x91094e]  CompileBroker::invoke_compiler_on_method(CompileTask*)+0x45e
V  [libjvm.so+0x912488]  CompileBroker::compiler_thread_loop()+0xab8
V  [libjvm.so+0x16a7ac6]  JavaThread::thread_main_inner()+0x226
V  [libjvm.so+0x16ad960]  Thread::call_run()+0x100
V  [libjvm.so+0x13b2396]  thread_native_entry(Thread*)+0x116

It seems, a method can be redefined/retransformed before the compiler gets new nmethod installed. So, the compiler may need to check if the method has not become old before nmethod installation.

This problem is very intermittent and rarely reproducible.
The Kitchensink Instrumentation module needs to be enabled.
Also, the options to use are:
  -Xlog:class+redefine*=trace -Xcomp -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -XX:-TieredCompilation -XX:+CreateCoredumpOnCrash
Comments
Changeset: 6d8c81f6 Author: Serguei Spitsyn <sspitsyn@openjdk.org> Date: 2020-06-11 06:04:05 +0000 URL: https://git.openjdk.java.net/lanai/commit/6d8c81f6
02-07-2020
URL: https://hg.openjdk.java.net/jdk/jdk/rev/3b165fdd3722 User: sspitsyn Date: 2020-06-11 06:04:44 +0000
11-06-2020
The suggested fix is: http://cr.openjdk.java.net/~sspitsyn/webrevs/2020/kitchensink-comp.1/
26-05-2020
I've moved the bug to hotspot/jvmti sub-component. This bug is in a gray zone between compiler and JVMTI. The fix itself is needed in the compiler files but Kitchensink with the Instrumentation module enabled is failing because the JVMTI support is broken.
26-05-2020
I've added an assert into ciEnv::register_method() after NoSafepointVerifier nsv; assert(!target->get_Method()->is_old(), "MY_TRACE: ciEnv::register_method: target method is old"); and got it fired: # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/opt/mach5/mesos/work_dir/slaves/805146e6-8fdb-4552-bf9e-385b73cf7129-S276/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/5e14c647-d84b-441d-bf0e-ed7d433ddaba/runs/4a69aa60-0e17-4aa2-974f-10dea9a9f4e9/workspace/open/src/hotspot/share/ci/ciEnv.cpp:987), pid=30409, tid=30519 # assert(!target->get_Method()->is_old()) failed: MY_TRACE: ciEnv::register_method: target method is old # # JRE version: Java(TM) SE Runtime Environment (15.0) (fastdebug build 15-internal+0-2020-05-22-1039134.serguei.spitsyn.jdk15.2) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 15-internal+0-2020-05-22-1039134.serguei.spitsyn.jdk15.2, compiled mode, sharing, compressed oops, g1 gc, linux-amd64) # Problematic frame: # V [libjvm.so+0x7d15d3] ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, bool, bool, RTMState)+0x803 . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . --------------- T H R E A D --------------- Current thread (0x00007efbf6615000): JavaThread "C2 CompilerThread1" daemon [_thread_in_vm, id=30519, stack(0x00007efbeb0f1000,0x00007efbeb1f2000)] Current CompileTask: C2: 54262 6846 b java.lang.invoke.VarHandles::makeFieldHandle (836 bytes) Stack: [0x00007efbeb0f1000,0x00007efbeb1f2000], sp=0x00007efbeb1ed340, free space=1008k Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code) V [libjvm.so+0x7d15d3] ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, bool, bool, RTMState)+0x803 V [libjvm.so+0x13d33ad] PhaseOutput::install_code(ciMethod*, int, AbstractCompiler*, bool, bool, RTMState)+0x17d V [libjvm.so+0x13d35a4] PhaseOutput::install()+0x164 V [libjvm.so+0x8fa0b1] Compile::Code_Gen()+0x461 V [libjvm.so+0x9019e3] Compile::Compile(ciEnv*, ciMethod*, int, bool, bool, bool, DirectiveSet*)+0x1763 V [libjvm.so+0x74aa25] C2Compiler::compile_method(ciEnv*, ciMethod*, int, DirectiveSet*)+0x175 V [libjvm.so+0x9108ee] CompileBroker::invoke_compiler_on_method(CompileTask*)+0x45e V [libjvm.so+0x912428] CompileBroker::compiler_thread_loop()+0xab8 V [libjvm.so+0x16a7766] JavaThread::thread_main_inner()+0x226 V [libjvm.so+0x16ad600] Thread::call_run()+0x100 V [libjvm.so+0x13b1f96] thread_native_entry(Thread*)+0x116
22-05-2020
A method can be set old in the VM_RedefineClasses::doit(). VM_RedefineClasses::doit() also increments the _jvmti_redefinition_count at the beginning. The CompileBroker::invoke_compiler_on_method() checks the target_handle (method to compile) is not old with: if (target_handle->is_old()) If the target method to compile is not old then the JVMCICompileState is cached before the call to C2Compiler::compile_method(): JVMCICompileState compile_state(task); The _jvmti_redefinition_count is cached as part of the JVMCICompileState. Likely the assumption is: ensuring _jvmti_redefinition_count is the same guarantees target method to remain non-old as well. The ciEnv::register_method() works in execution context of the C2Compiler::compile_method. Under protection of the MethodCompileQueue_lock, Compiler_lock and NoSafepointVerifier, it checks for !jvmti_state_changed() so it is safe to register the compiler method.. The jvmti_state_changed() checks that the _jvmti_redefinition_count was not changed. So, at least, at the start of the ciEnv::register_method() the compiled method should not be old. The NoSafepointVerifier must guarantee that there are no safepoints at the time new nmethod is registered. A record_failure is reported if any redefinition happens between the call to C2Compiler::compile_method and check and this check: // Change in Jvmti state may invalidate compilation. if (!failing() && jvmti_state_changed()) { record_failure("Jvmti state change invalidated dependencies"); } The sync approach described above looks pretty good but seems to be broken somewhere. A trap needs to be constructed to catch where it is exactly broken. Some of the assumptions might be incorrect.
22-05-2020
Assigned to myself for initial evaluation.
19-05-2020
The patch to enable Instrumentation module: diff --git a/closed/test/hotspot/jtreg/applications/kitchensink/kitchensink.properties b/closed/test/hotspot/jtreg/applications/kitchensink/kitchensink.properties --- a/closed/test/hotspot/jtreg/applications/kitchensink/kitchensink.properties +++ b/closed/test/hotspot/jtreg/applications/kitchensink/kitchensink.properties @@ -14,7 +14,7 @@ #user.dir modules.additional= -modules.enable=Allocator,Exception,Jcmd,Jfr,Jni,Jstat,Jvmti,Inflater,LockDeflation,MBean,MemAccess,Monitor,NMT,Perfmon,Reference,SpecJbb2005,SpecJvm2008Batch,ThreadDumper,${modules.additional} +modules.enable=Allocator,Exception,Jcmd,Jfr,Jni,Jstat,Jvmti,Inflater,Instrumentation,LockDeflation,MBean,MemAccess,Monitor,NMT,Perfmon,Reference,SpecJbb2005,SpecJvm2008Batch,ThreadDumper,${modules.additional} test.duration=30m result.analyzer.definition.files=kitchensink.stress.def,kitchensink.perf.def
19-05-2020