RFR (XS): 8035983: Fix "Native frames:" in crash report (hs_err file)

[Christian Thalinger]

On Feb 28, 2014, at 3:25 PM, Vladimir Kozlov <vladimir.kozlov at oracle.com> wrote:

> On 2/27/14 7:59 PM, Christian Thalinger wrote:
>> 
>> On Feb 27, 2014, at 6:39 PM, Vladimir Kozlov <vladimir.kozlov at oracle.com> wrote:
>> 
>>> http://cr.openjdk.java.net/~kvn/8035983/webrev.01/
>>> 
>>> New check is used only for JavaThread where it is definitely initialized and where we have problem with call stack dump.
>> 
>> Looks good.  Just to be sure; +1 would also work here:
>> 
>> +                if (!_thread->on_local_stack((address)(fr.sp() + 4)))
>> 
>> Right?
> 
> No, for Stack: [0xffff80ffa69f8000,0xffff80ffa6af8000]
> 
> I see for first frame "_lwp_start+0x0"
> 
> frame::_sp = 0xffff80ffa6af7ff0
> 
> I just tested it on SPARC and it needs more than +4 (+11), the first frame has:
> 
> frame::_sp = 0xffffffff6befff50
> 
> It seems using fr.sender_sp() in the check work on x86 and sparc.
> On x86 it return stack_base value on sparc it returns STACK_BIAS.
> 
>  if (!_thread->on_local_stack((address)(fr.sender_sp() + 1)))
>    break;
> 
> http://cr.openjdk.java.net/~kvn/8035983/webrev.02/

That looks good and supposedly also works on PPC, ARM and all the others.

> 
> Thanks,
> Vladimir
> 
>> 
>>> 
>>> thanks,
>>> Vladimir
>>> 
>>> On 2/27/14 6:31 PM, Christian Thalinger wrote:
>>>> 
>>>> On Feb 27, 2014, at 6:08 PM, Vladimir Kozlov <vladimir.kozlov at oracle.com> wrote:
>>>> 
>>>>> 
>>>>> 
>>>>> On 2/27/14 5:38 PM, Christian Thalinger wrote:
>>>>>> 
>>>>>> On Feb 27, 2014, at 4:33 PM, Vladimir Kozlov <vladimir.kozlov at oracle.com> wrote:
>>>>>> 
>>>>>>> https://bugs.openjdk.java.net/browse/JDK-8035983
>>>>>>> http://cr.openjdk.java.net/~kvn/8035983/webrev/
>>>>>>> 
>>>>>>> We don't print whole stack if native frames intermix with compiled java frames (on x86 fp is used by compiled code).
>>>>>>> Instead of using os::is_first_C_frame() which produces incorrect result for compiled java frames I am suggesting to look on frame's stack pointer relative to stack base.
>>>>>> 
>>>>>> I have two questions:
>>>>>> 
>>>>>> 1) Why does this work:
>>>>>> 
>>>>>> +              // Catch very first native frame by using stack address.
>>>>>> +              if (!_thread->on_local_stack((address)(fr.sp() + 4))) break;
>>>>>> 
>>>>>> Because we set the stack base to the current value when we start the thread?
>>>>> 
>>>>> You are right not all threads have stack base set (all VM's thread do). So I need to add check for stack_size() != 0 and use is_first_C_frame() if it is 0 (uninitialized).
>>>> 
>>>> Maybe add a comment why the on_local_stack() check works.
>>>> 
>>>>> 
>>>>>> 
>>>>>> 2) Why does this not work?  I have seen many correct stack traces in the past.
>>>>> 
>>>>> Look on os::is_first_C_frame(). It does some stupid simple checks which nothing to do with real value. The test will pass if a java compiled code has a pointer in EBP register.
>>>> 
>>>> Ah, that’s what I was missing.  Makes sense then.  Yeah, the code in os::is_first_C_frame() is weird :-)
>>>> 
>>>>> 
>>>>> Thanks,
>>>>> Vladimir
>>>>> 
>>>>>> 
>>>>>>> 
>>>>>>> Thanks,
>>>>>>> Vladimir
>>>>>>> 
>>>>>>> Output before the fix:
>>>>>>> 
>>>>>>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
>>>>>>> V  [libjvm.so+0x1e28428]  void VMError::report(outputStream*)+0x1478
>>>>>>> V  [libjvm.so+0x1e29dd4]  void VMError::report_and_die()+0x6b4
>>>>>>> V  [libjvm.so+0x14ad9ba]  void report_vm_error(const char*,int,const char*,const char*)+0x9a
>>>>>>> V  [libjvm.so+0x1b6ccf5]  void ObjectMonitor::exit(bool,Thread*)+0x125
>>>>>>> V  [libjvm.so+0x1d41cda]  void ObjectSynchronizer::fast_exit(oopDesc*,BasicLock*,Thread*)+0x38a
>>>>>>> V  [libjvm.so+0x1d41fba]  void ObjectSynchronizer::slow_exit(oopDesc*,BasicLock*,Thread*)+0x2a
>>>>>>> V  [libjvm.so+0x1caa13f]  void SharedRuntime::complete_monitor_unlocking_C(oopDesc*,BasicLock*)+0x27f
>>>>>>> 
>>>>>>> 
>>>>>>> After the fix:
>>>>>>> 
>>>>>>> Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
>>>>>>> V  [libjvm.so+0x1e28428]  void VMError::report(outputStream*)+0x1478
>>>>>>> V  [libjvm.so+0x1e29dd4]  void VMError::report_and_die()+0x6b4
>>>>>>> V  [libjvm.so+0x14ad9ba]  void report_vm_error(const char*,int,const char*,const char*)+0x9a
>>>>>>> V  [libjvm.so+0x1b6ccf5]  void ObjectMonitor::exit(bool,Thread*)+0x125
>>>>>>> V  [libjvm.so+0x1d41cda]  void ObjectSynchronizer::fast_exit(oopDesc*,BasicLock*,Thread*)+0x38a
>>>>>>> V  [libjvm.so+0x1d41fba]  void ObjectSynchronizer::slow_exit(oopDesc*,BasicLock*,Thread*)+0x2a
>>>>>>> V  [libjvm.so+0x1caa13f]  void SharedRuntime::complete_monitor_unlocking_C(oopDesc*,BasicLock*)+0x27f
>>>>>>> J 13 C2 java.util.Hashtable.get(Ljava/lang/Object;)Ljava/lang/Object; (69 bytes) @ 0xffff80ffb979da84 [0xffff80ffb979d700+0x384]
>>>>>>> J 10% C2 Test.Worker()V (381 bytes) @ 0xffff80ffb97a1c8c [0xffff80ffb97a1840+0x44c]
>>>>>>> j  Test$1.run()V+0
>>>>>>> v  ~StubRoutines::call_stub
>>>>>>> V  [libjvm.so+0x177d196]  void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x886
>>>>>>> V  [libjvm.so+0x1b9a6c8]  void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x38
>>>>>>> V  [libjvm.so+0x177c90a]  void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x9a
>>>>>>> V  [libjvm.so+0x177be70]  void JavaCalls::call_virtual(JavaValue*,KlassHandle,Symbol*,Symbol*,JavaCallArguments*,Thread*)+0x250
>>>>>>> V  [libjvm.so+0x177bf56]  void JavaCalls::call_virtual(JavaValue*,Handle,KlassHandle,Symbol*,Symbol*,Thread*)+0x66
>>>>>>> V  [libjvm.so+0x1896897]  void thread_entry(JavaThread*,Thread*)+0xc7
>>>>>>> V  [libjvm.so+0x1d8f23e]  void JavaThread::thread_main_inner()+0x18e
>>>>>>> V  [libjvm.so+0x1d8f09a]  void JavaThread::run()+0x1fa
>>>>>>> V  [libjvm.so+0x1b8f3c8]  java_start+0x248
>>>>>>> C  [libc.so.1+0x122105]  _thrp_setup+0xa5
>>>>>>> C  [libc.so.1+0x1223b0]  _lwp_start+0x0
>>>> 
>>