Android App Crashes Suddenly while running?

Question

What my App does ? The App I am developing is a typical client server App which talks to a windows server using Wifi. The Application has multiple Activities and really has heavy memory and CPU requirements i.e native calls for speex encoding / decoding.

What my Problem is ? The problem is the Application restarts suddenly while working absolutely fine. Sometimes while working normally suddenly I see (in logcat ) that the Constructor of Application class (Class which extends API's Application Class) is called. That crashes my App since all the global data is stored with in the Application class itself.

What I have done ? The first thing which struck my mind was that may be Android feels their is low memory so it terminates my App, and than restarts it automatically. So I implemented onLowMemory() of Application class. But to my surprise it is never called..

What is the main problem ? The main problem is that Nothing is printed on LogCat. It looks that even the Android itself is clueless about why it restarted my already running Application ?

What could be the possible reason of this sudden restart ? How can I avoid that ?

I am working on Galaxy Y, and the API version is 2.3.6. My AndroidManifiest.xml looks like

<manifest xmlns:android="http://schemas.android.com/apk/res/android"
    package="some.package.MyApp"
    android:versionCode="1"
    android:versionName="1.0" >

    <uses-sdk
        android:maxSdkVersion="15"
        android:minSdkVersion="10"
        android:targetSdkVersion="10" />

    <uses-permission android:name="android.permission.RECORD_AUDIO" />
    <uses-permission android:name="android.permission.WRITE_EXTERNAL_STORAGE" />
    <uses-permission android:name="android.permission.ACCESS_NETWORK_STATE" />
    <uses-permission android:name="android.permission.ACCESS_WIFI_STATE" />
    <uses-permission android:name="android.permission.INTERNET" />

    <uses-permission android:name="android.permission.CAMERA" />
    <uses-permission android:name="android.permission.RECORD_VIDEO" />

    <uses-feature android:name="android.hardware.camera" />
    <uses-feature android:name="android.hardware.camera.autofocus" />

    <application
        android:name="some.package.MyApp"
        android:icon="@drawable/display_image"
        android:label="@string/app_name" >
        <activity
            android:name="some.package.LoginActivity"
            android:configChanges="keyboardHidden|orientation"
            android:label="@string/app_name"
            android:screenOrientation="user" >
            <intent-filter>
                <action android:name="android.intent.action.MAIN" />

                <category android:name="android.intent.category.LAUNCHER" />
            </intent-filter>
        </activity>
        <activity
            android:name="some.package.BuddyListActivity"
            android:configChanges="keyboardHidden|orientation"
            android:label="@string/app_name"
            android:screenOrientation="user"
            android:theme="@android:style/Theme.Black.NoTitleBar" >

            <!--
            <intent-filter>
                <action android:name="android.intent.action.MAIN" />
                <category android:name="android.intent.category.LAUNCHER" />
            </intent-filter>
            -->
        </activity>
        <activity
            android:name="some.package.SessionWindowActivity"
            android:configChanges="keyboardHidden|orientation"
            android:label="@string/app_name"
            android:screenOrientation="user"
            android:theme="@android:style/Theme.Black.NoTitleBar" >

            <!--
            <intent-filter>
                <action android:name="android.intent.action.MAIN" />

                <category android:name="android.intent.category.LAUNCHER" />
            </intent-filter>
            -->
        </activity>
    </application>

</manifest>

EDIT I just saw following output in LogCat after using CheckJNI,

06-26 17:27:30.023: I/remove(24544): Sending Signal : 13 **//App Working fine here**
06-26 17:27:32.148: D/dalvikvm(24544): GC_CONCURRENT freed 446K, 49% free 3384K/6599K, external 1057K/1076K, paused 3ms+4ms
06-26 17:27:39.531: W/dalvikvm(24544): **HeapWorker may be wedged: 7374ms spent** inside LsomePackageName/modules/AudioPlayer;.finalize()V
06-26 17:27:40.023: I/remove(24544): Sending Signal : 13
06-26 17:27:40.218: D/dalvikvm(24544): GC_CONCURRENT freed 479K, 49% free 3383K/6599K, external 1057K/1076K, paused 9ms+5ms 
06-26 17:27:42.343: E/RoobrooApp(24670): Application Instance created **//Restarted** 
06-26 17:27:42.351: I/ApplicationPackageManager(24670): cscCountry is not German : INS

UPDATE While experimenting further at one step I intentionally allocated a very large memory for a double array. But to my surprise neither onLowMemory() called nor the App restarted instead I got outOfMemoryException. If onLowMemory() is never called why it is there ?

One more problem is that after restart OS already starts BuddyListActivity instead of LoginActivity... Help really needed ....

UPDATE 2 I just saw following error log, I really don't know what that means..

06-29 12:07:28.398: W/dalvikvm(19308): ReferenceTable overflow (max=1024)
06-29 12:07:28.398: W/dalvikvm(19308): Last 10 entries in JNI pinned array reference table:
06-29 12:07:28.398: W/dalvikvm(19308):  1014: 0x405b0280 cls=[B (340 bytes)
06-29 12:07:28.398: W/dalvikvm(19308):  1015: 0x405b03d8 cls=[S (660 bytes)
06-29 12:07:28.398: W/dalvikvm(19308):  1016: 0x405d8208 cls=[B (340 bytes)
06-29 12:07:28.398: W/dalvikvm(19308):  1017: 0x405d8360 cls=[S (660 bytes)
06-29 12:07:28.398: W/dalvikvm(19308):  1018: 0x405f8b08 cls=[B (340 bytes)
06-29 12:07:28.398: W/dalvikvm(19308):  1019: 0x405f8c60 cls=[S (660 bytes)
06-29 12:07:28.398: W/dalvikvm(19308):  1020: 0x405f8ef8 cls=[B (340 bytes)
06-29 12:07:28.398: W/dalvikvm(19308):  1021: 0x405ff698 cls=[S (660 bytes)
06-29 12:07:28.398: W/dalvikvm(19308):  1022: 0x405f9050 cls=[B (340 bytes)
06-29 12:07:28.398: W/dalvikvm(19308):  1023: 0x405ff930 cls=[S (660 bytes)
06-29 12:07:28.398: W/dalvikvm(19308): JNI pinned array reference table summary (1024 entries):
06-29 12:07:28.398: W/dalvikvm(19308):     1 of [B 20B
06-29 12:07:28.398: W/dalvikvm(19308):   508 of [B 340B (508 unique)
06-29 12:07:28.398: W/dalvikvm(19308):     3 of [B 348B (3 unique)
06-29 12:07:28.406: W/dalvikvm(19308):   511 of [S 660B (511 unique)
06-29 12:07:28.406: W/dalvikvm(19308):     1 of [S 668B
06-29 12:07:28.406: W/dalvikvm(19308): Memory held directly by tracked refs is 511712 bytes
06-29 12:07:28.406: E/dalvikvm(19308): Failed adding to JNI pinned array ref table (1024 entries)
06-29 12:07:28.406: I/dalvikvm(19308): "Thread-14" prio=5 tid=12 RUNNABLE
06-29 12:07:28.406: I/dalvikvm(19308):   | group="main" sCount=0 dsCount=0 obj=0x4050e548 self=0x2240b8
06-29 12:07:28.406: I/dalvikvm(19308):   | sysTid=19953 nice=-19 sched=0/0 cgrp=[fopen-error:2] handle=1905240
06-29 12:07:28.406: I/dalvikvm(19308):   | schedstat=( 207153329 82244881 1015 )
06-29 12:07:28.406: I/dalvikvm(19308):   at some.package.MyApp.speex.SpeexEncoder.encode(Native Method)
06-29 12:07:28.406: I/dalvikvm(19308):   at some.package.MyApp.speex.SpeexEncoder.encodeFrame(SpeexEncoder.java:51)
06-29 12:07:28.406: I/dalvikvm(19308):   at some.package.MyApp.models.Session.capturedAudioReceived(Session.java:656)
06-29 12:07:28.406: I/dalvikvm(19308):   at some.package.MyApp.modules.AudioCapturer.run(AudioCapturer.java:118)
06-29 12:07:28.406: I/dalvikvm(19308):   at java.lang.Thread.run(Thread.java:1019)
06-29 12:07:28.406: E/dalvikvm(19308): VM aborting
06-29 12:07:29.726: W/AudioTrack(19308): obtainBuffer() track 0x1d3520 disabled, restarting
06-29 12:07:30.351: W/dalvikvm(19308): threadid=4: spin on suspend #1 threadid=1 (pcf=0)
06-29 12:07:30.898: W/AudioTrack(19308): obtainBuffer() track 0x1d3520 disabled, restarting
06-29 12:07:31.101: W/dalvikvm(19308): threadid=4: spin on suspend #2 threadid=1 (pcf=0)
06-29 12:07:31.101: I/dalvikvm(19308): "Signal Catcher" daemon prio=5 tid=4 RUNNABLE
06-29 12:07:31.101: I/dalvikvm(19308):   | group="system" sCount=0 dsCount=0 obj=0x40510490 self=0x159898
06-29 12:07:31.101: I/dalvikvm(19308):   | sysTid=19312 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1575600
06-29 12:07:31.101: I/dalvikvm(19308):   | schedstat=( 1556395 4913328 26 )
06-29 12:07:31.101: I/dalvikvm(19308):   at dalvik.system.NativeStart.run(Native Method)
06-29 12:07:31.101: I/dalvikvm(19308): "main" prio=5 tid=1 RUNNABLE
06-29 12:07:31.101: I/dalvikvm(19308):   | group="main" sCount=1 dsCount=0 obj=0x40022198 self=0xcec8
06-29 12:07:31.101: I/dalvikvm(19308):   | sysTid=19308 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=-1345006496
06-29 12:07:31.101: I/dalvikvm(19308):   | schedstat=( 5364166234 3306213349 13647 )
06-29 12:07:31.101: I/dalvikvm(19308):   at android.media.AudioTrack.native_write_short(Native Method)
06-29 12:07:31.101: I/dalvikvm(19308):   at android.media.AudioTrack.write(AudioTrack.java:943)
06-29 12:07:31.101: I/dalvikvm(19308):   at some.package.MyApp.modules.AudioPlayer.onPeriodicNotification(AudioPlayer.java:163)
06-29 12:07:31.101: I/dalvikvm(19308):   at android.media.AudioTrack$NativeEventHandlerDelegate$1.handleMessage(AudioTrack.java:1084)
06-29 12:07:31.101: I/dalvikvm(19308):   at android.os.Handler.dispatchMessage(Handler.java:99)
06-29 12:07:31.101: I/dalvikvm(19308):   at android.os.Looper.loop(Looper.java:130)
06-29 12:07:31.101: I/dalvikvm(19308):   at android.app.ActivityThread.main(ActivityThread.java:3687)
06-29 12:07:31.101: I/dalvikvm(19308):   at java.lang.reflect.Method.invokeNative(Native Method)
06-29 12:07:31.101: I/dalvikvm(19308):   at java.lang.reflect.Method.invoke(Method.java:507)
06-29 12:07:31.101: I/dalvikvm(19308):   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:867)
06-29 12:07:31.101: I/dalvikvm(19308):   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:625)
06-29 12:07:31.101: I/dalvikvm(19308):   at dalvik.system.NativeStart.main(Native Method)
06-29 12:07:31.851: W/dalvikvm(19308): threadid=4: spin on suspend #3 threadid=1 (pcf=0)
06-29 12:07:31.851: I/dalvikvm(19308): "Signal Catcher" daemon prio=5 tid=4 RUNNABLE
06-29 12:07:31.851: I/dalvikvm(19308):   | group="system" sCount=0 dsCount=0 obj=0x40510490 self=0x159898
06-29 12:07:31.851: I/dalvikvm(19308):   | sysTid=19312 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1575600
06-29 12:07:31.851: I/dalvikvm(19308):   | schedstat=( 2868652 6927485 37 )
06-29 12:07:31.851: I/dalvikvm(19308):   at dalvik.system.NativeStart.run(Native Method)
06-29 12:07:31.851: I/dalvikvm(19308): "main" prio=5 tid=1 RUNNABLE
06-29 12:07:31.851: I/dalvikvm(19308):   | group="main" sCount=1 dsCount=0 obj=0x40022198 self=0xcec8
06-29 12:07:31.851: I/dalvikvm(19308):   | sysTid=19308 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=-1345006496
06-29 12:07:31.851: I/dalvikvm(19308):   | schedstat=( 5364166234 3306213349 13647 )
06-29 12:07:32.000: I/dalvikvm(19308):   at android.media.AudioTrack.native_write_short(Native Method)
06-29 12:07:32.015: I/dalvikvm(19308):   at android.media.AudioTrack.write(AudioTrack.java:943)
06-29 12:07:32.031: I/dalvikvm(19308):   at some.package.MyApp.modules.AudioPlayer.onPeriodicNotification(AudioPlayer.java:163)
06-29 12:07:32.039: I/dalvikvm(19308):   at android.media.AudioTrack$NativeEventHandlerDelegate$1.handleMessage(AudioTrack.java:1084)
06-29 12:07:32.054: I/dalvikvm(19308):   at android.os.Handler.dispatchMessage(Handler.java:99)
06-29 12:07:32.054: I/dalvikvm(19308):   at android.os.Looper.loop(Looper.java:130)
06-29 12:07:32.062: W/AudioTrack(19308): obtainBuffer() track 0x1d3520 disabled, restarting
06-29 12:07:32.070: I/dalvikvm(19308):   at android.app.ActivityThread.main(ActivityThread.java:3687)
06-29 12:07:32.093: I/dalvikvm(19308):   at java.lang.reflect.Method.invokeNative(Native Method)
06-29 12:07:32.101: I/dalvikvm(19308):   at java.lang.reflect.Method.invoke(Method.java:507)
06-29 12:07:32.109: I/dalvikvm(19308):   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:867)
06-29 12:07:32.125: I/dalvikvm(19308):   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:625)
06-29 12:07:32.132: I/dalvikvm(19308):   at dalvik.system.NativeStart.main(Native Method)
06-29 12:07:32.890: W/dalvikvm(19308): threadid=4: spin on suspend #4 threadid=1 (pcf=0)
06-29 12:07:32.890: I/dalvikvm(19308): "Signal Catcher" daemon prio=5 tid=4 RUNNABLE
06-29 12:07:32.890: I/dalvikvm(19308):   | group="system" sCount=0 dsCount=0 obj=0x40510490 self=0x159898
06-29 12:07:32.890: I/dalvikvm(19308):   | sysTid=19312 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1575600
06-29 12:07:32.890: I/dalvikvm(19308):   | schedstat=( 5340582 316192616 59 )
06-29 12:07:32.898: I/dalvikvm(19308):   at dalvik.system.NativeStart.run(Native Method)
06-29 12:07:32.898: I/dalvikvm(19308): "main" prio=5 tid=1 RUNNABLE
06-29 12:07:32.898: I/dalvikvm(19308):   | group="main" sCount=1 dsCount=0 obj=0x40022198 self=0xcec8
06-29 12:07:32.898: I/dalvikvm(19308):   | sysTid=19308 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=-1345006496
06-29 12:07:32.898: I/dalvikvm(19308):   | schedstat=( 5364166234 3306213349 13647 )
06-29 12:07:32.929: I/dalvikvm(19308):   at android.media.AudioTrack.native_write_short(Native Method)
06-29 12:07:32.945: I/dalvikvm(19308):   at android.media.AudioTrack.write(AudioTrack.java:943)
06-29 12:07:32.953: I/dalvikvm(19308):   at some.package.MyApp.modules.AudioPlayer.onPeriodicNotification(AudioPlayer.java:163)

Solution Well the testing is still on for the changed code and everything seems positive so far.. The problem was inside JNI (I guess). @n.Collins statement "The fact that no error is reported by the JVM also indicates it caused by your native code." Was one of the most correct pointers towards the solution. I really thank all the people who answered it really helped me in some way or the other. I actually removed a set of other bugs while trying to solve this problem all thanks to the community.

Answer 1

It is hard to tell without complete source code exactly what is happening, but perhaps Romain Guy's answer here on Google Groups will help.

onLowMemory()is called when the entire system is running out of memory, not when your process is running out of memory. Each app is limited to a fixed amount of RAM (24 MB on a Nexus One for instance). If you use up these 24 MB but the system still has more RAM available, you will get anOutOfMemoryErrorbut notonLowMemory().

The 24mb limit is pretty much set in stone for applications on < Honeycomb. If you are targeting API 11 or higher you can ask for more memory by declaring that a large heap be allocated for your application. It is not mentioned in documentation but adding android:largeHeap="true" to your application tag in your Manifest.xml will do this (although it is not guaranteed).

Note: on modified firmware (custom ROMs) it is possible for that value to be lower or higher. I believe on the Samsung Galaxy Nexus it is 48mb by default, but as a general rule staying within 24mb is a safe assumption. There is also a great post on the Sony Ericsson explaining the technical differences between Gingerbread and Ice Cream Sandwich (RAM is a topic covered in-depth).

Good luck, I hope this at least helps you track down the issue.

Answer 2

The other posters have covered the out-of-memory issues. I'll just add that to debug your native code, one quick-and-dirty way is to add log messages at various checkpoints. Here's an example from one of my native cpp files:

#include <android/log.h>

...

// Set to 1 to enable debug log traces...
#define DEBUG  0

#define LOG_TAG         "yourNativeCodeLogTag"
#if DEBUG
#define LOG_ERROR(...)  __android_log_print(ANDROID_LOG_ERROR,LOG_TAG,__VA_ARGS__)
#define LOG_WARN(...)   __android_log_print(ANDROID_LOG_WARN,LOG_TAG,__VA_ARGS__)
#define LOG_INFO(...)   __android_log_print(ANDROID_LOG_INFO,LOG_TAG,__VA_ARGS__)
#define LOG_DEBUG(...)  __android_log_print(ANDROID_LOG_DEBUG,LOG_TAG,__VA_ARGS__)
#else // if !DEBUG
#define LOG_ERROR(...)  __android_log_print(ANDROID_LOG_ERROR,LOG_TAG,__VA_ARGS__)
#define LOG_WARN(...)   __android_log_print(ANDROID_LOG_WARN,LOG_TAG,__VA_ARGS__)
#define LOG_INFO(...)   
#define LOG_DEBUG(...) 
#endif // DEBUG

...

extern "C"
JNIEXPORT void JNICALL Java_com_whatever_package_YourClassName_jniInitializeLibrary(JNIEnv * env, jobject thiz, /* other irrelevant stuff here */)                 
{    
    LOG_DEBUG("Initializing native library.\n");
    ....
}

Finally, you will also need to add -llog to your LOCAL_LDLIBS variable in the relevant *.mk file. Then, you can get log messages from your native library in logcat.

UPDATE: After seeing your updates, I think you should use the above technique to pepper log messages into your native encode() method to see exactly where it's crashes.

Answer 3

I don't have enough rep to comment on other people's answers, but I think Error 454's answer is pretty close.

I had a similar problem with my own app with application restarting with no message. My problem was caused by an array overflow where I was trying to access index n+1 in an array of n objects in my native code. The fact that no error is reported by the JVM also indicates it caused by your native code.

This question: c++ Jni Reference Table overflow has a very similar error log to your update 2, further indicating that your error lies in not having matched your get and release calls.

If you don't understand what the JNI pinned reference table is, I'd like to direct your attention to the JNI Specification sections titled "Accessing Java Objects", and the following section "Accessing Primitive Arrays".

Finally, some snippets of your native code where you access primitive data arrays would be useful to help solve your problem, but in the meantime I'd like draw your attention to the final comment on the answer to ReferenceTable overflow (max=512) JNI which reads:

GetObjectArrayElement returns object with local reference on it, so you need to delete local reference. But you should do that only when you are done with array elements. So you should put DeleteLocalRef(oneDim) after releaseIntArrayElements(oneDim).

So please, double check that you have matched Get/Release calls when you access your array elements and, when you no longer need access to it, delete the local reference. It is possible that you are hitting the end of the JNI pinned reference table because you are not deleting old objects. Remember, JNI is just a c interface for Java, so you have to help out the garbage collection for your native code.

Answer 4

Based on Update #2, it is pretty clear that you have failed to unpin an array in your JNI. This means that you are using the Get<Type>ArrayElements and have failed to match 1 or more of these calls with Release<Type>ArrayElements.

As a result, the ReferenceTable is overflowing. Look for places where you are calling Get and not calling Release. For example you could be calling GetIntArrayElements but failing to call ReleaseIntArrayElements when you are finished.

Answer 5

One thing that can be the problem, is that maybe your app crashes somewhere inside the native code and this will suddenly stop your app without any message, and nothing printed in the Logcat.

I had the same problem, while trying to decode some bitmaps, android crashed somewhere inside native code and the app stops, without displaying any message.

Regarding onLowMemory() @Tom answers covers it.