crash in JvmtiExport::post_compiled_method_load
Chris Plummer
chris.plummer at oracle.com
Wed May 9 08:12:59 UTC 2018
On 5/8/18 11:00 PM, David Holmes wrote:
> On 9/05/2018 3:06 PM, Ioi Lam wrote:
>> Serguei & Nezih,
>>
>> I've looked at the crash log and it seems like nm->method() is NULL,
>> which caused the crash.
>>
>> I am not familiar with the JVMTI internals or nmethods, so I am just
>> guessing here -- is it legal for nm->method() to be NULL? Or, is it
>> possible that someone has cleared nm->method() before it's processed
>> by post_compiled_method_load?
>
> I was wondering the same thing. Vladimir K. pointed me at:
>
> http://hg.openjdk.java.net/jdk/jdk/file/ae0ebd3cf949/src/hotspot/share/runtime/sweeper.hpp#l42
>
>
> for the nmethod lifecycle. Given this is actually a deferred event, I
> too wonder if the nmethod may have been made not-entrant or even
> zombie, since the event was posted.
JvmtiDeferredEvent JvmtiDeferredEvent::compiled_method_load_event(
nmethod* nm) {
JvmtiDeferredEvent event = JvmtiDeferredEvent(TYPE_COMPILED_METHOD_LOAD);
event._event_data.compiled_method_load = nm;
// Keep the nmethod alive until the ServiceThread can process
// this deferred event.
nmethodLocker::lock_nmethod(nm);
return event;
}
case TYPE_COMPILED_METHOD_LOAD: {
nmethod* nm = _event_data.compiled_method_load;
JvmtiExport::post_compiled_method_load(nm);
// done with the deferred event so unlock the nmethod
nmethodLocker::unlock_nmethod(nm);
break;
}
The same thing is done for unload. I was wondering if we would possibly
have trouble if we enqueued both the load and unload events, but the
lock is done with an atomic inc/dec, so it should be ok.
I guess still to be determined is if the nm could get freed before we
even have a chance to call lock_nmethod().
Chris
>
> David
> -----
>
>> Details from the crash log:
>>
>> =================================
>> Native frames: (J=compiled Java code, A=aot compiled Java code,
>> j=interpreted, Vv=VM code, C=native code)
>> V [libjvm.so+0x99e365]
>> JvmtiExport::post_compiled_method_load(nmethod*)+0x275
>> V [libjvm.so+0x9a6614] JvmtiDeferredEvent::post()+0x44
>> V [libjvm.so+0xc2c507]
>> ServiceThread::service_thread_entry(JavaThread*, Thread*)+0x337
>> V [libjvm.so+0xceee58] JavaThread::thread_main_inner()+0xd8
>> V [libjvm.so+0xb6de12] thread_native_entry(Thread*)+0xf2
>> C [libpthread.so.0+0x7e25] start_thread+0xc5
>> ...
>> R14=0x0000000000000000 is an unknown value
>> =================================
>>
>> Here's a disassembly of JvmtiExport::post_compiled_method_load from
>> JDK 9.0.1
>>
>> http://hg.openjdk.java.net/jdk9/jdk9/hotspot/file/b756e7a2ec33/src/share/vm/prims/jvmtiExport.cpp
>>
>>
>> 2051 HandleMark hm(thread);
>> 0x00007ffff67dd239 <+329>: mov %rax,-0x140(%rbp)
>> 0x00007ffff67dd240 <+336>: callq 0x7ffff66149d0
>> <HandleMark::initialize(Thread*)>
>>
>> 2054 jvmtiCompiledMethodLoadInlineRecord* inlinerecord =
>> create_inline_record(nm);
>> 0x00007ffff67dd245 <+341>: mov %r12,%rdi
>> 0x00007ffff67dd248 <+344>: callq 0x7ffff67d4090
>> <create_inline_record(nmethod*)>
>>
>> 2055 // Pass inlining information through the void pointer
>> 2056 JvmtiCompiledMethodLoadEventMark jem(thread, nm,
>> inlinerecord);
>> 0x00007ffff67dd24d <+349>: mov %rax,-0x1a8(%rbp)
>> 0x00007ffff67dd254 <+356>: mov 0x70(%r12),%rax
>> 0x00007ffff67dd259 <+361>: mov %rbx,-0x178(%rbp)
>> 0x00007ffff67dd260 <+368>: test %rax,%rax
>> 0x00007ffff67dd263 <+371>: mov %rax,-0x180(%rbp)
>> 0x00007ffff67dd26a <+378>: je 0x7ffff67dd282
>> <JvmtiExport::post_compiled_method_load(nmethod*)+402>
>> 0x00007ffff67dd26c <+380>: mov %rax,-0xa0(%rbp)
>> 0x00007ffff67dd273 <+387>: mov 0x160(%rbx),%rdi
>> 0x00007ffff67dd27a <+394>: mov %r13,%rsi
>> 0x00007ffff67dd27d <+397>: callq 0x7ffff671d5f0
>> <GrowableArray<Metadata*>::append(Metadata* const&)>
>> 0x00007ffff67dd282 <+402>: lea 0x218(%rbx),%rax
>> 0x00007ffff67dd289 <+409>: mov %rbx,-0xf0(%rbp)
>> 0x00007ffff67dd290 <+416>: movl $0x0,-0xe0(%rbp)
>> 0x00007ffff67dd29a <+426>: mov %rax,-0xe8(%rbp)
>> 0x00007ffff67dd2a1 <+433>: mov 0x3c8(%rbx),%rax
>> 0x00007ffff67dd2a8 <+440>: test %rax,%rax
>> 0x00007ffff67dd2ab <+443>: je 0x7ffff67dd2b6
>> <JvmtiExport::post_compiled_method_load(nmethod*)+454>
>> 0x00007ffff67dd2ad <+445>: mov 0x10(%rax),%eax
>> 0x00007ffff67dd2b0 <+448>: mov %eax,-0xe0(%rbp)
>> 0x00007ffff67dd2b6 <+454>: mov 0x38(%rbx),%r14
>> 0x00007ffff67dd2ba <+458>: mov %rbx,%rdi
>> 0x00007ffff67dd2bd <+461>: callq 0x7ffff6707d50
>> <JNIHandleBlock::allocate_block(Thread*)>
>> 0x00007ffff67dd2c2 <+466>: lea 0x1f8(%rbx),%rdi
>> 0x00007ffff67dd2c9 <+473>: mov %rbx,%rsi
>> 0x00007ffff67dd2cc <+476>: mov %r14,0x118(%rax)
>> 0x00007ffff67dd2d3 <+483>: mov %rax,0x38(%rbx)
>> 0x00007ffff67dd2d7 <+487>: callq 0x7ffff6559410
>> <JavaFrameAnchor::make_walkable(JavaThread*)>
>> 0x00007ffff67dd2dc <+492>: mov 0x1f0(%rbx),%rsi
>> 0x00007ffff67dd2e3 <+499>: mov -0xf0(%rbp),%rdi
>> 0x00007ffff67dd2ea <+506>: callq 0x7ffff6708520
>> <JNIHandles::make_local(Thread*, oopDesc*)>
>> 0x00007ffff67dd2ef <+511>: mov -0x1a0(%rbp),%rsi
>> 0x00007ffff67dd2f6 <+518>: mov %rax,-0xd8(%rbp)
>> 0x00007ffff67dd2fd <+525>: lea -0x170(%rbp),%rax
>> 0x00007ffff67dd304 <+532>: mov %rax,%rdi
>> 0x00007ffff67dd307 <+535>: mov %rax,-0x1b0(%rbp)
>>
>>
>> // JvmtiMethodEventMark(JavaThread *thread, methodHandle method) :
>> // JvmtiThreadEventMark(thread),
>> 234 _mid(to_jmethodID(method)) {}; <-- this line
>>
>> 0x00007ffff67dd30e <+542>: callq 0x7ffff66140a0
>> <methodHandle::methodHandle(methodHandle const&)>
>> 0x00007ffff67dd313 <+547>: mov -0x170(%rbp),%r14
>> 0x00007ffff67dd31a <+554>: movq $0x0,-0x98(%rbp)
>> 0x00007ffff67dd325 <+565>: test %r14,%r14
>> 0x00007ffff67dd328 <+568>: mov %r14,-0xa0(%rbp)
>> 0x00007ffff67dd32f <+575>: je 0x7ffff67dd365
>> <JvmtiExport::post_compiled_method_load(nmethod*)+629>
>>
>> 0x00007ffff67dd331 <+577>: data16 lea
>> 0x946ca7(%rip),%rdi # 0x7ffff7123fe0
>> 0x00007ffff67dd339 <+585>: data16 data16 callq 0x7ffff60b11d0
>> <__tls_get_addr at plt>
>> 0x00007ffff67dd341 <+593>: lea -0x188(%rbp),%rsi
>> 0x00007ffff67dd348 <+600>: mov %r14,-0x188(%rbp)
>> 0x00007ffff67dd34f <+607>: mov (%rax),%rax
>> 0x00007ffff67dd352 <+610>: mov %rax,-0x98(%rbp)
>> 0x00007ffff67dd359 <+617>: mov 0x160(%rax),%rdi
>> 0x00007ffff67dd360 <+624>: callq 0x7ffff671d5f0
>> <GrowableArray<Metadata*>::append(Metadata* const&)>
>>
>> >>> CRASH %r14 == 0x0
>> 198 jmethodID to_jmethodID(methodHandle method) { return
>> method->jmethod_id(); }
>>
>> 0x00007ffff67dd365 <+629>: mov 0x8(%r14),%rax
>>
>>
>> Hope this helps
>> - Ioi
>>
>> On 5/8/18 4:51 PM, serguei.spitsyn at oracle.com wrote:
>>> Hi Nezih,
>>>
>>> Crashing in the JvmtiExport::post_compiled_method_load function
>>> does not prove itself that it is a VM issue.
>>> And there are mo specific details in the log that help to understand
>>> this.
>>> Filing a bug with this log is almost useless as it would not help to
>>> get to the root cause.
>>> Also, there is still a pretty big chance the real problem is in the
>>> agent.
>>>
>>> My advice is to get as more details about this crash as possible.
>>> The best you can do is to provide a stand alone test case.
>>> Even if the issue is in the agent it will help to figure it out.
>>>
>>> Thanks,
>>> Serguei
>>>
>>>
>>> On 5/8/18 16:38, nezih yigitbasi wrote:
>>>> Hi Serguei,
>>>> We don't have a repro unfortunately. We have seen this only once so
>>>> far in our production environment.
>>>>
>>>> Do you think this can be an agent issue? I thought like if it was
>>>> an agent issue the stack trace would show it. The stack trace,
>>>> however, ends in the VM code -- the crash happens in the
>>>> "JvmtiExport::post_compiled_method_load" method.
>>>>
>>>> Thanks,
>>>> Nezih
>>>>
>>>> 2018-05-08 16:34 GMT-07:00 serguei.spitsyn at oracle.com
>>>> <mailto:serguei.spitsyn at oracle.com> <serguei.spitsyn at oracle.com
>>>> <mailto:serguei.spitsyn at oracle.com>>:
>>>>
>>>> Hi Nezih,
>>>>
>>>> You error file with log does not help much.
>>>> Could you, please, reproduce this issue with the debug or
>>>> fastdebug build?
>>>> Also, a standalone test case is better to provide to
>>>> increase chances the issue to be investigated and fixed.
>>>>
>>>> In general, a JVMTI agent has to be written very carefully as it
>>>> can easily cause the VM to crash.
>>>> So, it makes sense to look at the agent implementation first to
>>>> make sure it does not do anything wrong.
>>>> It is what we normally do first and why a test case that
>>>> demonstrates the problem is needed.
>>>>
>>>> Thanks,
>>>> Serguei
>>>>
>>>>
>>>>
>>>> On 5/8/18 16:00, nezih yigitbasi wrote:
>>>>> Hi,
>>>>>
>>>>> First of all, sorry for bringing up a crash issue in this dev
>>>>> mailing list, but the crash report submission page
>>>>> (https://bugreport.java.com/bugreport/crash.jsp
>>>>> <https://bugreport.java.com/bugreport/crash.jsp>) doesn't list
>>>>> Java 9 in the release drop down, so I couldn't report it there.
>>>>>
>>>>> We recently got a crash with Java 9.0.1+11 with an interesting
>>>>> stack ending at "JvmtiExport::post_compiled_method_load()"
>>>>> (entire error file is here
>>>>> <https://gist.github.com/nezihyigitbasi/52a58698cc9acfcab21c69d00bd0cef2>).
>>>>> A google search didn't end up with much info, so I just wanted
>>>>> to check with this mailing list to see whether anyone has any
>>>>> ideas to investigate this further.
>>>>>
>>>>> Thanks,
>>>>> Nezih
>>>>>
>>>>
>>>>
>>>
>>
More information about the serviceability-dev
mailing list