With a modified version of the test from JDK-8324171 / JDK-8258553, C2 spends an excessive amount of time just during parsing:
java -XX:CompileCommand=quiet -XX:CompileCommand=compileonly,TestBigObj::test -XX:-TieredCompilation -XX:+PrintCompilation -XX:+PrintInlining -Xbatch -XX:+CITime TestBigObj.java
C2 Compile Time: 47,055 s
Parse: 47,045 s
Optimize: 0,002 s
We seem to spend most time in:
#0 0x00007ffff653badd in UNSIGNED5::read_uint<unsigned char const*, int, UNSIGNED5::ArrayGetSet<unsigned char const*, int> > (array=<optimized out>, offset_rw=@0x7fffe058c2b4: 434923, limit=<optimized out>, get=...)
at /oracle/jdk3/open/src/hotspot/share/utilities/unsigned5.hpp:130
#1 0x00007ffff6542603 in UNSIGNED5::Reader<unsigned char const*, int, UNSIGNED5::ArrayGetSet<unsigned char const*, int> >::next_uint (this=0x7fffe058c2a8) at /oracle/jdk3/open/src/hotspot/share/utilities/unsigned5.hpp:270
#2 FieldInfoReader::next_uint (this=0x7fffe058c2a8) at /oracle/jdk3/open/src/hotspot/share/oops/fieldInfo.hpp:238
#3 FieldInfoReader::read_field_info (this=0x7fffe058c2a8, fi=...) at /oracle/jdk3/open/src/hotspot/share/oops/fieldInfo.inline.hpp:104
#4 0x00007ffff6aa833f in FieldStreamBase::next (this=0x7fffe058c2a0) at /oracle/jdk3/open/src/hotspot/share/oops/fieldStreams.hpp:80
#5 InstanceKlass::field (this=this@entry=0x7f208000, index=index@entry=58120) at /oracle/jdk3/open/src/hotspot/share/oops/instanceKlass.cpp:1659
#6 0x00007ffff684a77c in fieldDescriptor::reinitialize (this=this@entry=0x7fffe058c488, ik=0x7f208000, index=58120) at /oracle/jdk3/open/src/hotspot/share/runtime/fieldDescriptor.cpp:98
#7 0x00007ffff6540e2c in FieldStreamBase::field_descriptor (this=0x7fffe058c430) at /oracle/jdk3/open/src/hotspot/share/oops/constantPool.hpp:219
#8 ciInstanceKlass::compute_nonstatic_fields_impl (this=this@entry=0x7ffff11d0258, super_fields=super_fields@entry=0x0) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:532
#9 0x00007ffff65416f1 in ciInstanceKlass::compute_nonstatic_fields (this=<optimized out>) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:482
#10 ciInstanceKlass::compute_nonstatic_fields (this=0x7ffff11d0258) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:460
#11 0x00007ffff65417b5 in ciInstanceKlass::nof_nonstatic_fields (this=0x7ffff11d0258) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.hpp:214
#12 ciInstanceKlass::compute_nonstatic_fields (this=<optimized out>) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:476
#13 ciInstanceKlass::compute_nonstatic_fields (this=this@entry=0x7ffff11cc100) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:460
#14 0x00007ffff6a08f8c in ciInstanceKlass::nof_nonstatic_fields (this=<optimized out>) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.hpp:214
#15 GraphKit::set_output_for_allocation (this=this@entry=0x7fffe058c960, alloc=0x7ffff11ac4b0, oop_type=0x7ffff11c5cc8, oop_type@entry=0x7ffff11cc100, deoptimize_on_exception=deoptimize_on_exception@entry=255)
at /oracle/jdk3/open/src/hotspot/share/opto/graphKit.cpp:3656
#16 0x00007ffff6a09635 in GraphKit::new_instance (this=this@entry=0x7fffe058c960, klass_node=<optimized out>, extra_slow_test=<optimized out>, extra_slow_test@entry=0x0, return_size_val=return_size_val@entry=0x0,
deoptimize_on_exception=255, deoptimize_on_exception@entry=false) at /oracle/jdk3/open/src/hotspot/share/opto/graphKit.cpp:3772
#17 0x00007ffff7188dc4 in Parse::do_new (this=this@entry=0x7fffe058c960) at /oracle/jdk3/open/src/hotspot/share/opto/parseHelper.cpp:266
#18 0x00007ffff717fa48 in Parse::do_one_bytecode (this=this@entry=0x7fffe058c960) at /oracle/jdk3/open/src/hotspot/share/opto/parse2.cpp:2745
#19 0x00007ffff716ad0a in Parse::do_one_block (this=0x7fffe058c960) at /oracle/jdk3/open/src/hotspot/share/opto/parse1.cpp:1592
#20 0x00007ffff716c1c5 in Parse::do_all_blocks (this=this@entry=0x7fffe058c960) at /oracle/jdk3/open/src/hotspot/share/opto/parse1.cpp:712
#21 0x00007ffff71704a5 in Parse::Parse (this=this@entry=0x7fffe058c960, caller=caller@entry=0x7ffff11b7420, parse_method=<optimized out>, expected_uses=<optimized out>) at /oracle/jdk3/open/src/hotspot/share/opto/parse1.cpp:616
#22 0x00007ffff64b3659 in ParseGenerator::generate (this=0x7ffff11b7408, jvms=0x7ffff11b7420) at /oracle/jdk3/open/src/hotspot/share/opto/callGenerator.hpp:53
#23 0x00007ffff665bfce in Compile::Compile (this=this@entry=0x7fffe058d840, ci_env=ci_env@entry=0x7fffe058e6f0, target=target@entry=0x7ffff11cc1b0, osr_bci=osr_bci@entry=-1, options=..., options@entry=...,
directive=directive@entry=0x7ffff01cf1f0) at /oracle/jdk3/open/src/hotspot/share/opto/compile.cpp:791
#24 0x00007ffff64b13c5 in C2Compiler::compile_method (this=<optimized out>, env=0x7fffe058e6f0, target=0x7ffff11cc1b0, entry_bci=-1, install_code=<optimized out>, directive=0x7ffff01cf1f0)
With -XX:EliminateAllocationFieldsLimit=100000 we also hit the node limit:
# A fatal error has been detected by the Java Runtime Environment:
#
# Internal Error (/opt/mach5/mesos/work_dir/slaves/0db9c48f-6638-40d0-9a4b-bd9cc7533eb8-S10108/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/64ecc42e-c311-4cbc-9f8c-cdb54670fe43/runs/6ce1ca2a-f2b6-4d79-a919-946bcfa599e7/workspace/open/src/hotspot/share/opto/node.cpp:78), pid=3632360, tid=3632375
# assert(C->live_nodes() <= C->max_node_limit()) failed: Live Node limit exceeded limit
#
# JRE version: Java(TM) SE Runtime Environment (23.0+4) (fastdebug build 23-ea+4-173)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 23-ea+4-173, mixed mode, sharing, compressed oops, compressed class ptrs, g1 gc, linux-amd64)
# Problematic frame:
# V [libjvm.so+0x1434bb7] Node::verify_construction()+0x1a7
#
# No core dump will be written. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
Current CompileTask:
C2:141893 82 b TestBigObj::test (49 bytes)
Stack: [0x00007f1847335000,0x00007f1847436000], sp=0x00007f1847430eb0, free space=1007k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V [libjvm.so+0x1434bb7] Node::verify_construction()+0x1a7 (node.cpp:78)
V [libjvm.so+0x1435923] Node::Node(unsigned int)+0x43
V [libjvm.so+0x12da52a] PhaseMacroExpand::value_from_mem_phi(Node*, BasicType, Type const*, TypeOopPtr const*, AllocateNode*, Node_Stack*, int)+0x45a
V [libjvm.so+0x12dbd0e] PhaseMacroExpand::value_from_mem(Node*, Node*, BasicType, Type const*, TypeOopPtr const*, AllocateNode*)+0x86e
V [libjvm.so+0x12dcb64] PhaseMacroExpand::create_scalarized_object_description(AllocateNode*, SafePointNode*)+0x224
V [libjvm.so+0x12de56a] PhaseMacroExpand::scalar_replacement(AllocateNode*, GrowableArray<SafePointNode*>&)+0xfa
V [libjvm.so+0x12deb5e] PhaseMacroExpand::eliminate_allocate_node(AllocateNode*)+0x1ce
V [libjvm.so+0x12df2f2] PhaseMacroExpand::eliminate_macro_nodes()+0x3b2
V [libjvm.so+0x9ed2ae] Compile::Optimize()+0x135e
V [libjvm.so+0x9f050b] Compile::Compile(ciEnv*, ciMethod*, int, Options, DirectiveSet*)+0x1beb
V [libjvm.so+0x83dc57] C2Compiler::compile_method(ciEnv*, ciMethod*, int, bool, DirectiveSet*)+0x1e7
V [libjvm.so+0x9fbacc] CompileBroker::invoke_compiler_on_method(CompileTask*)+0x92c
V [libjvm.so+0x9fc758] CompileBroker::compiler_thread_loop()+0x468
V [libjvm.so+0xeb99ec] JavaThread::thread_main_inner()+0xcc
V [libjvm.so+0x179ea66] Thread::call_run()+0xb6
V [libjvm.so+0x14a92e7] thread_native_entry(Thread*)+0x127
It's probably expected and not easy to avoid, but we should double-check.
java -XX:CompileCommand=quiet -XX:CompileCommand=compileonly,TestBigObj::test -XX:-TieredCompilation -XX:+PrintCompilation -XX:+PrintInlining -Xbatch -XX:+CITime TestBigObj.java
C2 Compile Time: 47,055 s
Parse: 47,045 s
Optimize: 0,002 s
We seem to spend most time in:
#0 0x00007ffff653badd in UNSIGNED5::read_uint<unsigned char const*, int, UNSIGNED5::ArrayGetSet<unsigned char const*, int> > (array=<optimized out>, offset_rw=@0x7fffe058c2b4: 434923, limit=<optimized out>, get=...)
at /oracle/jdk3/open/src/hotspot/share/utilities/unsigned5.hpp:130
#1 0x00007ffff6542603 in UNSIGNED5::Reader<unsigned char const*, int, UNSIGNED5::ArrayGetSet<unsigned char const*, int> >::next_uint (this=0x7fffe058c2a8) at /oracle/jdk3/open/src/hotspot/share/utilities/unsigned5.hpp:270
#2 FieldInfoReader::next_uint (this=0x7fffe058c2a8) at /oracle/jdk3/open/src/hotspot/share/oops/fieldInfo.hpp:238
#3 FieldInfoReader::read_field_info (this=0x7fffe058c2a8, fi=...) at /oracle/jdk3/open/src/hotspot/share/oops/fieldInfo.inline.hpp:104
#4 0x00007ffff6aa833f in FieldStreamBase::next (this=0x7fffe058c2a0) at /oracle/jdk3/open/src/hotspot/share/oops/fieldStreams.hpp:80
#5 InstanceKlass::field (this=this@entry=0x7f208000, index=index@entry=58120) at /oracle/jdk3/open/src/hotspot/share/oops/instanceKlass.cpp:1659
#6 0x00007ffff684a77c in fieldDescriptor::reinitialize (this=this@entry=0x7fffe058c488, ik=0x7f208000, index=58120) at /oracle/jdk3/open/src/hotspot/share/runtime/fieldDescriptor.cpp:98
#7 0x00007ffff6540e2c in FieldStreamBase::field_descriptor (this=0x7fffe058c430) at /oracle/jdk3/open/src/hotspot/share/oops/constantPool.hpp:219
#8 ciInstanceKlass::compute_nonstatic_fields_impl (this=this@entry=0x7ffff11d0258, super_fields=super_fields@entry=0x0) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:532
#9 0x00007ffff65416f1 in ciInstanceKlass::compute_nonstatic_fields (this=<optimized out>) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:482
#10 ciInstanceKlass::compute_nonstatic_fields (this=0x7ffff11d0258) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:460
#11 0x00007ffff65417b5 in ciInstanceKlass::nof_nonstatic_fields (this=0x7ffff11d0258) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.hpp:214
#12 ciInstanceKlass::compute_nonstatic_fields (this=<optimized out>) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:476
#13 ciInstanceKlass::compute_nonstatic_fields (this=this@entry=0x7ffff11cc100) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.cpp:460
#14 0x00007ffff6a08f8c in ciInstanceKlass::nof_nonstatic_fields (this=<optimized out>) at /oracle/jdk3/open/src/hotspot/share/ci/ciInstanceKlass.hpp:214
#15 GraphKit::set_output_for_allocation (this=this@entry=0x7fffe058c960, alloc=0x7ffff11ac4b0, oop_type=0x7ffff11c5cc8, oop_type@entry=0x7ffff11cc100, deoptimize_on_exception=deoptimize_on_exception@entry=255)
at /oracle/jdk3/open/src/hotspot/share/opto/graphKit.cpp:3656
#16 0x00007ffff6a09635 in GraphKit::new_instance (this=this@entry=0x7fffe058c960, klass_node=<optimized out>, extra_slow_test=<optimized out>, extra_slow_test@entry=0x0, return_size_val=return_size_val@entry=0x0,
deoptimize_on_exception=255, deoptimize_on_exception@entry=false) at /oracle/jdk3/open/src/hotspot/share/opto/graphKit.cpp:3772
#17 0x00007ffff7188dc4 in Parse::do_new (this=this@entry=0x7fffe058c960) at /oracle/jdk3/open/src/hotspot/share/opto/parseHelper.cpp:266
#18 0x00007ffff717fa48 in Parse::do_one_bytecode (this=this@entry=0x7fffe058c960) at /oracle/jdk3/open/src/hotspot/share/opto/parse2.cpp:2745
#19 0x00007ffff716ad0a in Parse::do_one_block (this=0x7fffe058c960) at /oracle/jdk3/open/src/hotspot/share/opto/parse1.cpp:1592
#20 0x00007ffff716c1c5 in Parse::do_all_blocks (this=this@entry=0x7fffe058c960) at /oracle/jdk3/open/src/hotspot/share/opto/parse1.cpp:712
#21 0x00007ffff71704a5 in Parse::Parse (this=this@entry=0x7fffe058c960, caller=caller@entry=0x7ffff11b7420, parse_method=<optimized out>, expected_uses=<optimized out>) at /oracle/jdk3/open/src/hotspot/share/opto/parse1.cpp:616
#22 0x00007ffff64b3659 in ParseGenerator::generate (this=0x7ffff11b7408, jvms=0x7ffff11b7420) at /oracle/jdk3/open/src/hotspot/share/opto/callGenerator.hpp:53
#23 0x00007ffff665bfce in Compile::Compile (this=this@entry=0x7fffe058d840, ci_env=ci_env@entry=0x7fffe058e6f0, target=target@entry=0x7ffff11cc1b0, osr_bci=osr_bci@entry=-1, options=..., options@entry=...,
directive=directive@entry=0x7ffff01cf1f0) at /oracle/jdk3/open/src/hotspot/share/opto/compile.cpp:791
#24 0x00007ffff64b13c5 in C2Compiler::compile_method (this=<optimized out>, env=0x7fffe058e6f0, target=0x7ffff11cc1b0, entry_bci=-1, install_code=<optimized out>, directive=0x7ffff01cf1f0)
With -XX:EliminateAllocationFieldsLimit=100000 we also hit the node limit:
# A fatal error has been detected by the Java Runtime Environment:
#
# Internal Error (/opt/mach5/mesos/work_dir/slaves/0db9c48f-6638-40d0-9a4b-bd9cc7533eb8-S10108/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/64ecc42e-c311-4cbc-9f8c-cdb54670fe43/runs/6ce1ca2a-f2b6-4d79-a919-946bcfa599e7/workspace/open/src/hotspot/share/opto/node.cpp:78), pid=3632360, tid=3632375
# assert(C->live_nodes() <= C->max_node_limit()) failed: Live Node limit exceeded limit
#
# JRE version: Java(TM) SE Runtime Environment (23.0+4) (fastdebug build 23-ea+4-173)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 23-ea+4-173, mixed mode, sharing, compressed oops, compressed class ptrs, g1 gc, linux-amd64)
# Problematic frame:
# V [libjvm.so+0x1434bb7] Node::verify_construction()+0x1a7
#
# No core dump will be written. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
Current CompileTask:
C2:141893 82 b TestBigObj::test (49 bytes)
Stack: [0x00007f1847335000,0x00007f1847436000], sp=0x00007f1847430eb0, free space=1007k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V [libjvm.so+0x1434bb7] Node::verify_construction()+0x1a7 (node.cpp:78)
V [libjvm.so+0x1435923] Node::Node(unsigned int)+0x43
V [libjvm.so+0x12da52a] PhaseMacroExpand::value_from_mem_phi(Node*, BasicType, Type const*, TypeOopPtr const*, AllocateNode*, Node_Stack*, int)+0x45a
V [libjvm.so+0x12dbd0e] PhaseMacroExpand::value_from_mem(Node*, Node*, BasicType, Type const*, TypeOopPtr const*, AllocateNode*)+0x86e
V [libjvm.so+0x12dcb64] PhaseMacroExpand::create_scalarized_object_description(AllocateNode*, SafePointNode*)+0x224
V [libjvm.so+0x12de56a] PhaseMacroExpand::scalar_replacement(AllocateNode*, GrowableArray<SafePointNode*>&)+0xfa
V [libjvm.so+0x12deb5e] PhaseMacroExpand::eliminate_allocate_node(AllocateNode*)+0x1ce
V [libjvm.so+0x12df2f2] PhaseMacroExpand::eliminate_macro_nodes()+0x3b2
V [libjvm.so+0x9ed2ae] Compile::Optimize()+0x135e
V [libjvm.so+0x9f050b] Compile::Compile(ciEnv*, ciMethod*, int, Options, DirectiveSet*)+0x1beb
V [libjvm.so+0x83dc57] C2Compiler::compile_method(ciEnv*, ciMethod*, int, bool, DirectiveSet*)+0x1e7
V [libjvm.so+0x9fbacc] CompileBroker::invoke_compiler_on_method(CompileTask*)+0x92c
V [libjvm.so+0x9fc758] CompileBroker::compiler_thread_loop()+0x468
V [libjvm.so+0xeb99ec] JavaThread::thread_main_inner()+0xcc
V [libjvm.so+0x179ea66] Thread::call_run()+0xb6
V [libjvm.so+0x14a92e7] thread_native_entry(Thread*)+0x127
It's probably expected and not easy to avoid, but we should double-check.
- relates to
-
JDK-8307788 vmTestbase/gc/gctests/LargeObjects/large003/TestDescription.java timed out
-
- Resolved
-
-
JDK-8308094 Add a compilation timeout flag to catch long running compilations
-
- Open
-
-
JDK-8324171 assert failed: Live Node limit exceeded limit
-
- Closed
-
-
JDK-8258553 Limit number of fields in instance to be considered for scalar replacement
-
- Resolved
-