819740 - Unwanted homescreen cpu activity while in suspended state

Status: RESOLVED INVALID

(Firefox OS Graveyard :: General, defect, P1)

Description

[RamSomani:rsomani]

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:17.0) Gecko/20100101 Firefox/17.0
Build ID: 20121128204232

Steps to reproduce:

Keep the device at homescreen after boot and let it suspend (Screen is turned off). No need to connect USB. 


Actual results:

If you see top logs, homescreen plugin container shows cpu usage. Ideally, there shouldn't be any.


Expected results:

No activity from the gecko/gaia when phone is in suspended state.

Comment 1

[Michael Vines [:m1] [:evilmachines]]

A bit more detail here: we see /spikes/ in current every ~20s.  These spikes are driving the CPU up to max freq and are believed to be a major contributor to the higher-than-expected idle power numbers.

Comment 2

[Andreas Gal :gal]

Can you catch this in gdb?

Comment 3

[Michael Vines [:m1] [:evilmachines]]

Don't think we've tried.  We see this activity when the device is connected to a power meter.  Maybe just a stupid Gaia timer that needs to be cancelled or something.

Comment 4

[Doug Turner (:dougt)]

in very weak scientific sampling using top, the b2g process hit 8% usage for 3 samples over 60s.  I was using the Otoro connected using USB.  Not sure if that makes a difference.

One thing I noticed was that each time there was any higher-than-zero cpu usage, i'd see alot of rpc_handle_rpc_call logging.  I asked cjones about this, and he suggested that I'd enable RIL logging.

So, it looks like when we get a RIL message, then we pass it to the main b2g process.  This most likely is the cause for the main process waking up every 20 seconds or so.  Fwiw, the RIL events always start with a UNSOLICITED_RESPONSE_VOICE_NETWORK_STATE_CHANGED, then there are a bunch of other messages:


I/Gecko   (  647): RIL Worker: Handling parcel as UNSOLICITED_RESPONSE_VOICE_NETWORK_STATE_CHANGED
I/Gecko   (  647): RIL Worker: Handling parcel as UNSOLICITED_SIGNAL_STRENGTH
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_GET_SIM_STATUS
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_VOICE_REGISTRATION_STATE
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_DATA_REGISTRATION_STATE
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_OPERATOR
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_QUERY_NETWORK_SELECTION_MODE
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_GET_SMSC_ADDRESS
I/Gecko   (  647): RIL Worker: Handling parcel as UNSOLICITED_RESPONSE_VOICE_NETWORK_STATE_CHANGED
I/Gecko   (  647): RIL Worker: Handling parcel as UNSOLICITED_SIGNAL_STRENGTH
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_GET_SIM_STATUS
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_VOICE_REGISTRATION_STATE
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_DATA_REGISTRATION_STATE
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_OPERATOR
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_QUERY_NETWORK_SELECTION_MODE
I/Gecko   (  647): RIL Worker: Handling parcel as REQUEST_GET_SMSC_ADDRESS
I/Gecko   (  647): RIL Worker: Handling parcel as UNSOLICITED_SIGNAL_STRENGTH


I do not see the child process (plugin-container) spin up.

Thoughts?

Comment 5

[Michael Vines [:m1] [:evilmachines]]

Hey Ram,
Think we could gather a little bit more detail to help others reproduce our results?
Thanks,
Michael

Comment 6

[Doug Turner (:dougt)]

Alon, Does this bug sound similar to what you were working on a few years ago with cpu wakeups in the Fennec browser?  Maybe we can reuse what you built?

Comment 7

[Alon Zakai (:azakai)]

Not directly similar but the same approach might make sense. The tools I made back then can rewrite the tree so that each event gets printed out, and how long it took,

http://mozakai.blogspot.com/2010/09/tools-for-debugging-wakeups.html

I'm happy to help set that up, but it's possible the patches bitrotted significantly. Might be simpler to just add some code in the event running mechanism to throw a signal if the event takes >400ms, if a flag is set (and you set the flag way after startup)

Comment 8

[Doug Turner (:dougt)]

Ram, figure anything else out?  It looks pretty clear that this device is woken up about every 20s for these RIL events?  I am not familiar with RIL enough to suggest anything more than dumb ideas.

Comment 9

[Michael Vines [:m1] [:evilmachines]]

Thanks for the debug help Doug.  Was talking to Ram earlier and we've traced this down to a configuration issue on our side, very sorry about this.   No Gecko change required here!