Android Question App does not respond - Wait or Close ?

Discussion in 'Android Questions' started by Geritt Schlag, Jun 24, 2015.

  1. Geritt Schlag

    Geritt Schlag Member Licensed User

    Hello everyone,
    exactly the problem I have sometimes with my app.
    I opened an Activity and do nothing, then after about 1 minute exactly this message.

    "App does not respond. Do you want to close the app?" Wait or OK

    Click to "Wait", I can continue to work normally.

    The problem occurs very rarely on some devices, on some other device almost constantly (tablet).
    I find no approach to eliminate it.

    Unfortunately I can't send the code, it is not private.

    The sequence in words:

    In the foreground, my app runs with a variety of Activities.

    Parallel I use a service, which tests for the presence of WiFi, the correct connection to the pre-Fi, etc. for the presence of link to a host computer on the network
    If the connection to the host computer exists, the service sends every 5 sec. Asynchronously a string to the host computer by the motto: "I'm still here" and gets an answer.

    And with the help of Klaus, I have found this error in the LOG:

    06-23 14:25:08.925: E/ActivityManager(635): writeStringToFile error: /sys/kernel/debug/binder/transaction_log_enable java.io.FileNotFoundException: /sys/kernel/debug/binder/transaction_log_enable: open failed: ENOENT (No such file or directory)
    06-23 14:25:09.518: E/Sensors(635): poll() failed (Interrupted system call)
    06-23 14:25:12.960: E/Sensors(635): poll() failed (Interrupted system call)
    06-23 14:25:14.592: E/ANRManager(635): ANR in provendis.gastrokasse.mobil
    06-23 14:25:14.592: E/ANRManager(635): Reason: Executing service provendis.gastrokasse.mobil/.loadorders
    06-23 14:25:14.592: E/ANRManager(635): Load: 6.33 / 6.51 / 6.6
    06-23 14:25:14.592: E/ANRManager(635): Android time :[2015-06-23 14:25:14.590] [24835,758]
    06-23 14:25:14.592: E/ANRManager(635): CPU usage from 0ms to 5690ms later:
    06-23 14:25:14.592: E/ANRManager(635): 26% 635/system_server: 22% user + 3.5% kernel / faults: 865 minor
    06-23 14:25:14.592: E/ANRManager(635): 4% 152/adbd: 1% user + 2.9% kernel / faults: 154 minor
    06-23 14:25:14.592: E/ANRManager(635): 2.2% 19066/logcat: 0.8% user + 1.4% kernel
    06-23 14:25:14.592: E/ANRManager(635): 1.4% 710/com.android.systemui: 1.2% user + 0.1% kernel / faults: 9 minor
    06-23 14:25:14.592: E/ANRManager(635): 0.6% 847/com.android.phone: 0.4% user + 0.1% kernel / faults: 1 minor
    06-23 14:25:14.592: E/ANRManager(635): 1% 22485/provendis.gastrokasse.mobil: 0.7% user + 0.3% kernel / faults: 24 minor
    06-23 14:25:14.592: E/ANRManager(635): 0.7% 23669/kworker/0:0: 0% user + 0.7% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0% 859/com.mediatek.bluetooth: 0% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0.1% 48/bat_thread_kthr: 0% user + 0.1% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0.1% 53/mmcqd/0: 0% user + 0.1% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0.3% 59/disp_config_upd: 0% user + 0.3% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0.3% 120/surfaceflinger: 0.3% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0% 866/com.acer.android.liveupdater: 0% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0% 49/mtk charger_hv_: 0% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0% 106/healthd: 0% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0% 114/debuggerd: 0% user + 0% kernel / faults: 48 minor
    06-23 14:25:14.592: E/ANRManager(635): 0% 151/em_svr: 0% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): 0.1% 23030/kworker/u:2: 0% user + 0.1% kernel
    06-23 14:25:14.592: E/ANRManager(635): +0% 23716/migration/1: 0% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): +0% 23718/kworker/1:0: 0% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): +0% 23719/ksoftirqd/1: 0% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): +0% 23720/kworker/1:1: 0% user + 0% kernel
    06-23 14:25:14.592: E/ANRManager(635): 26% TOTAL: 17% user + 8.6% kernel
    06-23 14:25:14.594: E/ActivityManager(635): get crashInfo fail.
    ----------------------------------------------------------------------------------------------------------------------------
    06-23 14:20:54.772: E/Activity(22485): monkey test icicle = null , mComponent = provendis.gastrokasse.mobil
    06-23 14:20:55.520: E/Sensors(635): poll() failed (Interrupted system call)
    06-23 14:20:56.969: E/ANRManager(635): ANR in provendis.gastrokasse.mobil
    06-23 14:20:56.969: E/ANRManager(635): Reason: Executing service provendis.gastrokasse.mobil/.loadorders
    06-23 14:20:56.969: E/ANRManager(635): Load: 6.44 / 6.47 / 6.62
    06-23 14:20:56.969: E/ANRManager(635): Android time :[2015-06-23 14:20:56.966] [24578,135]
    06-23 14:20:56.969: E/ANRManager(635): CPU usage from 397ms to -5168ms ago with 99% awake:
    06-23 14:20:56.969: E/ANRManager(635): 45% 22485/provendis.gastrokasse.mobil: 40% user + 5.5% kernel / faults: 931 minor 1 major
    06-23 14:20:56.969: E/ANRManager(635): 38% 635/system_server: 31% user + 7% kernel / faults: 1317 minor
    06-23 14:20:56.969: E/ANRManager(635): 9.6% 152/adbd: 1.7% user + 7.8% kernel / faults: 122 minor
    06-23 14:20:56.969: E/ANRManager(635): 7.1% 120/surfaceflinger: 2.6% user + 4.4% kernel / faults: 4 minor
    06-23 14:20:56.969: E/ANRManager(635): 6.4% 19066/logcat: 2.3% user + 4.1% kernel
    06-23 14:20:56.969: E/ANRManager(635): 5.7% 710/com.android.systemui: 5% user + 0.7% kernel / faults: 12 minor
    06-23 14:20:56.969: E/ANRManager(635): 1.6% 847/com.android.phone: 1% user + 0.5% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.8% 20623/kworker/0:3: 0% user + 0.8% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.7% 23052/kworker/1:1: 0% user + 0.7% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.5% 21452/kworker/u:3: 0% user + 0.5% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.3% 47/ion_mm_heap: 0% user + 0.3% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0% 859/com.mediatek.bluetooth: 0% user + 0% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0% 866/com.acer.android.liveupdater: 0% user + 0% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.1% 53/mmcqd/0: 0% user + 0.1% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.1% 59/disp_config_upd: 0% user + 0.1% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.1% 61/disp_ovl_kthrea: 0% user + 0.1% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.1% 68/mtk-tpd: 0% user + 0.1% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.1% 758/tx_thread: 0% user + 0.1% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0% 807/wpa_supplicant: 0% user + 0% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0% 5999/com.google.android.inputmethod.latin: 0% user + 0% kernel
    06-23 14:20:56.969: E/ANRManager(635): 0.1% 23030/kworker/u:2: 0% user + 0.1% kernel
    06-23 14:20:56.969: E/ANRManager(635): 65% TOTAL: 45% user + 19% kernel + 0.3% iowait + 0% softirq
    06-23 14:20:56.970: E/ActivityManager(635): get crashInfo fail.
    06-23 14:20:56.974: E/ActivityManager(635): writeStringToFile error: /sys/kernel/debug/tracing/tracing_on java.io.FileNotFoundException: /sys/kernel/debug/tracing/tracing_on: open failed: ENOENT (No such file or directory)
    06-23 14:20:56.975: E/ActivityManager(635): writeStringToFile error: /sys/kernel/debug/binder/transaction_log_enable java.io.FileNotFoundException: /sys/kernel/debug/binder/transaction_log_enable: open failed: ENOENT (No such file or directory)
    06-23 14:20:57.015: E/ActivityManager(635): writeStringToFile error: /sys/kernel/debug/tracing/tracing_on java.io.FileNotFoundException: /sys/kernel/debug/tracing/tracing_on: open failed: ENOENT (No such file or directory)
    06-23 14:20:57.016: E/ActivityManager(635): writeStringToFile error: /sys/kernel/debug/binder/transaction_log_enable java.io.FileNotFoundException: /sys/kernel/debug/binder/transaction_log_enable: open failed: ENOENT (No such file or directory)
    06-23 14:20:57.033: E/(635): Could not open '/data/data/hotplug/cmd'
    06-23 14:20:57.035: E/(635): error : 2, No such file or directory
    06-23 14:20:57.511: E/NativeCrypto(20124): ssl=0x62c96288 cert_verify_callback x509_store_ctx=0x6460c940 arg=0x0
    -------------------------------------------------------------------------------------------------------------------------


    06-23 16:09:24.788: E/Sensors(638): poll() failed (Interrupted system call)
    06-23 16:09:26.086: E/(638): Could not open '/data/data/hotplug/cmd'
    06-23 16:09:26.086: E/(638): error : 2, No such file or directory
    06-23 16:09:27.055: E/(638): Could not open '/data/data/hotplug/cmd'
    06-23 16:09:27.055: E/(638): error : 2, No such file or directory
    06-23 16:09:27.143: E/(638): Could not open '/data/data/hotplug/cmd'
    06-23 16:09:27.144: E/(638): error : 2, No such file or directory
    06-23 16:09:27.801: E/Sensors(638): poll() failed (Interrupted system call)
    06-23 16:09:29.152: E/(638): Could not open '/data/data/hotplug/cmd'
    06-23 16:09:29.152: E/(638): error : 2, No such file or directory
    06-23 16:09:29.219: E/ANRManager(638): ANR in provendis.gastrokasse.mobil
    06-23 16:09:29.219: E/ANRManager(638): Reason: Executing service provendis.gastrokasse.mobil/.loadorders
    06-23 16:09:29.219: E/ANRManager(638): Load: 6.96 / 6.87 / 6.89
    06-23 16:09:29.219: E/ANRManager(638): Android time :[2015-06-23 16:09:29.211] [3367,105]
    06-23 16:09:29.219: E/ANRManager(638): CPU usage from 5140ms to 24ms ago:
    06-23 16:09:29.219: E/ANRManager(638): 78% 5366/provendis.gastrokasse.mobil: 72% user + 6.8% kernel / faults: 2877 minor
    06-23 16:09:29.219: E/ANRManager(638): 21% 153/adbd: 4.6% user + 16% kernel
    06-23 16:09:29.219: E/ANRManager(638): 8.2% 638/system_server: 5.2% user + 2.9% kernel / faults: 153 minor
    06-23 16:09:29.219: E/ANRManager(638): 7.6% 121/surfaceflinger: 4.2% user + 3.3% kernel / faults: 2 minor
    06-23 16:09:29.219: E/ANRManager(638): 6.6% 5914/logcat: 2.1% user + 4.4% kernel
    06-23 16:09:29.219: E/ANRManager(638): 6% 5381/logcat: 1.9% user + 4.1% kernel / faults: 1 minor
    06-23 16:09:29.219: E/ANRManager(638): 0.1% 5677/kworker/0:2: 0% user + 0.1% kernel
    06-23 16:09:29.219: E/ANRManager(638): 1.1% 711/com.android.systemui: 0.7% user + 0.3% kernel / faults: 6 minor
    06-23 16:09:29.219: E/ANRManager(638): 1.1% 859/com.android.phone: 0.9% user + 0.1% kernel
    06-23 16:09:29.219: E/ANRManager(638): 1.1% 6038/kworker/1:1: 0% user + 1.1% kernel
    06-23 16:09:29.219: E/ANRManager(638): 0.7% 4963/kworker/0:0: 0% user + 0.7% kernel
    06-23 16:09:29.219: E/ANRManager(638): 0.5% 5024/kworker/u:0: 0% user + 0.5% kernel
    06-23 16:09:29.219: E/ANRManager(638): 0.3% 61/disp_ovl_kthrea: 0% user + 0.3% kernel
    06-23 16:09:29.219: E/ANRManager(638): 0.3% 611/rild: 0.3% user + 0% kernel
    06-23 16:09:29.219: E/ANRManager(638): 0.1% 1//init: 0% user + 0.1% kernel
    06-23 16:09:29.219: E/ANRManager(638): 0.1% 59/disp_config_upd: 0% user + 0.1% kernel
    06-23 16:09:29.219: E/ANRManager(638): 0% 123/aal: 0% user + 0% kernel
    06-23 16:09:29.219: E/ANRManager(638): 0.1% 5810/kworker/u:2: 0% user + 0.1% kernel
    06-23 16:09:29.219: E/ANRManager(638): 70% TOTAL: 47% user + 21% kernel + 0.8% iowait
    06-23 16:09:29.221: E/ActivityManager(638): get crashInfo fail.
    06-23 16:09:29.237: E/(638): Could not open '/data/data/hotplug/cmd'
    06-23 16:09:29.237: E/(638): error : 2, No such file or directory
    06-23 16:09:29.242: E/Activity(5366): monkey test icicle = null , mComponent = provendis.gastrokasse.mobil
    06-23 16:09:37.371: E/CellLocation(638): create GsmCellLocation
    06-23 16:09:37.373: E/CellLocation(843): create GsmCellLocation
    06-23 16:09:37.378: E/MtkAgps(638): [MtkAgpsManagerService][agps] ERR: imsi=null is invalid on SIM=1
    06-23 16:09:37.388: E/CellLocation(843): create GsmCellLocation
    06-23 16:09:37.399: E/CellLocation(638): create GsmCellLocation
     
  2. Erel

    Erel Administrator Staff Member Licensed User

    Can you post the service code (or some of it which might be relevant)?

    Are you seeing it in release mode?
     
  3. Geritt Schlag

    Geritt Schlag Member Licensed User

    Yes, i see this in release mode.

    I separate the service code. But I'm not sure if this is enough to find the error.
    Difficult, the project to dismember.
     

    Attached Files:

    Last edited: Jun 24, 2015
  4. Geritt Schlag

    Geritt Schlag Member Licensed User

    And here the other service from the error message.
     

    Attached Files:

  5. Geritt Schlag

    Geritt Schlag Member Licensed User

    And here is only ANR-filter-LOG
     

    Attached Files:

  6. Geritt Schlag

    Geritt Schlag Member Licensed User

    And now the complete Log with error
     

    Attached Files:

  7. Erel

    Erel Administrator Staff Member Licensed User

    The problem might be here:

    Do While (g_InData.Length > 0) And (nI < 2) Then

    Add some log messages so you can see where it hangs.
     
  8. sorex

    sorex Expert Licensed User

    that was my guess too but nI increments on each loop so it should finish after 2 "rolls".

    it's hard to know where it happends without having the files to play with.
     
  9. Geritt Schlag

    Geritt Schlag Member Licensed User

    Wow! Okay, i'm doing.
     
  10. Geritt Schlag

    Geritt Schlag Member Licensed User

    Yes, for a data test missing even the opposite side: the server program.
     
  11. Geritt Schlag

    Geritt Schlag Member Licensed User


    I followed your advice and have added logs.
    Now the ANR error occurs no longer on.

    It must be a timing issue in asynchronous sending or receiving.
     
  12. Geritt Schlag

    Geritt Schlag Member Licensed User

    The Loop is correct. That's not the problem.

    The service LoadOrders is finished (Log: ** Service (loadorders) Destroy **) and some times later comes the ANR. Mysterious!!! :mad::mad:


    Can the following sequence are a problem???

    Activity 1: Start Service LoadOrders
    Start Activity2

    Activity 2: running

    Load Service Orders: stops himself with StopService (me)

    and some times later: ANR because of Service LoadOrders
     
    Last edited: Jun 25, 2015
  13. Erel

    Erel Administrator Staff Member Licensed User

    Which libraries are you using?
     
  14. Geritt Schlag

    Geritt Schlag Member Licensed User

    CollectionsExtra
    Core
    DateUtils
    Dialogs
    JavaObjects
    Jhwifi
    MasketEditText
    MLwifi
    Network
    OSLibrary
    Phone
    RandomAccessFile
    Reflection
    RichString
    RSImageProcessing
    ScrollView2D
    SQL
    StringFunctions
    StringUtils
    USB
     
  15. Erel

    Erel Administrator Staff Member Licensed User

    All that I can say is that you need to add enough log messages that will allow you to find the piece of code that hangs the main thread for too long.
     
  16. Geritt Schlag

    Geritt Schlag Member Licensed User

    Many thanks for the help so far. So I'll keep looking.
     
  17. Geritt Schlag

    Geritt Schlag Member Licensed User

    Some times not followed service_start after Service_Create and then crash the app with ANR.

    ----- test 1 -----

    ** Service (loadorders) Create **
    ** Service (loadorders) Start **
    .LoadOrderInClientDB ....................................................... SERVICE_START 1435577996488
    ** Activity (konfigstation) Pause, UserClosed = false **
    KonfigStation.Activity_Pause - LoadOrders paused ??? false existiert ? true
    .LoadOrderInClientDB ....................................................... STARTTCPCONTROL 1435577996501
    [ 9 ] : S O C K E T S : LOADORDER-Socket wurde versucht, zu öffnen 13:39:56
    ** Activity (ordersmain) Create, isFirst = false **

    ----- test 2 -----

    ** Service (loadorders) Create **
    ** Activity (konfigstation) Pause, UserClosed = false **
    KonfigStation.Activity_Pause - LoadOrders paused ??? false existiert ? true
    ** Activity (ordersmain) Create, isFirst = false **

     
    Last edited: Jun 29, 2015
  18. Erel

    Erel Administrator Staff Member Licensed User

    Can you post the code in Service_Create? You are testing it in release mode, right?
     
  19. Geritt Schlag

    Geritt Schlag Member Licensed User

    Yes, i'm testing in release mode.

    Code:
    Sub Service_Create
       StartTimer.Initialize(
    "StartTimer"200)
       StartTimer.Enabled = 
    True
       sf.Initialize
    End Sub

    Sub Service_Start (StartingIntent As Intent)
    End Sub

    Sub Service_Destroy
       SocketClosing
    End Sub

    Sub StartTimer_Tick
    Log(cMe & ".......................................................  StartTimer_Tick  ".ToUpperCase & DateTime.Now )
       Tcp_Load.Initialize (
    "TcpLoad")
       StartTimer.Enabled = 
    False
       StartTCPControl
    End Sub

    Sub StartTCPControl()
    Try
    Log(cMe & ".......................................................  StartTCPControl  ".ToUpperCase & DateTime.Now )
       Tcp_Load.Connect(Globals.g_Connection.ServerIP, 
    130001000)
       Globals.SaveLog(
    "S O C K E T S  : LOADORDER-Socket wurde versucht, zu öffnen  " & DateTime.Time(DateTime.now) , 9)
    Catch
       Globals.SaveLog( cMe & 
    ".StartTCPControl : " & LastException.Message, 0)
    End Try    
    End Sub
    And when i'm move the code vom Service_Create to Service_Start also the same.
     
  20. Erel

    Erel Administrator Staff Member Licensed User

    What is sf? What happens if you remove this line?
     
Loading...