Reputation: 2657
I am logging errors to a file on the external storage of my device. The first time I write to the file it works no problem. However, the second time I get and ANR. Here is the code:
PrintWriter writer;
try {
writer = new PrintWriter(
new FileWriter(LOG_FILE_DIR + LOG_FILE, true)
);
while(e != null){
e.printStackTrace(writer);
e = e.getCause();
}
writer.println();
writer.println("--------------------------------------------------");
writer.flush();
writer.close();
} catch (IOException ex) {
ex.printStackTrace();
}
Here is the output from /data/anr/traces.txt:
----- pid 3859 at 2013-09-02 11:26:42 -----
DALVIK THREADS: (mutexes: tll=0 tsl=0 tscl=0 ghl=0)
"AsyncTask #2" prio=5 tid=19 WAIT
| group="main" sCount=1 dsCount=0 obj=0x416c6818 self=0x58260df0
| sysTid=3888 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1477254904
| state=S schedstat=( 5445000 16382000 49 ) utm=0 stm=0 core=3
at java.lang.Object.wait(Native Method)
- waiting on <0x416c6938> (a java.lang.VMThread) held by tid=19 (AsyncTask #2)
at java.lang.Thread.parkFor(Thread.java:1231)
at sun.misc.Unsafe.park(Unsafe.java:323)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
at java.lang.Thread.run(Thread.java:856)
"Thread-239" prio=5 tid=1 VMWAIT
| group="main" sCount=1 dsCount=0 obj=0x416c6990 self=0x56de3010
| sysTid=3859 nice=0 sched=0/0 cgrp=apps handle=1074619356
| state=S schedstat=( 2408747000 339367000 1739 ) utm=148 stm=92 core=3
#00 pc 00018104 /system/lib/libc.so (__futex_syscall3+8)
#01 pc 0000e41c /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
#02 pc 0000e478 /system/lib/libc.so (__pthread_cond_timedwait+60)
#03 pc 0004a4e9 /system/lib/libdvm.so
#04 pc 0003a215 /system/lib/libdvm.so
#05 pc 00048429 /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+452)
#06 pc 00000db7 /system/bin/app_process
#07 pc 0001271f /system/lib/libc.so (__libc_init+38)
#08 pc 00000ae8 /system/bin/app_process
at dalvik.system.NativeStart.run(Native Method)
"pool-1-thread-1" prio=5 tid=18 TIMED_WAIT
| group="main" sCount=1 dsCount=0 obj=0x412854d8 self=0x57fa4f80
| sysTid=3887 nice=0 sched=0/0 cgrp=apps handle=1476019712
| state=S schedstat=( 5789000 5521000 10 ) utm=0 stm=0 core=3
at java.lang.Object.wait(Native Method)
- waiting on <0x412c9f10> (a java.lang.VMThread) held by tid=18 (pool-1-thread-1)
at java.lang.Thread.parkFor(Thread.java:1231)
at sun.misc.Unsafe.park(Unsafe.java:323)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:199)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:429)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:329)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:911)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
at java.lang.Thread.run(Thread.java:856)
"Binder_3" prio=5 tid=17 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x41290dc0 self=0x58114bb0
| sysTid=3885 nice=0 sched=0/0 cgrp=apps handle=1477292960
| state=S schedstat=( 749000 177000 4 ) utm=0 stm=0 core=3
#00 pc 00016fe4 /system/lib/libc.so (__ioctl+8)
#01 pc 0002a9ad /system/lib/libc.so (ioctl+16)
#02 pc 00016ba1 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)
#03 pc 00017363 /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
#04 pc 0001b15d /system/lib/libbinder.so
#05 pc 00011267 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
#06 pc 00047657 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
#07 pc 00010dcd /system/lib/libutils.so
#08 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#09 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)
"Thread-235" prio=5 tid=16 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x412f0270 self=0x57fb1410
| sysTid=3882 nice=0 sched=0/0 cgrp=apps handle=1476072312
| state=S schedstat=( 4084000 504000 3 ) utm=0 stm=0 core=2
#00 pc 00018104 /system/lib/libc.so (__futex_syscall3+8)
#01 pc 0000e41c /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
#02 pc 0000e478 /system/lib/libc.so (__pthread_cond_timedwait+60)
#03 pc 001041f5 /system/lib/libwebcore.so
#04 pc 0032f88f /system/lib/libwebcore.so
#05 pc 0032f8eb /system/lib/libwebcore.so
#06 pc 0024e9e9 /system/lib/libwebcore.so
#07 pc 001040b3 /system/lib/libwebcore.so
#08 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#09 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)
"Thread-234" prio=5 tid=15 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x412df390 self=0x56e6adf0
| sysTid=3880 nice=0 sched=0/0 cgrp=apps handle=1457254064
| state=S schedstat=( 127952000 36864000 136 ) utm=11 stm=1 core=3
#00 pc 00017ee4 /system/lib/libc.so (epoll_wait+12)
#01 pc 0012b949 /system/lib/libchromium_net.so
#02 pc 0012b755 /system/lib/libchromium_net.so
#03 pc 000583ab /system/lib/libchromium_net.so
#04 pc 00056b13 /system/lib/libchromium_net.so (MessageLoop::RunInternal()+114)
#05 pc 00056b71 /system/lib/libchromium_net.so (MessageLoop::Run()+16)
#06 pc 000771d9 /system/lib/libchromium_net.so (base::Thread::ThreadMain()+188)
#07 pc 00076c93 /system/lib/libchromium_net.so
#08 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#09 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)
"Thread-232" prio=5 tid=12 TIMED_WAIT
| group="main" sCount=1 dsCount=0 obj=0x412c7038 self=0x586d1010
| sysTid=3878 nice=0 sched=0/0 cgrp=apps handle=1483543648
| state=S schedstat=( 144000 0 2 ) utm=0 stm=0 core=3
at java.lang.Object.wait(Native Method)
- waiting on <0x412c5c70> (a org.apache.cordova.CordovaWebView$3)
at java.lang.Object.wait(Object.java:401)
at org.apache.cordova.CordovaWebView$3.run(CordovaWebView.java:446)
at java.lang.Thread.run(Thread.java:856)
"AsyncTask #1" prio=5 tid=14 WAIT
| group="main" sCount=1 dsCount=0 obj=0x412abfc8 self=0x5a7979c8
| sysTid=3876 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1508051320
| state=S schedstat=( 3910000 23282000 28 ) utm=0 stm=0 core=1
at java.lang.Object.wait(Native Method)
- waiting on <0x412abcc8> (a java.lang.VMThread) held by tid=14 (AsyncTask #1)
at java.lang.Thread.parkFor(Thread.java:1231)
at sun.misc.Unsafe.park(Unsafe.java:323)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
at java.lang.Thread.run(Thread.java:856)
"CookieSyncManager" prio=5 tid=13 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x412a4eb8 self=0x5870ca68
| sysTid=3874 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1506000736
| state=S schedstat=( 527000 135000 3 ) utm=0 stm=0 core=3
#00 pc 00017ee4 /system/lib/libc.so (epoll_wait+12)
#01 pc 00014b09 /system/lib/libutils.so (android::Looper::pollInner(int)+96)
#02 pc 00014d71 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+104)
#03 pc 0005fc1b /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22)
#04 pc 0001e290 /system/lib/libdvm.so (dvmPlatformInvoke+112)
#05 pc 0004d489 /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+396)
#06 pc 000276a0 /system/lib/libdvm.so
#07 pc 0002b5f4 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
#08 pc 0005fdc9 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272)
#09 pc 0005fdf3 /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20)
#10 pc 0005496f /system/lib/libdvm.so
#11 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#12 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
at android.os.MessageQueue.nativePollOnce(Native Method)
at android.os.MessageQueue.next(MessageQueue.java:125)
at android.os.Looper.loop(Looper.java:124)
at android.webkit.WebSyncManager.run(WebSyncManager.java:90)
at android.webkit.CookieSyncManager.run(CookieSyncManager.java:58)
at java.lang.Thread.run(Thread.java:856)
"WebViewCoreThread" prio=5 tid=11 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x41298db8 self=0x56e477c8
| sysTid=3872 nice=0 sched=0/0 cgrp=apps handle=1489447232
| state=S schedstat=( 668477000 227888000 696 ) utm=53 stm=13 core=0
#00 pc 00017ee4 /system/lib/libc.so (epoll_wait+12)
#01 pc 00014b09 /system/lib/libutils.so (android::Looper::pollInner(int)+96)
#02 pc 00014d71 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+104)
#03 pc 0005fc1b /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22)
#04 pc 0001e290 /system/lib/libdvm.so (dvmPlatformInvoke+112)
#05 pc 0004d489 /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+396)
#06 pc 000276a0 /system/lib/libdvm.so
#07 pc 0002b5f4 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
#08 pc 0005fdc9 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272)
#09 pc 0005fdf3 /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20)
#10 pc 0005496f /system/lib/libdvm.so
#11 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#12 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
#13 pc 0000c77c <unknown>
at android.os.MessageQueue.nativePollOnce(Native Method)
at android.os.MessageQueue.next(MessageQueue.java:125)
at android.os.Looper.loop(Looper.java:124)
at android.webkit.WebViewCore$WebCoreThread.run(WebViewCore.java:920)
at java.lang.Thread.run(Thread.java:856)
"Binder_2" prio=5 tid=10 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x40ef0750 self=0x5a78e0d0
| sysTid=3871 nice=0 sched=0/0 cgrp=apps handle=1483315936
| state=S schedstat=( 4287000 1864000 13 ) utm=0 stm=0 core=2
#00 pc 00016fe4 /system/lib/libc.so (__ioctl+8)
#01 pc 0002a9ad /system/lib/libc.so (ioctl+16)
#02 pc 00016ba1 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)
#03 pc 00017363 /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
#04 pc 0001b15d /system/lib/libbinder.so
#05 pc 00011267 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
#06 pc 00047657 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
#07 pc 00010dcd /system/lib/libutils.so
#08 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#09 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)
"Binder_1" prio=5 tid=9 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x40eed3b0 self=0x400ba600
| sysTid=3870 nice=0 sched=0/0 cgrp=apps handle=1359715720
| state=S schedstat=( 6634000 4035000 15 ) utm=0 stm=0 core=0
#00 pc 00016fe4 /system/lib/libc.so (__ioctl+8)
#01 pc 0002a9ad /system/lib/libc.so (ioctl+16)
#02 pc 00016ba1 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)
#03 pc 00017363 /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
#04 pc 0001b15d /system/lib/libbinder.so
#05 pc 00011267 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
#06 pc 00047657 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
#07 pc 00010dcd /system/lib/libutils.so
#08 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#09 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)
"FinalizerWatchdogDaemon" daemon prio=5 tid=8 WAIT
| group="system" sCount=1 dsCount=0 obj=0x40ee9fd0 self=0x585bf408
| sysTid=3869 nice=0 sched=0/0 cgrp=apps handle=1490720336
| state=S schedstat=( 1012000 455000 5 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x40c8e5f0> (a java.lang.Daemons$FinalizerWatchdogDaemon)
at java.lang.Object.wait(Object.java:364)
at java.lang.Daemons$FinalizerWatchdogDaemon.waitForObject(Daemons.java:230)
at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:207)
at java.lang.Thread.run(Thread.java:856)
"FinalizerDaemon" daemon prio=5 tid=7 WAIT
| group="system" sCount=1 dsCount=0 obj=0x40ee9e20 self=0x5862d008
| sysTid=3868 nice=0 sched=0/0 cgrp=apps handle=1514179416
| state=S schedstat=( 63627000 14162000 64 ) utm=6 stm=0 core=3
at java.lang.Object.wait(Native Method)
- waiting on <0x40c7a610> (a java.lang.ref.ReferenceQueue)
at java.lang.Object.wait(Object.java:401)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:170)
at java.lang.Thread.run(Thread.java:856)
"ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
| group="system" sCount=1 dsCount=0 obj=0x40ee9cb8 self=0x587bf3c8
| sysTid=3867 nice=0 sched=0/0 cgrp=apps handle=1458334392
| state=S schedstat=( 6227000 6534000 43 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x40c7a538>
at java.lang.Object.wait(Object.java:364)
at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:130)
at java.lang.Thread.run(Thread.java:856)
"Compiler" daemon prio=5 tid=5 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x40ee9bc8 self=0x56e67810
| sysTid=3866 nice=0 sched=0/0 cgrp=apps handle=1477360488
| state=S schedstat=( 152410000 44911000 752 ) utm=9 stm=6 core=3
#00 pc 00018104 /system/lib/libc.so (__futex_syscall3+8)
#01 pc 0000e41c /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
#02 pc 0000e478 /system/lib/libc.so (__pthread_cond_timedwait+60)
#03 pc 00072c85 /system/lib/libdvm.so
#04 pc 0005405b /system/lib/libdvm.so
#05 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#06 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)
"JDWP" daemon prio=5 tid=4 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x40ee9ae0 self=0x586446c0
| sysTid=3865 nice=0 sched=0/0 cgrp=apps handle=1457404880
| state=S schedstat=( 3200000 8133000 15 ) utm=0 stm=0 core=3
#00 pc 0001710c /system/lib/libc.so (select+20)
#01 pc 00060c8b /system/lib/libdvm.so
#02 pc 0006381d /system/lib/libdvm.so
#03 pc 0005405b /system/lib/libdvm.so
#04 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#05 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)
"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
| group="system" sCount=0 dsCount=0 obj=0x40ee99e8 self=0x56e5ebe8
| sysTid=3864 nice=0 sched=0/0 cgrp=apps handle=1477364616
| state=R schedstat=( 16076000 21692000 20 ) utm=1 stm=0 core=0
at dalvik.system.NativeStart.run(Native Method)
"GC" daemon prio=5 tid=2 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x40ee9908 self=0x58a14928
| sysTid=3863 nice=0 sched=0/0 cgrp=apps handle=1489737912
| state=S schedstat=( 339909000 49610000 132 ) utm=33 stm=0 core=0
#00 pc 00018104 /system/lib/libc.so (__futex_syscall3+8)
#01 pc 0000e41c /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
#02 pc 0000e478 /system/lib/libc.so (__pthread_cond_timedwait+60)
#03 pc 00071a37 /system/lib/libdvm.so
#04 pc 0005405b /system/lib/libdvm.so
#05 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
#06 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)
NATIVE THREADS:
"WebViewCoreThre" sysTid=3875 nice=0 sched=0/0 cgrp=apps
| state=S schedstat=( 512000 0 4 ) utm=0 stm=0 core=3
"SignalSender" sysTid=3877 nice=0 sched=0/0 cgrp=apps
| state=S schedstat=( 10025000 25432000 166 ) utm=0 stm=1 core=0
"[my package id]" sysTid=3881 nice=0 sched=0/0 cgrp=apps
| state=S schedstat=( 43000 0 1 ) utm=0 stm=0 core=3
"TexturesGenerat" sysTid=3886 nice=0 sched=0/0 cgrp=apps
| state=S schedstat=( 248008000 76502000 297 ) utm=17 stm=7 core=0
----- end 3859 -----
UPDATE: I am only getting this when my handler for setUncaughtExceptionHandler is called more than once.
Upvotes: 0
Views: 796
Reputation: 1
Make your logging method synchronized to avoid problems with writing from several threads to one file
Upvotes: 0
Reputation: 2159
Doesn't seem to be a problem with your code, but note take that e.printStackTrace(writer);
already does what you want, if the Throwable
contains a cause, the method will be invoked recursively for the nested Throwable
and print the corresponding stacktrace, making your while
loop unnecessary.
You can try without the while
loop and check that there is no cycle between the exceptions (that is if e
and t
are exceptions and e.getCause()
is t
then make sure and t.getCause()
is different than e
)
Upvotes: 0