want your help
Yongqiang Yang
xiaoqiangnk at gmail.com
Thu Dec 9 22:22:33 PST 2010
Hi David,
Here is stacktrace for the assertion failure. The 1st column of
number is line numbers. Lines from 1 to 12 are comments beginning as
a '#'.
Thanks,
Yongqiang.
1 #
2 # A fatal error has been detected by the Java Runtime Environment:
3 #
4 # Internal Error
(/home/yangyongqiang/hotspot6/hotspot/src/share/vm/runtime/handles.cpp:34),
pid=17186, tid=11 11291088
5 # assert(SharedSkipVerify || obj->is_oop()) failed: sanity check
6 #
7 # JRE version: 6.0
8 # Java VM: OpenJDK Client VM (19.0-b09-internal-jvmg compiled mode
linux-mips )
9 # If you would like to submit a bug report, please visit:
10 # http://java.sun.com/webapps/bugreport/crash.jsp
11 #
12
13 --------------- T H R E A D ---------------
14
15 Current thread (0x00482400): JavaThread "Finalizer" daemon
[_thread_in_vm, id=17190, stack(0x42380000,0x423d00 00)]
16
17 Stack: [0x42380000,0x423d0000], sp=0x423ce6c8, free space=313k
18 Native frames: (J=compiled Java code, j=interpreted, Vv=VM code,
C=native code)
19 C 0x423ce6d8
20 C 0x423ce6e0
21
22 Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
23 J java.lang.ref.Finalizer.invokeFinalizeMethod(Ljava/lang/Object;)V
24 J java.lang.ref.Finalizer.runFinalizer()V
25 J java.lang.ref.Finalizer.access$100(Ljava/lang/ref/Finalizer;)V
26 j java.lang.ref.Finalizer$FinalizerThread.run()V+11
27 v ~StubRoutines::call_stub
28
29 --------------- P R O C E S S ---------------
30
31 Java Threads: ( => current thread )
32 0x004fb000 JavaThread "Low Memory Detector" daemon
[_thread_blocked, id=17193, stack(0x424a0000,0x424f0000)]
33 0x00497000 JavaThread "CompilerThread0" daemon [_thread_blocked,
id=17192, stack(0x42420000,0x424a0000)]
34 0x00495000 JavaThread "Signal Dispatcher" daemon
[_thread_blocked, id=17191, stack(0x423d0000,0x42420000)]
35 =>0x00482400 JavaThread "Finalizer" daemon [_thread_in_vm,
id=17190, stack(0x42380000,0x423d0000)]
36 0x0047d000 JavaThread "Reference Handler" daemon
[_thread_blocked, id=17189, stack(0x42330000,0x42380000)]
37 0x00437c00 JavaThread "main" [_thread_blocked, id=17187,
stack(0x2bd6c000,0x2bdbc000)]
38
39 Other Threads:
40 0x00478800 VMThread [stack: 0x422b0000,0x42330000] [id=17188]
41 0x00501800 WatcherThread [stack: 0x424f0000,0x42570000] [id=17194]
42
43 VM state:not at safepoint (normal execution)
44
45 VM Mutex/Monitor currently owned by a thread: ([mutex/lock_event])
46 [0x004358a8] Heap_lock - owner thread: 0x00437c00
47
48 Heap
49 def new generation total 4864K, used 87K [0x2dfa0000,
0x2e4e0000, 0x334f0000)
50 eden space 4352K, 1% used [0x2dfa0000, 0x2dfb5c28, 0x2e3e0000)
51 from space 512K, 0% used [0x2e3e0000, 0x2e3e0000, 0x2e460000)
52 to space 512K, 0% used [0x2e460000, 0x2e460000, 0x2e4e0000)
53 tenured generation total 10688K, used 101K [0x334f0000,
0x33f60000, 0x3dfa0000)
54 the space 10688K, 0% used [0x334f0000, 0x335097f0,
0x33509800, 0x33f60000)
55 compacting perm gen total 12288K, used 1620K [0x3dfa0000,
0x3eba0000, 0x41fa0000)
56 the space 12288K, 13% used [0x3dfa0000, 0x3e135290,
0x3e135400, 0x3eba0000)
57 No shared spaces configured.
On Fri, Dec 10, 2010 at 10:59 AM, David Holmes <David.Holmes at oracle.com> wrote:
> Yongqiang Yang said the following on 12/10/10 12:42:
>>
>> On Fri, Dec 10, 2010 at 10:10 AM, David Holmes <David.Holmes at oracle.com>
>> wrote:
>>>
>>> I'm somewhat puzzled as to why the address is so often the same, but this
>>> occurs with other platforms as well.
>>
>> I guess the reason is that System.gc() is invoked manually. Before
>> current allocation request comes, last allocated space has been
>> recycled.
>
> You are right, if I disable the System.gc() then the address changes.
>
> This reminded me that an object can be collected before its finalizer is
> executed if the finalizer does not reference the 'this' reference in a way
> that causes the the object to be retained (bit of a circular description I
> know).
>
> That said I changed the finalizer to reference 'this' in a few ways and it
> still seems that GC was able to reuse the same address. Strange.
>
> Hmmm I have an idea. Can you please show me the stacktrace for the assertion
> failure from the hs_err log file.
>
> David
>
>>> Beyond that I'm out of suggestions as to how and pin this down further -
>>> sorry.
>>>
>>> David
>>>
>>> Yongqiang Yang said the following on 12/10/10 11:49:
>>>>
>>>> Hi ramki,
>>>>
>>>> Thank you for your help.
>>>> I have done as you suggested and found nothing different. I list my
>>>> test program and output at end of this email.
>>>>
>>>> Apparentlym, object at 0x2dfa0000 was collected before finalized with
>>>> Xcomp. However, with Xint, everything is right. Both Xcomp and Xint
>>>> register finalizer through the same function
>>>> instanceKlass::register_finalizer, where a handle for object is
>>>> constructed.
>>>>
>>>> Yongqiang.
>>>>
>>>> My test program named finalexc.java is as follows.
>>>> public class finalexc {
>>>> static int f;
>>>> public void finalize() {
>>>> f++;
>>>> System.out.println("finalize " + f);
>>>> }
>>>> static void test() {
>>>> for (int i = 0; i < 100; i++) {
>>>> new finalexc();
>>>> System.gc();
>>>> }
>>>> }
>>>> public static void main(String av[]) {
>>>> while(true) test();
>>>> }
>>>> }
>>>>
>>>> java -Xcomp -XX:+TraceFinalizerRegistration finalexc
>>>> Output is as follow.
>>>> ===========================================================
>>>> VM option '+TraceFinalizerRegistration'
>>>> Registered a 'java/io/FileInputStream' (0x2dfa8910) as finalizable
>>>> Registered a 'java/io/FileOutputStream' (0x2dfa89c8) as finalizable
>>>> Registered a 'java/io/FileOutputStream' (0x2dfa8a08) as finalizable
>>>> Registered a 'java/lang/ClassLoader$NativeLibrary' (0x2dfb4090) as
>>>> finalizable
>>>> Registered a 'java/io/FileInputStream' (0x2dfb4db8) as finalizable
>>>> Registered a 'java/io/FileInputStream' (0x2dfc9e20) as finalizable
>>>> Registered a 'finalexc' (0x2dfcbfb8) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> return 0x2b2a3618
>>>> allocate_handle 33 0x5431f8
>>>> # To suppress the following error report, specify this argument
>>>> # after -XX: or in .hotspotrc: SuppressErrorAt=/handles.cpp:34
>>>> #
>>>> # A fatal error has been detected by the Java Runtime Environment:
>>>> #
>>>> # Internal Error
>>>>
>>>>
>>>> (/home/yangyongqiang/hotspot6/hotspot/src/share/vm/runtime/handles.cpp:34),
>>>> pid=17186, tid=1111291088
>>>> # assert(SharedSkipVerify || obj->is_oop()) failed: sanity check
>>>> #
>>>> # JRE version: 6.0
>>>> # Java VM: OpenJDK Client VM (19.0-b09-internal-jvmg compiled mode
>>>> linux-mips )
>>>> # An error report file with more information is saved as:
>>>> # /home/yangyongqiang/benchmark/regression/hs_err_pid17186.log
>>>> @@@@@@@@@@@@@@@@@@@get_previous_fp = 0x423ce6c0
>>>> @@@@@@@@@@@@@@@@@@@get_previous_fp = 0x423ce6c0
>>>> #
>>>> # If you would like to submit a bug report, please visit:
>>>> # http://java.sun.com/webapps/bugreport/crash.jsp
>>>> #
>>>> =========================================================
>>>>
>>>> With Xint, output is:
>>>>
>>>> =========================================================
>>>> Registered a 'finalexc' (0x2dfcbe88) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfb5c60) as finalizable
>>>> finalize 1
>>>> finalize 2
>>>> finalize 3
>>>> finalize 4
>>>> Registered a 'finalexc' (0x2dfb5c68) as finalizable
>>>> finalize 5
>>>> Registered a 'finalexc' (0x2dfb5c68) as finalizable
>>>> finalize 6
>>>> Registered a 'finalexc' (0x2dfb5c68) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> Registered a 'finalexc' (0x2dfa0000) as finalizable
>>>> finalize 7
>>>> finalize 8
>>>> =======================================================
>>>>
>>>>
>>>> On Fri, Dec 10, 2010 at 4:42 AM, Y. Srinivas Ramakrishna
>>>> <y.s.ramakrishna at oracle.com> wrote:
>>>>>
>>>>> Yongqiang, In addition to the suggestions already made,
>>>>> you might also try -XX:+CheckUnhandleOops -XX:+VerifyBeforeGC
>>>>> -XX:+VerifyAfterGC to
>>>>> see if it sheds more light in the issue. (although these might
>>>>> slow down execution and cause a race/bug to disappear.)
>>>>>
>>>>> best.
>>>>> -- ramki
>>>>>
>>>>> On 12/9/2010 5:55 AM, Yongqiang Yang wrote:
>>>>>>
>>>>>> Hi David,
>>>>>>
>>>>>> Xint works well. I think I did something wrong with finalizer, but I
>>>>>> can't find it.
>>>>>> When in Xcomp mode, finalize function is not called before object was
>>>>>> collected.
>>>>>> I am sure finalizer is registered.
>>>>>>
>>>>>> On Thu, Dec 9, 2010 at 3:06 PM, David Holmes<David.Holmes at oracle.com>
>>>>>> wrote:
>>>>>>>
>>>>>>> Hi,
>>>>>>>
>>>>>>> Yongqiang Yang said the following on 12/09/10 16:44:
>>>>>>>>
>>>>>>>> Maybe I didn't elaborate the problem clearly.
>>>>>>>> Java_java_lang_ref_Finalizer_invokeFinalizeMethod is a native
>>>>>>>> method.
>>>>>>>> It
>>>>>>>> invokes GetObjectClass and CallVoidMethod. So jump to
>>>>>>>> Java_java_lang_ref_Finalizer_invokeFinalizeMethod via a native
>>>>>>>> wrapper.
>>>>>>>> Thus returns from it uses a native return wrapper. Callings or
>>>>>>>> returns
>>>>>>>> of GetObjectClass and CallVoidMethod are done by g++.
>>>>>>>
>>>>>>> Sorry - You said you were porting to MIPS so I was pointing out that
>>>>>>> the
>>>>>>> problem might be in the MIPS code that handles native method calls eg
>>>>>>> by
>>>>>>> clobbering a register that might be used in the callee. But I just
>>>>>>> realized
>>>>>>> that is for calls from Java to native, not from native to Java - the
>>>>>>> latter
>>>>>>> is all basic C++ code as you point out.
>>>>>>>
>>>>>>>> The bug is as follows.
>>>>>>>> Before return from GetObjectClass, the ob's value is right, that it
>>>>>>>> references a right object. However, when CallVoidMethod begins, ob
>>>>>>>> references a invalid object.
>>>>>>>
>>>>>>> Are you certain there is no gc occurring? If not, and the ob value
>>>>>>> has
>>>>>>> changed when GetObjectClass returns then I can only assume some kind
>>>>>>> of
>>>>>>> memory stomp during the execution of GetObjectClass. Can you add some
>>>>>>> extra
>>>>>>> local variables and check their values to see if it is a stack stomp?
>>>>>>>
>>>>>>> Does the problem occur with -Xint? Is compilation occurring
>>>>>>> elsewhere?
>>>>>>>
>>>>>>> David
>>>>>>> -----
>>>>>>>
>>>>>>>> During the change, Finalizer-Thread is in native method
>>>>>>>> Java_java_lang_ref_Finalizer_invokeFinalizeMethod. That says
>>>>>>>> Finalizer-Thread runs codes compiled by g++ during the change.
>>>>>>>>
>>>>>>>> I think another thread changes ob's value, but I can't think of any
>>>>>>>> thread
>>>>>>>> except GC.
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> On Thu, Dec 9, 2010 at 10:27 AM, David
>>>>>>>> Holmes<David.Holmes at oracle.com
>>>>>>>> <mailto:David.Holmes at oracle.com>> wrote:
>>>>>>>>
>>>>>>>> -Xcomp compiles every method on first use, rather than only
>>>>>>>> compiling when the method becomes "hot".
>>>>>>>>
>>>>>>>> If the test passes in -Xmixed but not -Xcomp then it is likely that
>>>>>>>> in -Xmixed the problematic code is not getting compiled. (Use
>>>>>>>> -XX:+PrintCompilation to check - may need a debug VM for that).
>>>>>>>>
>>>>>>>> The jobject is an opaque reference to the object for which
>>>>>>>> finalize() is to be invoked. Even if safepoints occur and GC occurs
>>>>>>>> etc, this should remain a valid reference. If that is not the case
>>>>>>>> then something is corrupting the value. The stacktrace from the
>>>>>>>> assert should show where the corruption is detected, which may
>>>>>>>> help,
>>>>>>>> but it won't show where it occurred. It could be something as
>>>>>>>> simple
>>>>>>>> as not setting up the correct register usage for return from the
>>>>>>>> native method - ie your method return from GetObjectClass might be
>>>>>>>> trashing the register that holds "ob". I think you would need to be
>>>>>>>> able to dump dissassenbly of both methods to see if there is
>>>>>>>> obvious
>>>>>>>> corruption.
>>>>>>>>
>>>>>>>> David Holmes
>>>>>>>>
>>>>>>>> Yongqiang Yang said the following on 12/09/10 11:57:
>>>>>>>>
>>>>>>>> Hi Gary,
>>>>>>>>
>>>>>>>>
>>>>>>>> That you for your help very much.
>>>>>>>> I have looked as you suggested. There is no safepoint rom
>>>>>>>> return at GetObjectClass to calling CallVoidMethod.
>>>>>>>> This bug appears in Finalizer thread every time. Thus, I think
>>>>>>>> maybe there is a bug in finalizer. When I use -Xcomp option,
>>>>>>>> finalize function is not called. When I use mixed or
>>>>>>>> interpretered jvm, finalize is called. I don't know what
>>>>>>>> happens in -Xcomp mode. I find that finalizer is registered
>>>>>>>> using -XX:+TraceRegisterdFinalizer.
>>>>>>>>
>>>>>>>>
>>>>>>>> On Wed, Dec 8, 2010 at 5:49 PM, Gary Benson<gbenson at redhat.com
>>>>>>>> <mailto:gbenson at redhat.com> <mailto:gbenson at redhat.com
>>>>>>>> <mailto:gbenson at redhat.com>>> wrote:
>>>>>>>>
>>>>>>>> Hi Yongqiang,
>>>>>>>>
>>>>>>>> Yongqiang Yang wrote:
>>>>>>>> > Hi everyone,
>>>>>>>> >
>>>>>>>> > I am porting hotspot to MIPS. I meet a bug as follows.
>>>>>>>> >
>>>>>>>> > In function
>>>>>>>> Java_java_lang_ref_Finalizer_invokeFinalizeMethod,
>>>>>>>> > value of jobject is right when call GetObjectClass and
>>>>>>>> also right
>>>>>>>> > before return from GetObjectClass . However, it is
>>>>>>>> wrong
>>>>>>>> when
>>>>>>>> > calling CallVoidMethod. For example, It is changed
>>>>>>>> from
>>>>>>>> 0x3e0885d0
>>>>>>>> > to 0x423ce794.
>>>>>>>> > Thus, it results in an assert failure below.
>>>>>>>> >
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> ----------------------------------------------------------------------
>>>>>>>> > assert(SharedSkipVerify || obj->is_oop()) failed:
>>>>>>>> sanity
>>>>>>>> check
>>>>>>>> >
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> ----------------------------------------------------------------------
>>>>>>>> >
>>>>>>>>
>>>>>>>> > I want to know who will change this value from return at
>>>>>>>> GetObjectClass
>>>>>>>> > to calling CallVoidMethod. During this time, GC don't
>>>>>>>> run.
>>>>>>>>
>>>>>>>> >
>>>>>>>> > Could anyone have an idea about this?
>>>>>>>>
>>>>>>>> Look at the source code to jni_GetMethodID and
>>>>>>>> jni_CallVoidMethod,
>>>>>>>> in hotspot/src/share/vm/prims/jni.cpp. Notice the JNI_ENTRY
>>>>>>>> and
>>>>>>>> JNI_END surrounding them? Look at the source code for
>>>>>>>> JNI_ENTRY,
>>>>>>>> in hotspot/src/share/vm/runtime/interfaceSupport.hpp. Do
>>>>>>>> you
>>>>>>>> see
>>>>>>>> the ThreadInVMfromNative? That object has a constructor and
>>>>>>>> a
>>>>>>>> destructor, both of which contain thread state transitions.
>>>>>>>> Safepoints can occur during those transitions, and oops can
>>>>>>>> change
>>>>>>>> at any safepoint regardless of whether the GC runs. You
>>>>>>>> could try
>>>>>>>> running with -XX:+TraceSafepoint or something like that to
>>>>>>>> see
>>>>>>>> if
>>>>>>>> one is occuring.
>>>>>>>>
>>>>>>>> Cheers,
>>>>>>>> Gary
>>>>>>>>
>>>>>>>> --
>>>>>>>> http://gbenson.net/
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> -- Best Wishes
>>>>>>>> Yongqiang Yang
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> --
>>>>>>>> Best Wishes
>>>>>>>> Yongqiang Yang
>>>>>>>>
>>>>>>
>>>>
>>>>
>>
>>
>>
>
--
Best Wishes
Yongqiang Yang
More information about the hotspot-dev
mailing list