Bug ID: JDK-8262134 compiler/uncommontrap/TestDeoptOOM.java failed with "guarantee(false) failed: wrong number of expression stack elements during deopt"

JDK-8262134 : compiler/uncommontrap/TestDeoptOOM.java failed with "guarantee(false) failed: wrong number of expression stack elements during deopt"

Type: Bug
Component: hotspot
Sub-Component: compiler
Affected Version: 11,17,18

Priority: P3
Status: Resolved
Resolution: Fixed
OS: linux
CPU: x86_64

Submitted: 2021-02-22
Updated: 2023-10-25
Resolved: 2021-12-14

Versions (Unresolved/Resolved/Fixed)

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 11	JDK 13	JDK 15	JDK 17	JDK 18	JDK 19
11.0.15-oracleFixed	13.0.13Fixed	15.0.9Fixed	17.0.3-oracleFixed	18 b28Fixed	19Fixed

Related Reports

Relates :	JDK-8278758 - runtime/BootstrapMethod/BSMCalledTwice.java fails with release VMs after JDK-8262134
Relates :	JDK-8049252 - VerifyStack logic in Deoptimization::unpack_frames does not expect to see invoke bc at the top frame during normal deoptimization

Description

The following test failed in the JDK17 CI:

compiler/uncommontrap/TestDeoptOOM.java

Here's a snippet from the log file:

#section:main
----------messages:(4/643)----------
command: main -XX:-BackgroundCompilation -Xmx128M -XX:+IgnoreUnrecognizedVMOptions -XX:+VerifyStack -XX:CompileCommand=exclude,compiler.uncommontrap.TestDeoptOOM::main -XX:CompileCommand=exclude,compiler.uncommontrap.TestDeoptOOM::m9_1 compiler.uncommontrap.TestDeoptOOM
reason: User specified action: run main/othervm -XX:-BackgroundCompilation -Xmx128M -XX:+IgnoreUnrecognizedVMOptions -XX:+VerifyStack -XX:CompileCommand=exclude,compiler.uncommontrap.TestDeoptOOM::main -XX:CompileCommand=exclude,compiler.uncommontrap.TestDeoptOOM::m9_1 compiler.uncommontrap.TestDeoptOOM 
Mode: othervm [/othervm specified]
elapsed time (seconds): 25.999
----------configuration:(0/0)----------
----------System.out:(45/3101)----------
CompileCommand: exclude compiler/uncommontrap/TestDeoptOOM.main bool exclude = true
CompileCommand: exclude compiler/uncommontrap/TestDeoptOOM.m9_1 bool exclude = true
OOM caught in m1
Wrong number of expression stack elements during deoptimization
  Error occurred while verifying frame 0 (0..0, 0 is topmost)
  Fabricated interpreter frame had 1 expression stack elements
  Interpreter oop map had 0 expression stack elements
  try_next_mask = 0
  next_mask_expression_stack_size = -1
  callee_size_of_parameters = 0
  callee_max_locals = 0
  top_frame_expression_stack_adjustment = 0
  exec_mode = 1
  cur_invoke_parameter_size = 1
  Thread = 0x00007f370020f940, thread ID = 19928
  Interpreted frames:
    sun.util.cldr.CLDRLocaleProviderAdapter.getTimeZoneNameProvider()Ljava/util/spi/TimeZoneNameProvider; (bci 8)
 - sp: 0x00007f36e94c61f0
 - thread: "UsageTracker" #14 daemon prio=5 os_prio=0 cpu=1185.46ms elapsed=16.42s tid=0x00007f370020f940 nid=0x4dd8 runnable  [0x00007f36e94c5000]
   java.lang.Thread.State: RUNNABLE
Thread: 0x00007f370020f940  [0x4dd8] State: _running _at_poll_safepoint 0
   JavaThread state: _thread_in_Java
 - frame size: 26
 - interpreter_frame -> sp: 0x00007f36e94c6248
# To suppress the following error report, specify this argument
# after -XX: or in .hotspotrc:  SuppressErrorAt=/deoptimization.cpp:853
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (/opt/mach5/mesos/work_dir/slaves/983c483a-6907-44e0-ad29-98c7183575e2-S14826/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/9f825512-2738-4ffb-b585-2f7496ecee27/runs/d564efbd-a26d-4f69-8df4-100ba92994c6/workspace/open/src/hotspot/share/runtime/deoptimization.cpp:853), pid=19879, tid=19928
#  guarantee(false) failed: wrong number of expression stack elements during deopt
#
# JRE version: Java(TM) SE Runtime Environment (17.0+11) (fastdebug build 17-ea+11-LTS-782)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 17-ea+11-LTS-782, compiled mode, sharing, tiered, compressed oops, compressed class ptrs, g1 gc, linux-amd64)
# Problematic frame:
# V  [libjvm.so+0xab228f]  Deoptimization::unpack_frames(JavaThread*, int)+0xa7f
#
# 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/35ca6ea2-bf72-41ef-89b8-0c013c60cac4-S206/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/bc5bc38e-d5fa-4270-98b5-37f826bef99f/runs/a4f23d3b-7a11-4690-bde6-a97d6a9d5749/testoutput/test-support/jtreg_open_test_hotspot_jtreg_tier1_compiler_3/scratch/2/core.19879)
#
# An error report file with more information is saved as:
# /opt/mach5/mesos/work_dir/slaves/35ca6ea2-bf72-41ef-89b8-0c013c60cac4-S206/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/bc5bc38e-d5fa-4270-98b5-37f826bef99f/runs/a4f23d3b-7a11-4690-bde6-a97d6a9d5749/testoutput/test-support/jtreg_open_test_hotspot_jtreg_tier1_compiler_3/scratch/2/hs_err_pid19879.log
#
# If you would like to submit a bug report, please visit:
#   https://bugreport.java.com/bugreport/crash.jsp
#
----------System.err:(0/0)----------
----------rerun:(50/6485)*----------


Here's the crashing thread's stack:

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

Current thread (0x00007f370020f940):  JavaThread "UsageTracker" daemon [_thread_in_Java, id=19928, stack(0x00007f36e93c7000,0x00007f36e94c8000)]

Stack: [0x00007f36e93c7000,0x00007f36e94c8000],  sp=0x00007f36e94c41b0,  free space=1012k
Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0xab228f]  Deoptimization::unpack_frames(JavaThread*, int)+0xa7f
v  ~DeoptimizationBlob
j  sun.util.cldr.CLDRLocaleProviderAdapter.getTimeZoneNameProvider()Ljava/util/spi/TimeZoneNameProvider;+8 java.base@17-ea
j  sun.util.locale.provider.JRELocaleProviderAdapter.getLocaleServiceProvider(Ljava/lang/Class;)Ljava/util/spi/LocaleServiceProvider;+417 java.base@17-ea
j  sun.util.locale.provider.LocaleServiceProviderPool.findProviders(Ljava/util/Locale;Z)Ljava/util/List;+68 java.base@17-ea
j  sun.util.locale.provider.LocaleServiceProviderPool.getLocalizedObjectImpl(Lsun/util/locale/provider/LocaleServiceProviderPool$LocalizedObjectGetter;Ljava/util/Locale;ZLjava/lang/String;[Ljava/lang/Object;)Ljava/lang/Object;+53 java.base@17-ea
J 1018 c1 sun.util.locale.provider.LocaleServiceProviderPool.getLocalizedObject(Lsun/util/locale/provider/LocaleServiceProviderPool$LocalizedObjectGetter;Ljava/util/Locale;Ljava/lang/String;[Ljava/lang/Object;)Ljava/lang/Object; java.base@17-ea (11 bytes) @ 0x00007f36e9fbaee4 [0x00007f36e9fbae40+0x00000000000000a4]
j  sun.util.locale.provider.TimeZoneNameUtility.retrieveDisplayNamesImpl(Ljava/lang/String;Ljava/util/Locale;)[Ljava/lang/String;+140 java.base@17-ea
J 997 c1 sun.util.locale.provider.TimeZoneNameUtility.retrieveDisplayName(Ljava/lang/String;ZILjava/util/Locale;)Ljava/lang/String; java.base@17-ea (32 bytes) @ 0x00007f36e9fae4fc [0x00007f36e9fae4a0+0x000000000000005c]
J 990 c1 java.util.TimeZone.getDisplayName(ZILjava/util/Locale;)Ljava/lang/String; java.base@17-ea (129 bytes) @ 0x00007f36e9fab004 [0x00007f36e9faae40+0x00000000000001c4]
j  java.util.Date.toString()Ljava/lang/String;+150 java.base@17-ea
j  sun.usagetracker.UsageTrackerClient$UsageTrackerRunnable.buildMessage(Ljava/lang/String;Ljava/lang/String;)Ljava/lang/String;+55 java.base@17-ea
J 713 c1 sun.usagetracker.UsageTrackerClient$UsageTrackerRunnable.run()V java.base@17-ea (131 bytes) @ 0x00007f36e9ecaec4 [0x00007f36e9eca7e0+0x00000000000006e4]
J 712 c1 java.lang.Thread.run()V java.base@17-ea (17 bytes) @ 0x00007f36e9eca17c [0x00007f36e9eca0e0+0x000000000000009c]
v  ~StubRoutines::call_stub
V  [libjvm.so+0xe4f405]  JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, Thread*)+0x595
V  [libjvm.so+0xe4fc85]  JavaCalls::call_virtual(JavaValue*, Klass*, Symbol*, Symbol*, JavaCallArguments*, Thread*)+0x4c5
V  [libjvm.so+0xe5013c]  JavaCalls::call_virtual(JavaValue*, Handle, Klass*, Symbol*, Symbol*, Thread*)+0xac
V  [libjvm.so+0xfbfb9b]  thread_entry(JavaThread*, Thread*)+0x12b
V  [libjvm.so+0x1844616]  JavaThread::thread_main_inner()+0x256
V  [libjvm.so+0x184a980]  Thread::call_run()+0x100
V  [libjvm.so+0x1536b36]  thread_native_entry(Thread*)+0x116

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
v  ~DeoptimizationBlob
j  sun.util.cldr.CLDRLocaleProviderAdapter.getTimeZoneNameProvider()Ljava/util/spi/TimeZoneNameProvider;+8 java.base@17-ea
j  sun.util.locale.provider.JRELocaleProviderAdapter.getLocaleServiceProvider(Ljava/lang/Class;)Ljava/util/spi/LocaleServiceProvider;+417 java.base@17-ea
j  sun.util.locale.provider.LocaleServiceProviderPool.findProviders(Ljava/util/Locale;Z)Ljava/util/List;+68 java.base@17-ea
j  sun.util.locale.provider.LocaleServiceProviderPool.getLocalizedObjectImpl(Lsun/util/locale/provider/LocaleServiceProviderPool$LocalizedObjectGetter;Ljava/util/Locale;ZLjava/lang/String;[Ljava/lang/Object;)Ljava/lang/Object;+53 java.base@17-ea
J 1018 c1 sun.util.locale.provider.LocaleServiceProviderPool.getLocalizedObject(Lsun/util/locale/provider/LocaleServiceProviderPool$LocalizedObjectGetter;Ljava/util/Locale;Ljava/lang/String;[Ljava/lang/Object;)Ljava/lang/Object; java.base@17-ea (11 bytes) @ 0x00007f36e9fbaee4 [0x00007f36e9fbae40+0x00000000000000a4]
j  sun.util.locale.provider.TimeZoneNameUtility.retrieveDisplayNamesImpl(Ljava/lang/String;Ljava/util/Locale;)[Ljava/lang/String;+140 java.base@17-ea
J 997 c1 sun.util.locale.provider.TimeZoneNameUtility.retrieveDisplayName(Ljava/lang/String;ZILjava/util/Locale;)Ljava/lang/String; java.base@17-ea (32 bytes) @ 0x00007f36e9fae4fc [0x00007f36e9fae4a0+0x000000000000005c]
J 990 c1 java.util.TimeZone.getDisplayName(ZILjava/util/Locale;)Ljava/lang/String; java.base@17-ea (129 bytes) @ 0x00007f36e9fab004 [0x00007f36e9faae40+0x00000000000001c4]
j  java.util.Date.toString()Ljava/lang/String;+150 java.base@17-ea
j  sun.usagetracker.UsageTrackerClient$UsageTrackerRunnable.buildMessage(Ljava/lang/String;Ljava/lang/String;)Ljava/lang/String;+55 java.base@17-ea
J 713 c1 sun.usagetracker.UsageTrackerClient$UsageTrackerRunnable.run()V java.base@17-ea (131 bytes) @ 0x00007f36e9ecaec4 [0x00007f36e9eca7e0+0x00000000000006e4]
J 712 c1 java.lang.Thread.run()V java.base@17-ea (17 bytes) @ 0x00007f36e9eca17c [0x00007f36e9eca0e0+0x000000000000009c]
v  ~StubRoutines::call_stub

Comments

A pull request was submitted for review. URL: https://git.openjdk.org/jdk13u-dev/pull/370 Date: 2022-07-15 15:11:07 +0000
15-07-2022
Fix request (15u, 13u): clean backport for parity with major releases. With debug builds, hotspot/jtreg/runtime all pass. Requiring a follow-up for the test in the release build.
15-07-2022
A pull request was submitted for review. URL: https://git.openjdk.org/jdk15u-dev/pull/233 Date: 2022-07-15 14:31:28 +0000
15-07-2022
Fix request [11u] I backport this for parity with 11.0.15-oracle. A fix we should have, too. I had to do a trivial resolve. Test passes. SAP nightly testing passed.
17-01-2022
A pull request was submitted for review. URL: https://git.openjdk.java.net/jdk11u-dev/pull/763 Date: 2022-01-14 12:49:52 +0000
14-01-2022
Fix request [17u] I backport this for parity with 17.0.3-oracle. Risk: a C2 change we should take. Clean backport. Test passes. SAP nightly tests passed.
11-01-2022
A pull request was submitted for review. URL: https://git.openjdk.java.net/jdk17u-dev/pull/73 Date: 2022-01-10 14:00:21 +0000
10-01-2022
Changeset: 32139c1a Author: Dean Long <dlong@openjdk.org> Date: 2021-12-14 03:16:17 +0000 URL: https://git.openjdk.java.net/jdk18/commit/32139c1a8aae51c0869f41be57580ff4463913d2
14-12-2021
I can reproduce this in gdb. In a C1-compiled method that performs an invokedynamic, I force SystemDictionary::invoke_bootstrap_method to throw an InternalError, then force the caller frame to be deoptimized when returning from the C1 load_appendix_patching patching stub. I don't see how the getTimeZoneNameProvider frame got deoptimized in the reported failure, however.
09-07-2021
exec_mode = 1 means Unpack_exception sun.util.cldr.CLDRLocaleProviderAdapter.getTimeZoneNameProvider()Ljava/util/spi/TimeZoneNameProvider; at bci 8 is an invokedynamic. This could be a flaw in the -XX:+VerifyStack logic. Or maybe we don't handle correctly an exception and deopt when resolving the invokedynamic and calling the BSM.
08-07-2021
ILW = Assert during deoptimization, intermittent with single test, no workaround but disable compilation of affected method = HLM = P3
23-02-2021