[Mono-bugs] [Bug 692896] New: Java.Lang.Exceptions aren't GC'd and can create a reference table overflow

bugzilla_noreply at novell.com bugzilla_noreply at novell.com
Tue May 10 11:38:00 EDT 2011 

https://bugzilla.novell.com/show_bug.cgi?id=692896

https://bugzilla.novell.com/show_bug.cgi?id=692896#c0


           Summary: Java.Lang.Exceptions aren't GC'd and can create a
                    reference table overflow
    Classification: Mono
           Product: MonoDroid
           Version: SVN
          Platform: Other
        OS/Version: Other
            Status: NEW
          Severity: Major
          Priority: P5 - None
         Component: Runtime
        AssignedTo: mkestner at novell.com
        ReportedBy: saml at itrgroupinc.com
         QAContact: mono-bugs at lists.ximian.com
          Found By: ---
           Blocker: ---


Created an attachment (id=428872)
 --> (http://bugzilla.novell.com/attachment.cgi?id=428872)
M4A repro project

User-Agent:       Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0.1) Gecko/20100101
Firefox/4.0.1

I have an application that crashes sometimes, when its JNI reference table is
filled. When it crashes, the reference table size is 512, and is mostly filled
with Java.Lang.NoClassDefFoundErrors. I'm not throwing them myself, nor am I
being notified of when they're happening in the logs or debugger.

Because I don't have this information, I tried a whole bunch of silly things to
try to make it crash, and I finally succeeded in the attached test case.

What I found is that Any Java.Lang.Exception will cause this sort of behavior,
but (unsurprisingly) System.Exceptions and Exceptions in Java code do not.

Reproducible: Always

Steps to Reproduce:
1. Run code in attached m4a project
2. Wait for crash
Actual Results:  
Here's the log output from the test:

05-10 09:46:55.399: WARN/dalvikvm(32350): ReferenceTable overflow (max=51200)
05-10 09:46:55.399: WARN/dalvikvm(32350): Last 10 entries in JNI global
reference table:
05-10 09:46:55.399: WARN/dalvikvm(32350): 51190: 0x480aeab8
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.399: WARN/dalvikvm(32350): 51191: 0x480aeaf8
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.399: WARN/dalvikvm(32350): 51192: 0x480aeb38
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.399: WARN/dalvikvm(32350): 51193: 0x480aeb78
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.399: WARN/dalvikvm(32350): 51194: 0x480aebb8
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.399: WARN/dalvikvm(32350): 51195: 0x480aebf8
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.399: WARN/dalvikvm(32350): 51196: 0x480aec38
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.399: WARN/dalvikvm(32350): 51197: 0x480aec78
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.399: WARN/dalvikvm(32350): 51198: 0x480aecb8
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.399: WARN/dalvikvm(32350): 51199: 0x480aecf8
cls=Ljava/lang/Exception; (28 bytes)
05-10 09:46:55.524: WARN/dalvikvm(32350): JNI global reference table summary
(51200 entries):
05-10 09:46:55.524: WARN/dalvikvm(32350):   121 of Ljava/lang/Class; 164B (72
unique)
05-10 09:46:55.536: WARN/dalvikvm(32350): 50736 of Ljava/lang/Exception; 28B
(50736 unique)
05-10 09:46:55.536: WARN/dalvikvm(32350):   319 of Ljava/lang/Exception; 36B
(319 unique)
05-10 09:46:55.536: WARN/dalvikvm(32350):     2 of Ldalvik/system/VMRuntime;
12B (1 unique)
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of Ljava/lang/String; 28B
05-10 09:46:55.536: WARN/dalvikvm(32350):     8 of
Ljava/lang/ref/WeakReference; 28B (8 unique)
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of
Ljava/lang/ref/WeakReference; 36B
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of
Landroid/app/ActivityThread$ApplicationThread; 28B
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of
Ldalvik/system/PathClassLoader; 52B
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of
Landroid/content/ContentProvider$Transport; 28B
05-10 09:46:55.536: WARN/dalvikvm(32350):     2 of
Lorg/apache/harmony/xnet/provider/jsse/TrustManagerImpl; 28B (1 unique)
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of Landroid/widget/Button; 564B
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of Landroid/view/ViewRoot$W;
28B
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of
Landroid/view/accessibility/AccessibilityManager$1; 36B
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of Lm4acrashdummy/Activity1;
180B
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of
Lmono/android/view/view/IOnClickListenerAdapter; 12B
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of
Landroid/view/inputmethod/InputMethodManager$1; 28B
05-10 09:46:55.536: WARN/dalvikvm(32350):     1 of
Landroid/view/inputmethod/InputMethodManager$ControlledInputConnectionWrapper;
36B
05-10 09:46:55.536: WARN/dalvikvm(32350): Memory held directly by tracked refs
is 1445220 bytes
05-10 09:46:55.536: ERROR/dalvikvm(32350): Failed adding to JNI global ref
table (51200 entries)
05-10 09:46:55.540: ERROR/dalvikvm(32350): VM aborting
05-10 09:46:55.555: DEBUG/Zygote(2351): Process 32350 exited cleanly (1)


And, for sanity's sake, here's the log output from my application:

05-10 10:00:59.125: DEBUG/dalvikvm(3750): GC_EXPLICIT freed 5694 objects /
342648 bytes in 38ms
05-10 10:00:59.297: DEBUG/dalvikvm(3750): GC_EXTERNAL_ALLOC freed 1781 objects
/ 88992 bytes in 36ms
05-10 10:01:00.883: DEBUG/dalvikvm(3750): GC_EXTERNAL_ALLOC freed 8091 objects
/ 494176 bytes in 40ms
05-10 10:01:01.364: DEBUG/dalvikvm(3750): GC_EXPLICIT freed 2478 objects /
141152 bytes in 37ms
05-10 10:01:01.563: DEBUG/dalvikvm(3750): GC_EXTERNAL_ALLOC freed 1589 objects
/ 79448 bytes in 37ms
05-10 10:01:02.133: INFO/dalvikvm(3750): Jit: resizing JitTable from 4096 to
8192
05-10 10:01:02.864: WARN/dalvikvm(3750): ReferenceTable overflow (max=512)
05-10 10:01:02.864: WARN/dalvikvm(3750): Last 10 entries in JNI local reference
table:
05-10 10:01:02.864: WARN/dalvikvm(3750):   502: 0x47fedb68
cls=Ljava/lang/String; (28 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750):   503: 0x4001d490
cls=Ljava/lang/NoClassDefFoundError; (28 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750):   504: 0x4001d490
cls=Ljava/lang/NoClassDefFoundError; (28 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750):   505: 0x4001d490
cls=Ljava/lang/NoClassDefFoundError; (28 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750):   506: 0x48001210
cls=Ljava/lang/String; (28 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750):   507: 0x4001d490
cls=Ljava/lang/NoClassDefFoundError; (28 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750):   508: 0x4001d490
cls=Ljava/lang/NoClassDefFoundError; (28 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750):   509: 0x48001970
cls=Ljava/lang/String; (28 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750):   510: 0x48003170
cls=Ljava/lang/ClassNotFoundException; (28 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750):   511: 0x401f66d8
cls=Ljava/lang/Class; 'Ljava/lang/ClassNotFoundException;' (164 bytes)
05-10 10:01:02.864: WARN/dalvikvm(3750): JNI local reference table summary (512
entries):
05-10 10:01:02.864: WARN/dalvikvm(3750):     1 of Ljava/lang/Class; 164B
05-10 10:01:02.864: WARN/dalvikvm(3750):   361 of
Ljava/lang/NoClassDefFoundError; 28B (1 unique)
05-10 10:01:02.864: WARN/dalvikvm(3750):   129 of Ljava/lang/String; 28B (129
unique)
05-10 10:01:02.864: WARN/dalvikvm(3750):    20 of Ljava/lang/String; 36B (20
unique)
05-10 10:01:02.864: WARN/dalvikvm(3750):     1 of
Ljava/lang/ClassNotFoundException; 28B
05-10 10:01:02.864: WARN/dalvikvm(3750): Memory held directly by tracked refs
is 4552 bytes
05-10 10:01:02.864: ERROR/dalvikvm(3750): Failed adding to JNI local ref table
(has 512 entries)
05-10 10:01:02.864: INFO/dalvikvm(3750): "Thread-11" prio=5 tid=9 RUNNABLE
05-10 10:01:02.864: INFO/dalvikvm(3750):   | group="main" sCount=0 dsCount=0
s=N obj=0x47d7fd88 self=0x4466e8
05-10 10:01:02.864: INFO/dalvikvm(3750):   | sysTid=3761 nice=0 sched=0/0
cgrp=default handle=4349136
05-10 10:01:02.864: INFO/dalvikvm(3750):   | schedstat=( 921680722 483690647
645 )
05-10 10:01:02.864: INFO/dalvikvm(3750):   at
dalvik.system.NativeStart.run(Native Method)
05-10 10:01:02.864: ERROR/dalvikvm(3750): VM aborting
05-10 10:01:02.887: DEBUG/Zygote(2351): Process 3750 exited cleanly (1)


Expected Results:  
I created a similar project in Java, that does the same thing (also attached).
Here's a sample of its log output:

05-10 09:44:23.614: DEBUG/dalvikvm(32175): GC_FOR_MALLOC freed 16378 objects /
524248 bytes in 22ms
05-10 09:44:23.681: DEBUG/dalvikvm(32175): GC_FOR_MALLOC freed 16380 objects /
524312 bytes in 22ms
05-10 09:44:23.743: DEBUG/dalvikvm(32175): GC_FOR_MALLOC freed 16378 objects /
524248 bytes in 23ms
05-10 09:44:23.817: DEBUG/dalvikvm(32175): GC_FOR_MALLOC freed 16380 objects /
524312 bytes in 29ms

As you'd expect, these messages keep showing up as the Exceptions are GC'd.

The screen that shows this behavior in my app is a ViewFlipper that has
ListViews dynamically added to it, with their Adapters set to custom Adapters
that I've created, inheriting from BaseAdapter. I've got a feeling that it's in
these child classes that the NoClassDefFoundErrors are coming from, but I don't
have a repro for that. I'm working on one, and I'll attach it to this report if
it yields anything useful.

-- 
Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the QA contact for the bug.

More information about the mono-bugs mailing list