[broadcast] we have 700+ broadcasts in BroadcastQueue, what is the cause?

249 views
Skip to first unread message

junhou jiang

unread,
Feb 2, 2016, 10:15:24 AM2/2/16
to android-platform
we encounter a problem that Android does not reponse every broadcasts all the day in factory product line until we reboot with power button
can anybody help us to know why?
the attachment is all logs that we dump.

android version is kk-4.x
(1)anr
we think that traces in anr are related to the broadcast problem
(2)aosp_bugreport 
it tells us that we have 741  Active Ordered Broadcasts in foreground broadcast queue
according to the following bold text, dispatchTime=-- receiverTime=-- means 
that android does not excute BroadcastQueue.processNextBroadcast(boolean fromMsg), for these two fields are assigned in method processNextBroadcast()
so we think that these broadcasts aren't sent by mHandler?

  Active Ordered Broadcast foreground #741:
    BroadcastRecord{422ed468 u0 tv.policy.SYSTEM_KEY} to user 0
    Intent { act=tv.policy.SYSTEM_KEY flg=0x10000010 (has extras) }
      extras: Bundle[{android.intent.extra.KEY_EVENT=25, volume_ctrl_key_repeated_num=5}]
    caller=android 1787:system/1000 pid=1787 uid=1000
    dispatchClockTime=Thu Jan 01 08:00:00 GMT+08:00 1970
    dispatchTime=-- receiverTime=--
    resultAbort=false ordered=true sticky=false initialSticky=false
………………
Active Ordered Broadcast foreground #0:
    BroadcastRecord{42ccdc10 u-1 android.intent.action.TIME_TICK} to user -1
    Intent { act=android.intent.action.TIME_TICK flg=0x50000014 (has extras) }
      extras: Bundle[{android.intent.extra.ALARM_COUNT=1}]
    caller=android null pid=-1 uid=1000
    dispatchClockTime=Thu Jan 01 08:00:00 GMT+08:00 1970
    dispatchTime=-- receiverTime=--
    resultTo=android.app.PendingIntent$FinishedDispatcher@42037b00 resultCode=0 resultData=null
    resultAbort=false ordered=true sticky=false initialSticky=false
    Receiver #0: BroadcastFilter{41f4eb08 u0 ReceiverList{41f569f0 1787 system/1000/u0 local:41f77fc0}}
……
  mBroadcastsScheduled [foreground]=true
  mBroadcastsScheduled [background]=false
  mHandler:
    Handler (com.android.server.am.ActivityManagerService$2) {41c4ff10} @ 61416348
      Looper (ActivityManager, tid 15) {41c4cc30}
        Message 0: { when=+11m50s106ms what=27 target=com.android.server.am.ActivityManagerService$2 }
        Message 1: { when=+27m1s830ms callback=com.android.server.AppOpsService$1 target=android.os.Handler }
        (Total messages: 2, idling=true, quitting=false)


mBroadcastsScheduled [foreground] = true indicates that BroadcastQueue will return directly,
not send message by mHandler's sendMessage() when entering scheduleBroadcastsLocked() every time

we do some tests according to the above suspected point,  making the following changes:
(a) add the property "persist.msg.missed" to simulate the problem
(b) make the return condition more stricter
method return only when the broadcast is already  scheduled  and the broadcast queue is  less than the acceptable size(10 or 30)
the modified condition is "if (mBroadcastsScheduled && mOrderedBroadcasts.size() < 30)"

 
we first use change (a) to simulate the problem, android does not reponse the broadcast when msgMissed = true
after we set persist.msg.missed = false, android still not reponse the broadcast, it looks like our problem
then we add change (b) to let the system break from the infinite loop in this case, and it seems work.
change (b) is only be helpful if mHandler.sendMessage() fails once, 
if Handler's sendMessage() malfunctions always, it still not work

if the basic method of Handler's sendMessage() malfunctions, what is the reaseon?  will it function correctly if we sendMessage again?
And Jeff Brown adds enqueue time to assess latency in android 6.0 , where can we find the description of Bug 17695520? does the bug look like ours?
commit9fb3fd1d666aac3e8d889bead4109690b1484aac[log] [tgz]
authorJeff Brown <jeff...@google.com>Mon Sep 29 15:32:12 2014 -0700
committerJeff Brown <jeff...@google.com>Tue Feb 24 19:59:16 2015 +0000
treef96ccb54c9dd2f707b81587f53dbf5c2e996338b
parent5d8a69f2774d5843704f18f6ff608edc55051e9d [diff]

what is the side effect if we remove or make the condition stricter like if (mBroadcastsScheduled && mOrderedBroadcasts.size() < 30 ) 

Look forward to all useful feedbacks and suggestions!
Thanks!

bug.zip

Anders Du

unread,
May 5, 2016, 12:04:43 PM5/5/16
to android-platform
I think i saw the same issue here, with some wifi broadcast never received.

Do you have any updated info regarding this?
Reply all
Reply to author
Forward
0 new messages