JDK-7115356 : assert(!m->was_never_executed()) failed
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: hs23,hs24,hs25
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • OS: generic
  • CPU: generic
  • Submitted: 2011-11-24
  • Updated: 2023-07-21
  • Resolved: 2023-07-21
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 9
9Resolved
Related Reports
Blocks :  
JDK-8058564 - Tiered compilation performance drop in PIT
Duplicate :  
JDK-8058564 - Tiered compilation performance drop in PIT
Relates :  
JDK-8206938 - Compilation policy fails with assert(!m->was_never_executed()) failed: don't reset to 0 -- could be mistaken for never-executed
Relates :  
JDK-6805748 - Assertion "don't reset to 0 -- could be mistaken for never-executed" in CompilationPolicy
Description
VM crashes with:
;; Using jvm: "C:/local/common/jdk/baseline/windows-amd64/jre/bin/server/jvm.dll"

Warning: This error log is *not* generated by the following JVM:
           C:/local/common/jdk/baseline/windows-amd64/jre/bin/server/jvm.dll
         
         Expected vm_info: [Java HotSpot(TM) 64-Bit Server VM (23.0-b06-internal-201111211042.brutisso.hs-rt-rickard-prec-fastdebug) for windows-amd64 JRE (1.8.0), built on Nov 21 2011 02:48:22 by "jprtadm" with unknown MS VC++:1600]
         Actual vm_info:   []
         
         JVM symbol lookup may be incorrect.
         Please use --jvm=<path/to/jvm> to point to the correct JVM.
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (C:\temp\jprt\P1\104215.brutisso\source\src\share\vm\runtime\compilationPolicy.cpp:200), pid=81736, tid=166288
#  assert(!m->was_never_executed()) failed: don't reset to 0 -- could be mistaken for never-executed
#
# JRE version: 7.0-b148
# Java VM: Java HotSpot(TM) 64-Bit Server VM (23.0-b06-internal-201111211042.brutisso.hs-rt-rickard-prec-fastdebug mixed mode windows-amd64 compressed oops)
# Failed to write core dump. Minidumps are not enabled by default on client versions of Windows
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.sun.com/bugreport/crash.jsp
#
Comments
Come to think of it, the assert is so uncommon that it will take months before we know if JDK-8058564 solves it.
23-09-2014
This bug might be caused by the race when creating counters. Wait to fix the refactorization before we have seen the effect of the other fix.
23-09-2014
Also these tests could fail with same reason: gc/lock/jni/jnilock001 gc/lock/jni/jnilock002 gc/lock/jni/jnilock003 gc/lock/jniref/jniglobalreflock01 gc/lock/jniref/jniglobalreflock02 gc/lock/jniref/jniglobalreflock03 gc/lock/jniref/jniglobalreflock04 gc/lock/jniref/jnilocalreflock01 gc/lock/jniref/jnilocalreflock02 gc/lock/jniref/jnilocalreflock03 gc/lock/jniref/jnilocalreflock04 gc/lock/jniref/jnireflock01 gc/lock/jniref/jnireflock02 gc/lock/jniref/jnireflock03 gc/lock/jniref/jnireflock04 gc/lock/jniref/jniweakglobalreflock01 gc/lock/jniref/jniweakglobalreflock02 gc/lock/jniref/jniweakglobalreflock03 gc/lock/jniref/jniweakglobalreflock04 gc/lock/jvmti/alloc/jvmtialloclock01 gc/lock/jvmti/alloc/jvmtialloclock02 gc/lock/jvmti/alloc/jvmtialloclock03 gc/lock/jvmti/alloc/jvmtialloclock04 gc/lock/malloc/malloclock01 gc/lock/malloc/malloclock02 gc/lock/malloc/malloclock03 gc/lock/malloc/malloclock04
12-08-2013
I verified the assembler code in Method::was_executed_more_than() and it looks correct.
30-07-2013
An other weird thing, was_executed_more_than() should return 'true' because (code() != NULL): +0x050 _code : 0x00000000`031c7d90 nmethod
27-07-2013
Rickard, I mistook method_data() for method_counters(). Yes, carry() is false for method_data)
27-07-2013
Vladimir, I meant that method_data()->invocation_counter()->carry() is false. jvm!NonTieredCompPolicy::reset_counter_for_invocation_event [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 204]: 204 00000000`6f87dbf0 48895c2408 mov qword ptr [rsp+8],rbx 204 00000000`6f87dbf5 57 push rdi 204 00000000`6f87dbf6 4883ec20 sub rsp,20h 210 00000000`6f87dbfa 48833a00 cmp qword ptr [rdx],0 210 00000000`6f87dbfe 488bda mov rbx,rdx 210 00000000`6f87dc01 7524 jne jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0x37 (00000000`6f87dc27) jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0x13 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 210]: 210 00000000`6f87dc03 4c8d0db6ea5e00 lea r9,[jvm!`string' (00000000`6fe6c6c0)] 210 00000000`6f87dc0a 4c8d058fea5e00 lea r8,[jvm!`string' (00000000`6fe6c6a0)] 210 00000000`6f87dc11 488d0d40c75e00 lea rcx,[jvm!`string' (00000000`6fe6a358)] 210 00000000`6f87dc18 baac000000 mov edx,0ACh 210 00000000`6f87dc1d e8fe190a00 call jvm!report_vm_error (00000000`6f91f620) 210 00000000`6f87dc22 e879d50c00 call jvm!os::breakpoint (00000000`6f94b1a0) jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0x37 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 210]: 210 00000000`6f87dc27 488b03 mov rax,qword ptr [rbx] 210 00000000`6f87dc2a 488b7820 mov rdi,qword ptr [rax+20h] 211 00000000`6f87dc2e 4885ff test rdi,rdi 211 00000000`6f87dc31 7524 jne jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0x67 (00000000`6f87dc57) jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0x43 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 211]: 211 00000000`6f87dc33 4c8d0dde526700 lea r9,[jvm!`string' (00000000`6fef2f18)] 211 00000000`6f87dc3a 4c8d0567506200 lea r8,[jvm!`string' (00000000`6fea2ca8)] 211 00000000`6f87dc41 488d0df84f6700 lea rcx,[jvm!`string' (00000000`6fef2c40)] 211 00000000`6f87dc48 bad3000000 mov edx,0D3h 211 00000000`6f87dc4d e8ce190a00 call jvm!report_vm_error (00000000`6f91f620) 211 00000000`6f87dc52 e849d50c00 call jvm!os::breakpoint (00000000`6f94b1a0) jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0x67 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 212]: 212 00000000`6f87dc57 488d4f08 lea rcx,[rdi+8] 212 00000000`6f87dc5b e85008e5ff call jvm!InvocationCounter::set_carry (00000000`6f6ce4b0) 213 00000000`6f87dc60 488d4f0c lea rcx,[rdi+0Ch] 213 00000000`6f87dc64 e84708e5ff call jvm!InvocationCounter::set_carry (00000000`6f6ce4b0) 215 00000000`6f87dc69 48833b00 cmp qword ptr [rbx],0 215 00000000`6f87dc6d 7524 jne jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0xa3 (00000000`6f87dc93) jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0x7f [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 215]: 215 00000000`6f87dc6f 4c8d0d4aea5e00 lea r9,[jvm!`string' (00000000`6fe6c6c0)] 215 00000000`6f87dc76 4c8d0523ea5e00 lea r8,[jvm!`string' (00000000`6fe6c6a0)] 215 00000000`6f87dc7d 488d0dd4c65e00 lea rcx,[jvm!`string' (00000000`6fe6a358)] 215 00000000`6f87dc84 baac000000 mov edx,0ACh 215 00000000`6f87dc89 e892190a00 call jvm!report_vm_error (00000000`6f91f620) 215 00000000`6f87dc8e e80dd50c00 call jvm!os::breakpoint (00000000`6f94b1a0) jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0xa3 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 215]: 215 00000000`6f87dc93 488b0b mov rcx,qword ptr [rbx] 215 00000000`6f87dc96 33d2 xor edx,edx 215 00000000`6f87dc98 e8b3f8efff call jvm!Method::was_executed_more_than (00000000`6f77d550) 215 00000000`6f87dc9d 84c0 test al,al 215 00000000`6f87dc9f 7524 jne jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0xd5 (00000000`6f87dcc5) jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0xb1 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 215]: 215 00000000`6f87dca1 4c8d0d30526700 lea r9,[jvm!`string' (00000000`6fef2ed8)] 215 00000000`6f87dca8 4c8d0501526700 lea r8,[jvm!`string' (00000000`6fef2eb0)] 215 00000000`6f87dcaf 488d0d8a4f6700 lea rcx,[jvm!`string' (00000000`6fef2c40)] 215 00000000`6f87dcb6 bad7000000 mov edx,0D7h 215 00000000`6f87dcbb e860190a00 call jvm!report_vm_error (00000000`6f91f620) 215 00000000`6f87dcc0 e8dbd40c00 call jvm!os::breakpoint (00000000`6f94b1a0) jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0xd5 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 216]: 216 00000000`6f87dcc5 488bcb mov rcx,rbx 216 00000000`6f87dcc8 488b5c2430 mov rbx,qword ptr [rsp+30h] 216 00000000`6f87dccd 4883c420 add rsp,20h 216 00000000`6f87dcd1 5f pop rdi 216 00000000`6f87dcd2 e9896dd6ff jmp jvm!methodHandle::remove (00000000`6f5e4a60) and jvm!Method::was_executed_more_than [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 309]: 309 00000000`6f77d550 48895c2408 mov qword ptr [rsp+8],rbx 309 00000000`6f77d555 57 push rdi 309 00000000`6f77d556 4883ec20 sub rsp,20h 309 00000000`6f77d55a 8bfa mov edi,edx 309 00000000`6f77d55c 488bd9 mov rbx,rcx 313 00000000`6f77d55f e8acedffff call jvm!Method::is_accessor (00000000`6f77c310) 313 00000000`6f77d564 84c0 test al,al 313 00000000`6f77d566 0f8507010000 jne jvm!Method::was_executed_more_than+0x123 (00000000`6f77d673) jvm!Method::was_executed_more_than+0x1c [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 313]: 313 00000000`6f77d56c 488b4310 mov rax,qword ptr [rbx+10h] 313 00000000`6f77d570 6683781e01 cmp word ptr [rax+1Eh],1 313 00000000`6f77d575 750a jne jvm!Method::was_executed_more_than+0x31 (00000000`6f77d581) jvm!Method::was_executed_more_than+0x27 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 313]: 313 00000000`6f77d577 807830b1 cmp byte ptr [rax+30h],0B1h 313 00000000`6f77d57b 0f84f2000000 je jvm!Method::was_executed_more_than+0x123 (00000000`6f77d673) jvm!Method::was_executed_more_than+0x31 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 313]: 313 00000000`6f77d581 488bcb mov rcx,rbx 313 00000000`6f77d584 e8571ee7ff call jvm!Method::code (00000000`6f5ef3e0) 313 00000000`6f77d589 4885c0 test rax,rax 313 00000000`6f77d58c 0f85e1000000 jne jvm!Method::was_executed_more_than+0x123 (00000000`6f77d673) jvm!Method::was_executed_more_than+0x42 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 321]: 321 00000000`6f77d592 488b4b20 mov rcx,qword ptr [rbx+20h] 321 00000000`6f77d596 4885c9 test rcx,rcx 321 00000000`6f77d599 740e je jvm!Method::was_executed_more_than+0x59 (00000000`6f77d5a9) jvm!Method::was_executed_more_than+0x4b [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 321]: 321 00000000`6f77d59b 8b4108 mov eax,dword ptr [rcx+8] 321 00000000`6f77d59e c1e802 shr eax,2 321 00000000`6f77d5a1 a801 test al,1 321 00000000`6f77d5a3 0f85ca000000 jne jvm!Method::was_executed_more_than+0x123 (00000000`6f77d673) jvm!Method::was_executed_more_than+0x59 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 321]: 321 00000000`6f77d5a9 488b5318 mov rdx,qword ptr [rbx+18h] 321 00000000`6f77d5ad 4885d2 test rdx,rdx 321 00000000`6f77d5b0 740e je jvm!Method::was_executed_more_than+0x70 (00000000`6f77d5c0) jvm!Method::was_executed_more_than+0x62 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 321]: 321 00000000`6f77d5b2 8b426c mov eax,dword ptr [rdx+6Ch] 321 00000000`6f77d5b5 c1e802 shr eax,2 321 00000000`6f77d5b8 a801 test al,1 326 00000000`6f77d5ba 0f85b3000000 jne jvm!Method::was_executed_more_than+0x123 (00000000`6f77d673) jvm!Method::was_executed_more_than+0x70 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d5c0 4533c0 xor r8d,r8d 328 00000000`6f77d5c3 443805bf88aa00 cmp byte ptr [jvm!TieredCompilation (00000000`70225e89)],r8b 328 00000000`6f77d5ca 7479 je jvm!Method::was_executed_more_than+0xf5 (00000000`6f77d645) jvm!Method::was_executed_more_than+0x7c [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d5cc 4885c9 test rcx,rcx 328 00000000`6f77d5cf 740a je jvm!Method::was_executed_more_than+0x8b (00000000`6f77d5db) jvm!Method::was_executed_more_than+0x81 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d5d1 8b4108 mov eax,dword ptr [rcx+8] 328 00000000`6f77d5d4 c1e802 shr eax,2 328 00000000`6f77d5d7 2401 and al,1 328 00000000`6f77d5d9 750f jne jvm!Method::was_executed_more_than+0x9a (00000000`6f77d5ea) jvm!Method::was_executed_more_than+0x8b [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d5db 4885d2 test rdx,rdx 328 00000000`6f77d5de 741f je jvm!Method::was_executed_more_than+0xaf (00000000`6f77d5ff) jvm!Method::was_executed_more_than+0x90 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d5e0 8b426c mov eax,dword ptr [rdx+6Ch] 328 00000000`6f77d5e3 c1e802 shr eax,2 328 00000000`6f77d5e6 2401 and al,1 328 00000000`6f77d5e8 7415 je jvm!Method::was_executed_more_than+0xaf (00000000`6f77d5ff) jvm!Method::was_executed_more_than+0x9a [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d5ea b800000010 mov eax,10000000h 328 00000000`6f77d5ef 3bc7 cmp eax,edi 328 00000000`6f77d5f1 0f9fc0 setg al 330 00000000`6f77d5f4 488b5c2430 mov rbx,qword ptr [rsp+30h] 330 00000000`6f77d5f9 4883c420 add rsp,20h 330 00000000`6f77d5fd 5f pop rdi 330 00000000`6f77d5fe c3 ret jvm!Method::was_executed_more_than+0xaf [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d5ff 4885c9 test rcx,rcx 328 00000000`6f77d602 740a je jvm!Method::was_executed_more_than+0xbe (00000000`6f77d60e) jvm!Method::was_executed_more_than+0xb4 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d604 448b4908 mov r9d,dword ptr [rcx+8] 328 00000000`6f77d608 41c1e903 shr r9d,3 328 00000000`6f77d60c eb03 jmp jvm!Method::was_executed_more_than+0xc1 (00000000`6f77d611) jvm!Method::was_executed_more_than+0xbe [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d60e 458bc8 mov r9d,r8d jvm!Method::was_executed_more_than+0xc1 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d611 4885d2 test rdx,rdx 328 00000000`6f77d614 7419 je jvm!Method::was_executed_more_than+0xdf (00000000`6f77d62f) jvm!Method::was_executed_more_than+0xc6 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d616 8b426c mov eax,dword ptr [rdx+6Ch] 328 00000000`6f77d619 c1e803 shr eax,3 328 00000000`6f77d61c 4103c1 add eax,r9d 328 00000000`6f77d61f 3bc7 cmp eax,edi 328 00000000`6f77d621 0f9fc0 setg al 330 00000000`6f77d624 488b5c2430 mov rbx,qword ptr [rsp+30h] 330 00000000`6f77d629 4883c420 add rsp,20h 330 00000000`6f77d62d 5f pop rdi 330 00000000`6f77d62e c3 ret jvm!Method::was_executed_more_than+0xdf [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d62f 418bc0 mov eax,r8d 328 00000000`6f77d632 4103c1 add eax,r9d 328 00000000`6f77d635 3bc7 cmp eax,edi 328 00000000`6f77d637 0f9fc0 setg al 330 00000000`6f77d63a 488b5c2430 mov rbx,qword ptr [rsp+30h] 330 00000000`6f77d63f 4883c420 add rsp,20h 330 00000000`6f77d643 5f pop rdi 330 00000000`6f77d644 c3 ret jvm!Method::was_executed_more_than+0xf5 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d645 4885c9 test rcx,rcx 328 00000000`6f77d648 7513 jne jvm!Method::was_executed_more_than+0x10d (00000000`6f77d65d) jvm!Method::was_executed_more_than+0xfa [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d64a 418bc0 mov eax,r8d 328 00000000`6f77d64d 3bc7 cmp eax,edi 328 00000000`6f77d64f 0f9fc0 setg al 330 00000000`6f77d652 488b5c2430 mov rbx,qword ptr [rsp+30h] 330 00000000`6f77d657 4883c420 add rsp,20h 330 00000000`6f77d65b 5f pop rdi 330 00000000`6f77d65c c3 ret jvm!Method::was_executed_more_than+0x10d [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 328]: 328 00000000`6f77d65d 8b4108 mov eax,dword ptr [rcx+8] 328 00000000`6f77d660 c1e803 shr eax,3 328 00000000`6f77d663 3bc7 cmp eax,edi 328 00000000`6f77d665 0f9fc0 setg al 330 00000000`6f77d668 488b5c2430 mov rbx,qword ptr [rsp+30h] 330 00000000`6f77d66d 4883c420 add rsp,20h 330 00000000`6f77d671 5f pop rdi 330 00000000`6f77d672 c3 ret jvm!Method::was_executed_more_than+0x123 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\oops\method.cpp @ 316]: 316 00000000`6f77d673 b001 mov al,1 330 00000000`6f77d675 488b5c2430 mov rbx,qword ptr [rsp+30h] 330 00000000`6f77d67a 4883c420 add rsp,20h 330 00000000`6f77d67e 5f pop rdi 330 00000000`6f77d67f c3 ret
26-07-2013
Vladimir, I agree with you that most likely it is not a race in this issue since the carry bit is not cleared when the assertion happens according to Richard's data. It probably is a compiler issue as you pointed out.
25-07-2013
Jiangli, it could be your changes for 8010862 pushed VS over cliff :) We still have concurrency problem as you pointed but I think it is very very rare (but not 0%) case since the window is very small: in our profilining code: __ movl(rcx, invocation_counter); __ incrementl(rcx, InvocationCounter::count_increment); __ movl(invocation_counter, rcx); // save invocation count and set_carry_flag() { _counter |= carry_mask; } We can try to make set_carry_flag() atomic to avoid that but logistically it is not needed. Worst case is we reset only count to CompileThreshold / 2 and we need to wait again when it reachs threshold limit.
25-07-2013
Note, when only count is reset it is still invocation_count() > 0 so the assert should not fail!
25-07-2013
It seems 'else if' in Method::was_executed_more_than(0) should return true since the MethodCounter's InvocationCounter::_counter is 0xa485. The last 3 bits is 101, and the carry bit is set. Looks like Vladmir already beat me to it. :)
25-07-2013
Thank you, Rickard. Your evaluation is not right because MethodCounters is not NULL. The method_counters()->invocation_counter() value is _counter 0xa485 so carry bit (2nd) 0x4 is set. As result the condition (method_counters() != NULL && method_counters()->invocation_counter()->carry()) is TRUE so that was_executed_more_than() should return TRUE. So it is more and more look like VS C++ problem which generates incorrect code. Rickard could you look on assembler code for was_executed_more_than() and reset_counter_for_invocation_event() methods? Thanks!
25-07-2013
I don't know why but by default windbg doesn't make any sense out of the crashing thread in the mdmp. However some digging makes me think this is the stack trace: 0:076> k = 00000`3690e980 00000000`6f91f620 9 Child-SP RetAddr Call Site 00000000`3690e980 00000000`6fef2ed8 jvm!report_vm_error [c:\jprt\t\p1\162925.ehn\s\src\share\vm\utilities\debug.cpp @ 219] 00000000`3690e988 00000000`6f91f680 jvm!`string' 00000000`3690e990 00000000`6f87dcc0 jvm!report_vm_error+0x60 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\utilities\debug.cpp @ 224] 00000000`3690ea40 00000000`6f87e7dc jvm!NonTieredCompPolicy::reset_counter_for_invocation_event+0xd0 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 215] 00000000`3690ea70 00000000`6f87e646 jvm!SimpleCompPolicy::method_invocation_event+0x6c [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 448] 00000000`3690eb00 00000000`6f6ca5fb jvm!NonTieredCompPolicy::event+0xf6 [c:\jprt\t\p1\162925.ehn\s\src\share\vm\runtime\compilationpolicy.cpp @ 374] 00000000`3690eb60 00000000`6f6ce33a jvm!InterpreterRuntime::frequency_counter_overflow_inner+0x2ab [c:\jprt\t\p1\162925.ehn\s\src\share\vm\interpreter\interpreterruntime.cpp @ 803] 00000000`3690ec70 00000000`030df241 jvm!InterpreterRuntime::frequency_counter_overflow+0x1a [c:\jprt\t\p1\162925.ehn\s\src\share\vm\interpreter\interpreterruntime.cpp @ 766] 00000000`3690ece0 00000000`02b58070 0x30df241
25-07-2013
The method we are looking at: 0:076> dt jvm!Method 00000000`02b58070 +0x000 __VFN_table : 0x00000000`6febf538 +0x008 _valid : 0n0 +0x010 _constMethod : 0x00000000`02b58010 ConstMethod +0x018 _method_data : 0x00000000`02b5c290 MethodData +0x020 _method_counters : 0x00000000`02b5bf10 MethodCounters +0x028 _access_flags : AccessFlags +0x02c _vtable_index : 0n19 +0x030 _method_size : 0xc +0x032 _intrinsic_id : 0 '' +0x033 _jfr_towrite : 0y0 +0x033 _caller_sensitive : 0y0 +0x033 _force_inline : 0y0 +0x033 _hidden : 0y0 +0x033 _dont_inline : 0y0 +0x034 _compiled_invocation_count : 0n0 +0x038 _i2i_entry : 0x00000000`030de640 "H???" +0x040 _adapter : 0x00000000`2d65fd50 AdapterHandlerEntry +0x048 _from_compiled_entry : 0x00000000`031c7f20 "???" +0x050 _code : 0x00000000`031c7d90 nmethod +0x058 _from_interpreted_entry : 0x00000000`0318eaa0 "H???" =00000000`6f5c0000 extra_stack_entries_for_jsr292 : 0n9460301 0:076> dt ConstMethod 0x00000000`02b58010 jvm!ConstMethod +0x000 _fingerprint : 0x80000000`00000000 +0x008 _constants : 0x00000000`02b56860 ConstantPool +0x010 _stackmap_data : (null) +0x018 _constMethod_size : 0n10 +0x01c _flags : 5 +0x01e _code_size : 0xb +0x020 _name_index : 0x91 +0x022 _signature_index : 0x92 +0x024 _method_idnum : 0x13 +0x026 _max_stack : 2 +0x028 _max_locals : 1 +0x02a _size_of_parameters : 1 =00000000`6fec2b7c ConstMethod::MAX_IDNUM : 0xfffe =00000000`6fec2b80 ConstMethod::UNSET_IDNUM : 0xffff 0:076> dt MethodCounters 0x00000000`02b5bf10 jvm!MethodCounters +0x000 _interpreter_invocation_count : 0n30280 +0x004 _interpreter_throwout_count : 0 +0x006 _number_of_breakpoints : 0 +0x008 _invocation_counter : InvocationCounter +0x00c _backedge_counter : InvocationCounter +0x010 _rate : 0 +0x018 _prev_time : 0n0 0:076> dt InvocationCounter 0x00000000`02b5bf18 jvm!InvocationCounter +0x000 _counter : 0xa485 =00000000`7020e2b8 InvocationCounter::InterpreterInvocationLimit : 0n80000 =00000000`7020e2b4 InvocationCounter::InterpreterBackwardBranchLimit : 0n10700 =00000000`7020e2b0 InvocationCounter::InterpreterProfileLimit : 0n26400 =00000000`7020e2d0 InvocationCounter::_init : [2] 0n0 =00000000`7020e2c0 InvocationCounter::_action : [2] 0x00000000`6f6ce710 unsigned char* jvm!do_nothing+0 0:076> dt -r1 MethodData 0x00000000`02b5c290 jvm!MethodData +0x000 __VFN_table : 0x00000000`6fe72448 +0x008 _valid : 0n0 +0x010 _method : 0x00000000`02b58070 Method +0x000 __VFN_table : 0x00000000`6febf538 +0x008 _valid : 0n0 +0x010 _constMethod : 0x00000000`02b58010 ConstMethod +0x018 _method_data : 0x00000000`02b5c290 MethodData +0x020 _method_counters : 0x00000000`02b5bf10 MethodCounters +0x028 _access_flags : AccessFlags +0x02c _vtable_index : 0n19 +0x030 _method_size : 0xc +0x032 _intrinsic_id : 0 '' +0x033 _jfr_towrite : 0y0 +0x033 _caller_sensitive : 0y0 +0x033 _force_inline : 0y0 +0x033 _hidden : 0y0 +0x033 _dont_inline : 0y0 +0x034 _compiled_invocation_count : 0n0 +0x038 _i2i_entry : 0x00000000`030de640 "H???" +0x040 _adapter : 0x00000000`2d65fd50 AdapterHandlerEntry +0x048 _from_compiled_entry : 0x00000000`031c7f20 "???" +0x050 _code : 0x00000000`031c7d90 nmethod +0x058 _from_interpreted_entry : 0x00000000`0318eaa0 "H???" =00000000`6f5c0000 extra_stack_entries_for_jsr292 : 0n9460301 +0x018 _size : 0n216 +0x01c _hint_di : 0n0 +0x020 _nof_decompiles : 0 +0x024 _nof_overflow_recompiles : 0 +0x028 _nof_overflow_traps : 0 +0x030 _trap_hist : MethodData::<unnamed-type-_trap_hist> +0x000 _align : 0n0 +0x000 _array : [17] "" +0x048 _eflags : 0n0 +0x050 _arg_local : 0n0 +0x058 _arg_stack : 0n0 +0x060 _arg_returned : 0n0 +0x068 _creation_mileage : 0n3308 +0x06c _invocation_counter : InvocationCounter +0x000 _counter : 1 =00000000`7020e2b8 InvocationCounter::InterpreterInvocationLimit : 0n80000 =00000000`7020e2b4 InvocationCounter::InterpreterBackwardBranchLimit : 0n10700 =00000000`7020e2b0 InvocationCounter::InterpreterProfileLimit : 0n26400 =00000000`7020e2d0 InvocationCounter::_init : [2] 0n0 =00000000`7020e2c0 InvocationCounter::_action : [2] 0x00000000`6f6ce710 unsigned char* jvm!do_nothing+0 +0x070 _backedge_counter : InvocationCounter +0x000 _counter : 1 =00000000`7020e2b8 InvocationCounter::InterpreterInvocationLimit : 0n80000 =00000000`7020e2b4 InvocationCounter::InterpreterBackwardBranchLimit : 0n10700 =00000000`7020e2b0 InvocationCounter::InterpreterProfileLimit : 0n26400 =00000000`7020e2d0 InvocationCounter::_init : [2] 0n0 =00000000`7020e2c0 InvocationCounter::_action : [2] 0x00000000`6f6ce710 unsigned char* jvm!do_nothing+0 +0x074 _invocation_counter_start : 0n0 +0x078 _backedge_counter_start : 0n0 +0x07c _num_loops : 0n0 +0x07e _num_blocks : 0n0 +0x080 _highest_comp_level : 0x4 '' +0x081 _highest_osr_comp_level : 0 '' +0x082 _would_profile : 1 +0x084 _data_size : 0n48 +0x088 _data : [1] 0n196613 The _counter of method_data() is 1. No carry set. The else if in bool Method::was_executed_more_than(int n) { ... else if ((method_counters() != NULL && method_counters()->invocation_counter()->carry()) || (method_data() != NULL && method_data()->invocation_counter()->carry())) { // The carry bit is set when the counter overflows and causes // a compilation to occur. We don't know how many times // the counter has been reset, so we simply assume it has // been executed more than n times. return true; } else { return invocation_count() > n; } would be false and we would do invocation_count() > 0 ... invocation count should be 0x1490 given the _counter 0xa485
25-07-2013
Albert on vacation. Rickard could you look on this? It failed only on win64. So it is either C++ problem or we really have race but why only on win64. Can you look on minidump to get call stack? Thanks.
24-07-2013
For some reasons the reported failure happens only on windows 64. Could be C++ problem because, as Jiangli pointed, the carry bit is set few instructions before: mcs->invocation_counter()->set_carry(); mcs->backedge_counter()->set_carry(); assert(!m->was_never_executed(), "don't reset to 0 -- could be mistaken for never-executed"); bool Method::was_executed_more_than(int n) { ... else if ((method_counters() != NULL && method_counters()->invocation_counter()->carry()) || (method_data() != NULL && method_data()->invocation_counter()->carry())) { // The carry bit is set when the counter overflows and causes // a compilation to occur. We don't know how many times // the counter has been reset, so we simply assume it has // been executed more than n times. return true; I doubt it is concurrency since several hs_err files show that all thread except this one are in blocked state. Also why, WHY there is no native call stack in hs_err files on windows?
23-07-2013
a couple of tests failed with the similar symptoms: RULE java/util/stream/boottest/java/util/stream/NodeTest.java Crash Internal Error ...compilationPolicy.cpp...assert(!m->was_never_executed()) failed: don't reset to ... -- could be mistaken for never-executed RULE java/util/stream/test/org/openjdk/tests/java/util/stream/SliceOpTest.java Crash Internal Error ...compilationPolicy.cpp...assert(!m->was_never_executed()) failed: don't reset to ... -- could be mistaken for never-executed hs_err_pid697608 attached for the record..
13-06-2013
ILW=MMH=>P3
10-06-2013
The assert(!m->was_never_executed()) looks very strange. The NonTieredCompPolicy::reset_counter_for_invocation_event() sets the invocation_counter carry bit right before the !m->was_never_executed() check. The check should always succeed as the carry bit is set. Looking at the InvocationCounter code, the 'count', 'carry' and 'state' are encoded using single 32-bit integer. The operations on the 'count', 'carry' and 'state' do not look thread safe. If another thread also updates the same counter's 'count' or 'state' at the same time, the 'carry' bit could be lost due to race.
25-04-2013