Closed Bug 839452 Opened 7 years ago Closed 6 years ago

Add helpful logging of DOM calls resulting in reboot/poweroff

Categories

(Firefox OS Graveyard :: General, defect)

x86_64
Linux
defect
Not set

Tracking

(Not tracked)

RESOLVED FIXED
1.2 FC (16sep)

People

(Reporter: bjacob, Assigned: bjacob)

References

Details

Attachments

(1 file)

Here's a funny story. jrmuizel and me were working on bug 834916, trying to get B2G to boot with some new gfx code. But our devices would just continuously reboot. It took us almost a week to figure why. We were running them from USB power without batteries, and B2G interpreted this absence of battery as a low-battery-level condition (isn't that a first bug?) and then decided to reboot (isn't that a second bug? i.e. shouldn't it power off in that case, like Android does?). Here's a JS stack we recorded of that happening:

I/Gecko   (  329): 0 sm_startPowerOff() ["app://system.gaiamobile.org/js/sleep_menu.js":219]
I/Gecko   (  329):     this = [object Object]
I/Gecko   (  329): 1 bm_checkBatteryDrainage() ["app://system.gaiamobile.org/js/battery_manager.js":29]
I/Gecko   (  329):     this = [object Object]
I/Gecko   (  329): 2 bm_init() ["app://system.gaiamobile.org/js/battery_manager.js":38]
I/Gecko   (  329):     this = [object Object]
I/Gecko   (  329): 3 <TOP LEVEL> ["app://system.gaiamobile.org/js/battery_manager.js":277]
I/Gecko   (  329):     this = [object Window]
I/Gecko   (  329):

Anyway, pending a discussion of whether these things are bugs, here is a patch that would at least have helped us not take too long to figure this out, by logging these calls with JS stack.
Attached patch add loggingSplinter Review
Attachment #711779 - Flags: review?(jones.chris.g)
(In reply to Benoit Jacob [:bjacob] from comment #0)
> We were running
> them from USB power without batteries, and B2G interpreted this absence of
> battery as a low-battery-level condition (isn't that a first bug?)

This is a bug, but we may be getting bad data from the APIs we're using.  Please file. 

> and then
> decided to reboot (isn't that a second bug? i.e. shouldn't it power off in
> that case, like Android does?).

Ugh, yes.  Please file.
Comment on attachment 711779 [details] [diff] [review]
add logging

This seems like a useful helper in general, although I would have some nits about it.

However, I'm not sure about the use case here.  Was attaching gdb not enough to debug this problem?  There are about 3 callers of this code, so I'm not convinced dumping the entire stack is all that useful in this code.

We also need to be exceeding careful about using a helper like this since it can expose user data.  (Not in this case, but in general.)
Attachment #711779 - Flags: review?(jones.chris.g)
(In reply to Chris Jones [:cjones] [:warhammer] from comment #3)
> Comment on attachment 711779 [details] [diff] [review]
> add logging
> 
> This seems like a useful helper in general, although I would have some nits
> about it.
> 
> However, I'm not sure about the use case here.  Was attaching gdb not enough
> to debug this problem?  There are about 3 callers of this code, so I'm not
> convinced dumping the entire stack is all that useful in this code.

No, because rebooting just caused loss of the gdbserver connection.

~ 1 person-week wasted trying to figure what was causing the connection loss, and then trying to figure why we were rebooting.

> 
> We also need to be exceeding careful about using a helper like this since it
> can expose user data.  (Not in this case, but in general.)
(In reply to Chris Jones [:cjones] [:warhammer] from comment #2)
> (In reply to Benoit Jacob [:bjacob] from comment #0)
> > We were running
> > them from USB power without batteries, and B2G interpreted this absence of
> > battery as a low-battery-level condition (isn't that a first bug?)
> 
> This is a bug, but we may be getting bad data from the APIs we're using. 
> Please file. 

bug 844974

> 
> > and then
> > decided to reboot (isn't that a second bug? i.e. shouldn't it power off in
> > that case, like Android does?).
> 
> Ugh, yes.  Please file.


bug 844998
I just wasted a *lot* of time trying to understand why my phone was boot-looping (I had taken out the battery because I needed to be able to hard reboot often, and was far from imagining that it would cause my device to boot-loop).
I spent a lot of time reading code related to whatever was coming out of logcat. I would have wasted much less time if I had had something in the logcat saying "rebooting now" (or even better, "rebooting now because [...]") which would have left we with a place to start looking.

Please, please, please, let's reconsider landing Benoit's patch before someone else wastes a week on this problem.
Comment on attachment 711779 [details] [diff] [review]
add logging

Thank you Nical :) re-requesting review now. I think that we are better off with this patch than without it.
Attachment #711779 - Flags: review?(mwu)
Comment on attachment 711779 [details] [diff] [review]
add logging

Can you make LOG_FUNCTION_AND_JS_STACK a function-like macro? It looks pretty weird. Otherwise, this seems like a good idea.

I'm not too comfortable reviewing general code in dom though - Jonas, do you mind reviewing?
Attachment #711779 - Flags: review?(mwu)
Attachment #711779 - Flags: review?(jonas)
Attachment #711779 - Flags: feedback+
https://hg.mozilla.org/integration/mozilla-inbound/rev/39a388613446
Assignee: nobody → bjacob
Target Milestone: --- → 1.2 FC (16sep)
Depends on: 1140478
You need to log in before you can comment on or make changes to this bug.