Android Question ANR Executing service

peacemaker · Sep 9, 2013

Erel,

Is there a chance to understand why my app has "ANR Executing service peacemaker.energeniepowermanager/.inet" ?

INET is my service connecting a HTTP server and parsing XML.

13 ANRs along 5 months of 2013 year, 6 pcs among them only on Samsung Galaxy S2\3\4, 2 pcs on HTC One M7 - no idea what OS version there.

3 latest dumps (2 from Galaxy S4) from Play Market log are attached.

Erel · Sep 9, 2013

How are you connecting to the server? HttpUtils2?

peacemaker · Sep 9, 2013

No, it's old software using the first version of HttpUtils (its separate URLDone and JobDone subs are convenient to get URLs group one by one parsing XML one by one).

Erel · Sep 10, 2013

Are you parsing a large XML file?

peacemaker · Sep 10, 2013

2-4 kbytes

Erel · Sep 10, 2013

You can try to add a DoEvents call in one of the parsing subs.

peacemaker · Sep 10, 2013

Thanks !
No relation to the downloading you think ?
Strange error.

Erel · Sep 10, 2013

Assuming that you are using HttpUtils or HttpUtils2 then it is not related to the downloads.

peacemaker · Sep 10, 2013

I can send more dumps from Play Market, to analize, if it may help to fix and improve B4A

peacemaker · Sep 10, 2013

Oh, Erel...
I have found that another service in this my app also gets ANR :-(
But this service was planned for working with SQLite DB, but actually now only open\close\search DB. No background activity.
Maybe it's not so related to the app :-(

B4X:

----- pid 32666 at 2013-08-31 21:56:58 -----
Cmd line: peacemaker.energeniepowermanager

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)

"main" prio=5 tid=1 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x41588b38 self=0x4010e008
| sysTid=32666 nice=0 sched=0/0 cgrp=apps handle=1075017180
| state=S schedstat=( 0 0 0 ) utm=66 stm=37 core=0
#00 pc 00018004 /system/lib/libc.so (epoll_wait+12)
#01 pc 00014d21 /system/lib/libutils.so (android::Looper::pollInner(int)+96)
#02 pc 00014f89 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+104)
#03 pc 00068e2f /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22)
#04 pc 00020210 /system/lib/libdvm.so (dvmPlatformInvoke+112)
#05 pc 0004f875 /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+396)
#06 pc 000296a0 /system/lib/libdvm.so
#07 pc 0002d7ec /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
#08 pc 00062537 /system/lib/libdvm.so (dvmInvokeMethod(Object*, Method const*, ArrayObject*, ArrayObject*, ClassObject*, bool)+374)
#09 pc 00069f79 /system/lib/libdvm.so
#10 pc 000296a0 /system/lib/libdvm.so
#11 pc 0002d7ec /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
#12 pc 00062261 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272)
#13 pc 0004be53 /system/lib/libdvm.so
#14 pc 0004fe97 /system/lib/libandroid_runtime.so
#15 pc 00051233 /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+390)
#16 pc 00000db7 /system/bin/app_process
#17 pc 0001283f /system/lib/libc.so (__libc_init+38)
#18 pc 00000ae8 /system/bin/app_process
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.app.ActivityThread.main(ActivityThread.java:5328)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:511)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1102)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:869)
at dalvik.system.NativeStart.main(Native Method)

"pool-2-thread-2" daemon prio=5 tid=13 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x427d5290 self=0x70ea9818
| sysTid=32746 nice=0 sched=0/0 cgrp=apps handle=1963316488
| state=S schedstat=( 0 0 0 ) utm=0 stm=1 core=0
#00 pc 00017c48 /system/lib/libc.so (recvfrom+20)
#01 pc 0001fe2b /system/lib/libjavacore.so
#02 pc 00020210 /system/lib/libdvm.so (dvmPlatformInvoke+112)
#03 pc 0004f875 /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+396)
#04 pc 000296a0 /system/lib/libdvm.so
#05 pc 0002d7ec /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
#06 pc 00062261 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272)
#07 pc 0006228b /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20)
#08 pc 00056e0b /system/lib/libdvm.so
#09 pc 0000e4f8 /system/lib/libc.so (__thread_entry+72)
#10 pc 0000dbe4 /system/lib/libc.so (pthread_create+160)
at libcore.io.Posix.recvfromBytes(Native Method)
at libcore.io.Posix.recvfrom(Posix.java:136)
at libcore.io.BlockGuardOs.recvfrom(BlockGuardOs.java:164)
at libcore.io.IoBridge.recvfrom(IoBridge.java:513)
at java.net.PlainSocketImpl.read(PlainSocketImpl.java:488)
at java.net.PlainSocketImpl.access$000(PlainSocketImpl.java:46)
at java.net.PlainSocketImpl$PlainSocketInputStream.read(PlainSocketImpl.java:240)
at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:103)
at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:191)
at org.apache.http.impl.conn.DefaultResponseParser.parseHead(DefaultResponseParser.java:82)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:174)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:180)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:235)
at org.apache.http.impl.conn.AbstractClientConnAdapter.receiveResponseHeader(AbstractClientConnAdapter.java:259)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:279)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:121)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:428)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:670)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:509)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:487)
at anywheresoftware.b4a.http.HttpClientWrapper$3.run(HttpClientWrapper.java:199)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:390)
at java.util.concurrent.FutureTask.run(FutureTask.java:234)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-1" daemon prio=5 tid=12 TIMED_WAIT
| group="main" sCount=1 dsCount=0 obj=0x427bb430 self=0x71c4e7b8
| sysTid=32693 nice=0 sched=0/0 cgrp=apps handle=1908729696
| state=S schedstat=( 0 0 0 ) utm=0 stm=3 core=1
at java.lang.Object.wait(Native Method)
- waiting on <0x427bb578> (a java.lang.VMThread) held by tid=12 (pool-2-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)

"[email protected]@427b4dd8" daemon prio=5 tid=11 WAIT
| group="main" sCount=1 dsCount=0 obj=0x427b7c70 self=0x71c4dfa0
| sysTid=32692 nice=0 sched=0/0 cgrp=apps handle=1908728816
| state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x427b6cb0> (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 org.apache.http.impl.conn.tsccm.RefQueueWorker.run(RefQueueWorker.java:102)
at java.lang.Thread.run(Thread.java:856)

"Binder_3" prio=5 tid=10 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x4275d280 self=0x6d268788
| sysTid=32688 nice=0 sched=0/0 cgrp=apps handle=1894377592
| state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
#00 pc 00017104 /system/lib/libc.so (__ioctl+8)
#01 pc 0002aab5 /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 0001147f /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
#06 pc 0004f513 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
#07 pc 00010fe5 /system/lib/libutils.so
#08 pc 0000e4f8 /system/lib/libc.so (__thread_entry+72)
#09 pc 0000dbe4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)

"Binder_2" prio=5 tid=9 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x426f3298 self=0x70ea5a20
| sysTid=32678 nice=0 sched=0/0 cgrp=apps handle=1831176744
| state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
#00 pc 00017104 /system/lib/libc.so (__ioctl+8)
#01 pc 0002aab5 /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 0001147f /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
#06 pc 0004f513 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
#07 pc 00010fe5 /system/lib/libutils.so
#08 pc 0000e4f8 /system/lib/libc.so (__thread_entry+72)
#09 pc 0000dbe4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)

"Binder_1" prio=5 tid=8 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x426f30b8 self=0x70ea80a0
| sysTid=32677 nice=0 sched=0/0 cgrp=apps handle=1831079680
| state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
#00 pc 00017104 /system/lib/libc.so (__ioctl+8)
#01 pc 0002aab5 /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 0001147f /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
#06 pc 0004f513 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
#07 pc 00010fe5 /system/lib/libutils.so
#08 pc 0000e4f8 /system/lib/libc.so (__thread_entry+72)
#09 pc 0000dbe4 /system/lib/libc.so (pthread_create+160)
at dalvik.system.NativeStart.run(Native Method)

"FinalizerWatchdogDaemon" daemon ...

peacemaker · Sep 24, 2014

So...
Now recent months the app (using XML downloading\parsing\SQLite) has only the single service (inet), using HttpUtils2 for downloading (not old HttpUtils).
Latest app versions were and are compiled by b4a 3.82.
ANR is still often, under Android 4.4, 4.3 and 4.2.

ANR Executing service (place is unknown), 5 dumps in file are attached.
Erel, any chance to understand what can be the reason ?

Erel · Sep 25, 2014

It is hard to say from the dumps. Are you holding the main thread with a loop in your code?

peacemaker · Sep 25, 2014

No threading used, all timers, XML parser, SQLite db are in the service, that calls Activity_Resume of the active activity to update.

Erel · Sep 25, 2014

Are you parsing large XML files? Are you doing any heavy database operations? Are you using a single transaction for these operations?

peacemaker · Sep 25, 2014

XML-pages are of various size (depends on the end-user account settings), mostly 3-6 KB, maybe 30-50 pcs of SQLite fields (1-10 records in tables) per user.
Periodically (10 sec up to .... Int max ms-interval) download XML, parsing, updating the db and refreshing the activity. Not by transaction, separate SQL requests.

But about 1500 end-user accounts for Android (and i guess these or + other 1500 for Apple devices accounts). Server's internet channel is very good\stable, the server scripts were optimized recently, before there were timeouts rather often - now no timeouts if test on our side with a single test account.

No, not "huge" app and db, but stable 6-10 errors per week (only this kind of ANR), i guess, for these 1500 users.
Or is it small error rate ?

Erel · Sep 26, 2014

Try to reproduce is locally. This will allow you to understand which step takes too long. If it is the database step then you should use SQL.ExecNonQueryBatch to solve it.

Can you post the code that runs when JobDone is fired?

peacemaker · Sep 26, 2014

B4X:

Sub JobDone(Job As HttpJob)
ProgressDialogHide

If Job.Success Then
    'Log("downloaded ok, parsing start")

    Dim tr As TextReader
    tr.Initialize2(Job.GetInputStream,"UTF8")    '"Windows-1251")
    Try
    DoEvents
    XML.Parse2(tr, "Parser")
    Catch
        a = "XML-parsing error, please, inform application developers: " & Job.JobName
        others.Notif(a, False, True, Status)
        others.AddToLog(a)
        DoEvents
        others.InAppToastOnly(a,True)
        others.BugReport(a,"","")
    End Try

Else    'problem during download
    Alarm = "No internet or server connection ! (" & Job.ErrorMessage & ")"
    'Log("downloading error")
End If

If Alarm <> "" Then
    others.Notif(Alarm, False, False, Main)    'single alert
    others.AddToLog("WARNING: " & Alarm)
    others.InAppToastOnly("WARNING: " & Alarm, True)
    ProgressDialogHide
End If

Job.Release
others.CheckOnlineStatus
If SyncTimer.Enabled = False Then SyncTimer.Enabled = True
End Sub

Erel · Sep 26, 2014

Try to reproduce it locally. Use a huge XML file.

Remove all the DoEvents calls.

What is others? Maybe it blocks the main thread.

peacemaker · Sep 26, 2014

"others" is code module with common tool subs, as their name state. Thre are some looms there, but using

B4X:

If (i Mod 10) = 0 Then DoEvents

Erel · Sep 28, 2014

DoEvents in many cases will do more harm than good.

Android Question ANR Executing service

Expert

Attachments

B4X founder

Expert

B4X founder

Expert

B4X founder

Expert

B4X founder

Expert

Expert

Expert

Attachments

B4X founder

Expert

B4X founder

Expert

B4X founder

Expert

B4X founder

Expert

B4X founder