Android ANR-Broadcast Timeout

Definition


  • Ordered broadcasts

    • Intents sent by Context.sendOrderedBroadcast() are broadcasted to one receiver at a time, regardless of if they are registered by Context.registerReceiver() or AndroidManifest.xml.
    • When receivers are delivered one at a time, each receiver’s execution time is restricted by 10 seconds to prevent later receivers’ starvation.
  • Parallel broadcasts

  • Intents sent by Context.sendBroadcast() are broadcasted to receivers in an undefined order.
  • Receivers registered by Context.registerReceiver() are delivered intents at the same time, whereas receivers registered by AndroidManifest.xml are delivered one at a time to reduce overall system’s loading.
  • Intent flag
  • FLAG_EXCLUDE_STOPPED_PACKAGES: If set, this intent will NOT match any components in packages that are currently stopped. that means, if the receiver process is stopped now, the receiver process will not bring-up under this flag setting.
  • FLAG_INCLUDE_STOPPED_PACKAGES: If set, this intent will always match any components in packages that are currently stopped. that means, if the receiver process is stopped now, the receiver process will be bring-up under this flag setting.

Code flow of ANR


这里写图片描述
这里写图片描述

  • broadcast Scenario:
    这里写图片描述

Log pattern


Broadcast log pattern

  • ActivityManager: broadcast
// Parallel broadcasts:
// pid:726 sent a 'BATTERY_CHANGED' intent; it's parallel broadcast and there are 11 receivers for this intent
I ActivityManager: broadcast act=android.intent.action.BATTERY_CHANGED flg=0x60000000 from pid=726, uid=1000,parallel BR:45f90fd,u-1,size=11,replaced=0,order BR:null,size=0,resultTo=null

// Ordered broadcasts:
// pid:726 sent a 'SCREEN_OFF' intent; it's order broadcast and there are 112 receivers for this intent
I ActivityManager: broadcast act=android.intent.action.SCREEN_OFF flg=0x50000000 from pid=726, uid=1000,order BR:3dc1eef7,u-1,size=112,replaced=0
  • BroadcastQueue: Deliver
// pid:726 sent a 'wifi.SCAN_RESULTS' intent
I ActivityManager: broadcast act=android.net.wifi.SCAN_RESULTS flg=0x4000000 from pid=726, uid=1000,parallel BR:3bfa7c3b,u-1,size=4,replaced=0,order BR:null,size=0,resultTo=null

// there are 4 parallel receivers (search keyword: 3bfa7c3b, it's BroadcastRecord hash-code)
I BroadcastQueue: Deliver non-order [BG] BR@3bfa7c3b BF{11b6236e u0 RL{a579ae9 726 system/1000/u0 c9ca770}} BF{1fbf7533 u0 RL{1f71b4a2 726 system/1000/u0 2a36a06d}} BF{1a300bcb u0 RL{2bf2a69a 2199 com.google.process.location/10029/u0}} BF{271fad82 u0 RL{3f2f70cd 2199 com.google.process.location/10029/u0}}

// BF{11b6236e u0 RL{a579ae9 726 system/1000/u0 c9ca770}}
// BF{1fbf7533 u0 RL{1f71b4a2 726 system/1000/u0 2a36a06d}}
// BF{1a300bcb u0 RL{2bf2a69a 2199 com.google.process.location/10029/u0}}
// BF{271fad82 u0 RL{3f2f70cd 2199 com.google.process.location/10029/u0}}
// pid:-1 sent a 'TIME_TICK' order broadcast, and there are 6 receivers
 726   977 I ActivityManager: broadcast act=android.intent.action.TIME_TICK flg=0x50000004 from pid=-1, uid=1000,order BR:27bfce76,u-1,size=6,replaced=0

// deliver to 1st, system(pid:726) (search keyword: 27bfce76, it's BroadcastRecord hash-code)
 726   755 I BroadcastQueue: Deliver order [FG] BF{284db6ba u0 RL{32477be5 726 system/1000/u0 1fe3bedc}}:BR@27bfce76
 726   726 V Perf    : com.android.server.AlarmManagerService$ClockReceiver@1fe3bedc onReceive:android.intent.action.TIME_TICK, 1ms    // pid:726 onReceive() completed in 1ms

// deliver to 2nd, systemui(pid:1034) (search keyword: 27bfce76, it's BroadcastRecord hash-code)
 726   726 I BroadcastQueue: Deliver order [FG] BF{a586775 u0 RL{1dddeac 1034 com.android.systemui/10052/u0}}:BR@27bfce76
1034  1034 V Perf    : com.htc.lockscreen.keyguard.KeyguardUpdateMonitor$2@620726e onReceive:android.intent.action.TIME_TICK, 0ms    // pid:1034 onReceive() completed in 0ms

// deliver to 3rd, systemui(pid:1034) (search keyword: 27bfce76, it's BroadcastRecord hash-code)
 726  1439 I BroadcastQueue: Deliver order [FG] BF{2f06c36d u0 RL{f4ccf84 1034 com.android.systemui/10052/u0}}:BR@27bfce76
1034  1034 V Perf    : com.htc.lockscreen.util.KeyguardIndicationController$2@cbd28a8 onReceive:android.intent.action.TIME_TICK, 1ms    // pid:1034 onReceive() completed in 1ms

...others...

Broadcast log pattern (MTK)

  • Pattern 1
// AMS got a request to broadcast intent
01-01 08:09:00.000   670   990 V ActivityManager: Broadcast: Intent { act=android.intent.action.TIME_TICK flg=0x50000014 (has extras) } ordered=true userid=-1 callerApp=null

// AMS schedules to broadcast intent to 1st app (pid:670).
01-01 08:09:00.004   670   716 D BroadcastQueue: BDC-Delivered broadcast: Intent { act=android.intent.action.TIME_TICK flg=0x50000014 (has extras) }, ordered=true, filter=BroadcastFilter{22568769 u0 ReceiverList{2fc975f0 670 system/1000/u0 local:20a67e33}}, receiver=android.app.LoadedApk$ReceiverDispatcher$InnerReceiver@20a67e33
01-01 08:09:00.005   670   670 D ActivityThread: BDC-Calling onReceive: intent=Intent { act=android.intent.action.TIME_TICK flg=0x50000014 (has extras) }, ordered=true, receiver=com.android.server.AlarmManagerService$ClockReceiver@10db41a2, IIntentReceiver=20a67e33    // app (pid:670) received this intent
01-01 08:09:00.006   670   670 D ActivityThread: BDC-Calling finishReceiver: IIntentReceiver=20a67e33    // app (pid:670) finished onReceive
01-01 08:09:00.006   670   670 D ActivityManager: BDC-Finishing receiver: android.app.LoadedApk$ReceiverDispatcher$InnerReceiver@20a67e33    // AMS is notified that application done receiver execution.

// AMS schedules to broadcast intent to 2nd app (pid:1043).
01-01 08:09:00.008   670   670 D BroadcastQueue: BDC-Delivered broadcast: Intent { act=android.intent.action.TIME_TICK flg=0x50000014 (has extras) }, ordered=true, filter=BroadcastFilter{c59798e u0 ReceiverList{19f7f589 1043 com.android.systemui/10015/u0 remote:27b14890}}, receiver=android.os.BinderProxy@27b14890
01-01 08:09:00.011  1043  1043 D ActivityThread: BDC-Calling onReceive: intent=Intent { act=android.intent.action.TIME_TICK flg=0x50000014 (has extras) }, ordered=true, receiver=com.android.keyguard.KeyguardUpdateMonitor$2@2ee2a814, IIntentReceiver=1f9f24a9
01-01 08:09:00.011  1043  1043 D ActivityThread: BDC-Calling finishReceiver: IIntentReceiver=1f9f24a9
01-01 08:09:00.012   670  1792 D ActivityManager: BDC-Finishing receiver: android.os.BinderProxy@27b14890

// AMS schedules to broadcast intent to 3rd app (pid:1990).
01-01 08:09:00.157   670  1456 D BroadcastQueue: BDC-Delivered broadcast: Intent { act=android.intent.action.TIME_TICK flg=0x50000014 (has extras) }, ordered=true, filter=BroadcastFilter{9a85e99 u0 ReceiverList{354c6be0 1990 com.android.launcher/10010/u0 remote:1f84d5e3}}, receiver=android.os.BinderProxy@1f84d5e3
01-01 08:09:00.158  1990  1990 D ActivityThread: BDC-Calling onReceive: intent=Intent { act=android.intent.action.TIME_TICK flg=0x50000014 (has extras) }, ordered=true, receiver=android.widget.AnalogClock$1@3a2ccbae, IIntentReceiver=1ed8a3b8
01-01 08:09:00.161  1990  1990 D ActivityThread: BDC-Calling finishReceiver: IIntentReceiver=1ed8a3b8
01-01 08:09:00.163   670  1456 D ActivityManager: BDC-Finishing receiver: android.os.BinderProxy@1f84d5e3
  • Pattern 2
// AMS got a request to broadcast intent
01-01 08:08:54.890   670   727 V ActivityManager: Broadcast: Intent { act=android.intent.action.PACKAGE_ADDED dat=package:com.mtk.anrmechanismtesting flg=0x4000010 (has extras) } ordered=false userid=0 callerApp=null

// AMS schedules to broadcast intent to 1st app (pid:3216).
01-01 08:08:54.934   670   716 D BroadcastQueue: BDC-Delivered broadcast: Intent { act=android.intent.action.PACKAGE_ADDED dat=package:com.mtk.anrmechanismtesting flg=0x4000010 cmp=com.android.providers.contacts/.PackageIntentReceiver (has extras) }, ordered=true, app=ProcessRecord{3ae71bea 3216:android.process.acore/u0a2}, receiver=android.os.BinderProxy@2f276aa4
01-01 08:08:54.927  3216  3216 D ActivityThread: BDC-Calling onReceive: intent=Intent { act=android.intent.action.PACKAGE_ADDED dat=package:com.mtk.anrmechanismtesting flg=0x4000010 cmp=com.android.providers.contacts/.PackageIntentReceiver (has extras) }, ordered=true, receiver=com.android.providers.contacts.PackageIntentReceiver@376d9110
01-01 08:08:54.928  3216  3216 D ActivityThread: BDC-RECEIVER handled : 0 / ReceiverData{intent=Intent { act=android.intent.action.PACKAGE_ADDED dat=package:com.mtk.anrmechanismtesting flg=0x4000010 cmp=com.android.providers.contacts/.PackageIntentReceiver (has extras) } packageName=com.android.providers.contacts resultCode=0 resultData=null resultExtras=null}
01-01 08:08:54.937   670  1867 D ActivityManager: BDC-Finishing receiver: android.os.BinderProxy@2f276aa4

// AMS schedules to broadcast intent to 2nd app (pid:2573).
01-01 08:08:54.964   670  1867 D BroadcastQueue: BDC-Delivered broadcast: Intent { act=android.intent.action.PACKAGE_ADDED dat=package:com.mtk.anrmechanismtesting flg=0x4000010 cmp=com.android.gallery3d/.app.PackagesMonitor (has extras) }, ordered=true, app=ProcessRecord{291bb754 2573:com.android.gallery3d/u0a37}, receiver=android.os.BinderProxy@11a0d6fd
01-01 08:08:55.001  2573  2573 D ActivityThread: BDC-Calling onReceive: intent=Intent { act=android.intent.action.PACKAGE_ADDED dat=package:com.mtk.anrmechanismtesting flg=0x4000010 cmp=com.android.gallery3d/.app.PackagesMonitor (has extras) }, ordered=true, receiver=com.android.gallery3d.app.PackagesMonitor@a0f0d6a
01-01 08:08:55.153  2573  2573 D ActivityThread: BDC-RECEIVER handled : 0 / ReceiverData{intent=Intent { act=android.intent.action.PACKAGE_ADDED dat=package:com.mtk.anrmechanismtesting flg=0x4000010 cmp=com.android.gallery3d/.app.PackagesMonitor$AsyncService (has extras) } packageName=com.android.gallery3d resultCode=0 resultData=null resultExtras=null}
01-01 08:08:55.153   670  1867 D ActivityManager: BDC-Finishing receiver: android.os.BinderProxy@11a0d6fd

How to check broadcast timeout


ANR’s timestamp

  • am_anr @ eventlog
  • BroadcastQueue: Timeout of broadcast @ devicelog
@device-log
W BroadcastQueue: Timeout of broadcast BroadcastRecord{48ab67c8 u-1 android.net.conn.CONNECTIVITY_CHANGE callingPid=921 callingUid=1000} - receiver=android.os.BinderProxy@488a5c10
W BroadcastQueue: Receiver during timeout: ResolveInfo{48a846c8 com.tencent.mm/.booter.MMReceivers$ConnectionReceiver m=0x108000}
...
E ActivityThread: MSG: Dump looper, process: com.tencent.mm:push
E ActivityThread: MSG: ===== Message History (Most recent to least recent) =====
...
E ActivityManager: ANR in com.tencent.mm:push, time=4391605
E ActivityManager: PID: 32154
E ActivityManager: Reason: Broadcast of Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 cmp=com.tencent.mm/.booter.MMReceivers$ConnectionReceiver (has extras) }
E ActivityManager: Load: 13.96 / 14.42 / 16.21
E ActivityManager: CPU usage from 10394ms to 0ms ago:

@event-log
I am_anr  : [0,32154,com.tencent.mm:push,9485892,Broadcast of Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 cmp=com.tencent.mm/.booter.MMReceivers$ConnectionReceiver (has extras) }]

when this broadcast intent deliver

  • ActivityManager: broadcast: AMS broadcast the intent
  • BroadcastQueue: Deliver: broadcast deliver the intent to receivers
// AMS broadcast this intent(android.intent.action.SCREEN_ON) at 18:17:50.967; and there are 42 order broadcast receivers
10-30 18:17:50.967   669   690 I ActivityManager: broadcast act=android.intent.action.SCREEN_ON flg=0x50000000 from pid=669, uid=1000,order BR:430eb370,u-1,size=42,replaced=0


// the broadcast record (BR:430eb370) delivered log...
10-30 18:17:50.967   669   768 I BroadcastQueue: Deliver order [FG] BF{41e6c178 u0 RL{41e7a5d0 669 system/1000/u0 local:41e90be8}}:BR@430eb370
10-30 18:17:51.017   669   690 I BroadcastQueue: Deliver order [FG] BF{42485c50 u0 RL{42485bd0 669 system/1000/u0 local:42485a38}}:BR@430eb370
10-30 18:17:51.037   669   690 I BroadcastQueue: Deliver order [FG] BF{4257c788 u0 RL{4257c708 669 system/1000/u0 local:4257c570}}:BR@430eb370
...
10-30 18:18:02.179   669   768 I BroadcastQueue: Deliver order [FG] BF{4437d0f8 u0 RL{42e7ebe0 10322 com.babytree.apps.pregnancy:pushservice/10408/u0 remote:439e4508}}:BR@430eb370
10-30 18:18:02.199   669   768 I BroadcastQueue: Deliver order [FG] BF{437b3030 u0 RL{437ac638 1309 com.funcity.taxi.driver/10412/u0 remote:434d4408}}:BR@430eb370


// broadcast this intent to 'RL{42cf82f0 10322 com.babytree.apps.pregnancy:pushservice/10408/u0 remote:42741340}}' this receiver, after 10sec timeout happened
10-30 18:17:52.169   669  1239 I BroadcastQueue: Deliver order [FG] BF{42cf8370 u0 RL{42cf82f0 10322 com.babytree.apps.pregnancy:pushservice/10408/u0 remote:42741340}}:BR@430eb370
...
10-30 18:18:02.179   669   768 W BroadcastQueue: Timeout of broadcast BroadcastRecord{430eb370 u-1 android.intent.action.SCREEN_ON callingPid=669 callingUid=1000} - receiver=android.os.BinderProxy@42741340
  • 2
    点赞
  • 3
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
ANR(Application Not Responding)错误是指应用程序在主线程上执行了太多的工作,导致界面无法响应用户的事件,从而出现了“应用程序无响应”的错误提示。在这种情况下,如果您的应用程序正在执行服务,那么该错误可能是由于服务执行超时导致的。 以下是解决这个问题的一些方法: 1. 使用IntentService: IntentService 是一种专门用于执行异步任务的服务。它可以在后台执行任务,并在完成任务后自动停止。使用 IntentService 可以避免在主线程上执行任务,从而避免 ANR 错误。 2. 使用线程池:如果您的应用程序需要在服务中执行大量的异步任务,可以使用线程池来管理这些任务。线程池可以在后台执行任务,并控制任务的数量和执行顺序,从而避免在主线程上执行过多的工作。 3. 使用HandlerThread:HandlerThread 是一种特殊的线程,它可以接收消息并在消息队列中处理这些消息。使用 HandlerThread 可以在后台执行任务,并避免在主线程上执行过多的工作。 4. 使用JobScheduler:JobScheduler 是一种 Android 系统提供的调度服务,它可以在特定的时间间隔或特定的条件下执行任务。使用 JobScheduler 可以避免在主线程上执行任务,并在系统空闲时执行任务,从而避免 ANR 错误。 请注意,如果您的应用程序需要执行长时间运行的任务,最好将这些任务移到后台线程中执行,以避免 ANR 错误。同时,还应该尽可能地优化代码,避免在主线程上执行过多的工作。
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值