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.