898240 - GPS never switches off

Status: RESOLVED FIXED

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

Description

[Hubert Figuiere [:hub]]

This is a follow up of bug 871343

I run master (1.2-prerelease) on Inari and Keon.

When I start HERE Maps, it starts the GPS. Even after killing Here Maps, the GPS is still on (indicated in the status bar). This also end up draining the battery quickly.

The only solution is to restart the phone (or maybe just b2g)

Comment 1

[Hubert Figuiere [:hub]]

Build ID 20130725024045 on Keon.

Also on Inari, today's repo.

Comment 2

[Hubert Figuiere [:hub]]

This also happen with the Camera app, or third-party apps like "check-in fox"

Comment 3

[Hubert Figuiere [:hub]]

On Keon this is the nightly build from GP, then the OTA updates.

See http://downloads.geeksphone.com/keon_nightly/latest_master.html

Comment 4

[Dave Huseby [:huseby]]

I have confirmed this bug is still in the latest master: B2G 82a260f, Gecko d206ff6, Gaia 0c37488.

Comment 5

[Dave Huseby [:huseby]]

Looking at the code, it looks like the nsGeolocationService::Observe() callback has some bad logic around the handling of mozsettings-changed and timer-callbacks.  After the maps app closes, I get a couple of timer-callback calls to ::Observe() but the test for HasActiveCallbacks() is true so it sets a disconnect timer and returns.  Then I see a mozsettings-changed call to ::Observe() which processes the change and returns.  Then I don't get any more timer-callbacks.

I'm still investigating why the timer-callback chain breaks.  It could be either that, or maybe the active callbacks aren't being cleared out.

Comment 6

[Dave Huseby [:huseby]]

If I launch the maps app, then close it down, I get a few timer-callback calls to ::Observer().  If I then launch the maps app again and close it down, I don't get any at all.  This bug must be around the setting up and management of the timer-callbacks used to turn off the geolocation when nothing is using it.

Comment 7

[Dave Huseby [:huseby]]

the timer-callback problem would explain why it affects all apps that use geolocation.  investigating how those are getting set up and managed.

Comment 8

[Dave Huseby [:huseby]]

call stack for Geolocation callback setup:

#0  nsGeolocationService::AddLocator (this=0x48856ca0, aLocator=0x46bdc740) at /media/huseby/fxos/B2G/gecko/dom/src/geolocation/nsGeolocation.cpp:998
#1  0x418d5382 in mozilla::dom::Geolocation::Init (this=0x46bdc740, aContentDom=0x0) at /media/huseby/fxos/B2G/gecko/dom/src/geolocation/nsGeolocation.cpp:1082
#2  0x411d0436 in GeolocationConstructor (aOuter=0x0, aIID=..., aResult=0xbe9317b0) at /media/huseby/fxos/B2G/gecko/layout/build/nsLayoutModule.cpp:619
#3  0x42453852 in mozilla::GenericFactory::CreateInstance (this=0x4892c500, aOuter=0x0, aIID=..., aResult=0xbe9317b0) at /media/huseby/fxos/B2G/objdir-gecko-noopt/xpcom/build/GenericFactory.cpp:16
#4  0x42498052 in nsComponentManagerImpl::CreateInstanceByContractID (this=0x40421500, aContractID=0x433e646c "@mozilla.org/geolocation;1", aDelegate=0x0, aIID=..., aResult=0xbe9317b0)
    at /media/huseby/fxos/B2G/gecko/xpcom/components/nsComponentManager.cpp:1097
#5  0x42498958 in nsComponentManagerImpl::GetServiceByContractID (this=0x40421500, aContractID=0x433e646c "@mozilla.org/geolocation;1", aIID=..., result=0xbe931844)
    at /media/huseby/fxos/B2G/gecko/xpcom/components/nsComponentManager.cpp:1453
#6  0x42456010 in CallGetService (aContractID=0x433e646c "@mozilla.org/geolocation;1", aIID=..., aResult=0xbe931844)
    at /media/huseby/fxos/B2G/objdir-gecko-noopt/xpcom/build/nsComponentManagerUtils.cpp:62
#7  0x4245643e in nsGetServiceByContractID::operator() (this=0xbe931838, aIID=..., aInstancePtr=0xbe931844) at /media/huseby/fxos/B2G/objdir-gecko-noopt/xpcom/build/nsComponentManagerUtils.cpp:246
#8  0x42454dba in nsCOMPtr_base::assign_from_gs_contractid (this=0xbe931874, gs=..., iid=...) at /media/huseby/fxos/B2G/objdir-gecko-noopt/xpcom/build/nsCOMPtr.cpp:92
#9  0x41eea74a in nsCOMPtr (this=0xbe931874, gs=...) at ../../dist/include/nsCOMPtr.h:620
#10 0x41ee9550 in AddGeolocationListener (watcher=0x45c33dec, highAccuracy=false) at /media/huseby/fxos/B2G/gecko/dom/ipc/ContentParent.cpp:2492
#11 0x41ee97f4 in mozilla::dom::ContentParent::RecvAddGeolocationListener (this=0x45c33c00, aPrincipal=..., aHighAccuracy=@0xbe931ef3) at /media/huseby/fxos/B2G/gecko/dom/ipc/ContentParent.cpp:2558
#12 0x41fba280 in mozilla::dom::PContentParent::OnMessageReceived (this=0x45c33c00, __msg=...) at /media/huseby/fxos/B2G/objdir-gecko-noopt/ipc/ipdl/PContentParent.cpp:2322
#13 0x41f1d066 in mozilla::ipc::AsyncChannel::OnDispatchMessage (this=0x45c33c0c, msg=...) at /media/huseby/fxos/B2G/gecko/ipc/glue/AsyncChannel.cpp:506
#14 0x41f2732e in mozilla::ipc::RPCChannel::OnMaybeDequeueOne (this=0x45c33c0c) at /media/huseby/fxos/B2G/gecko/ipc/glue/RPCChannel.cpp:387
#15 0x41730722 in DispatchToMethod<WebCore::ReverbConvolver, void (WebCore::ReverbConvolver::*)()> (obj=0x45c33c0c, method=0x41f2714d <mozilla::ipc::RPCChannel::OnMaybeDequeueOne()>, arg=...)
    at /media/huseby/fxos/B2G/gecko/ipc/chromium/src/base/tuple.h:383
#16 0x41730694 in RunnableMethod<WebCore::ReverbConvolver, void (WebCore::ReverbConvolver::*)(), Tuple0>::Run (this=0x45062ea0) at /media/huseby/fxos/B2G/gecko/ipc/chromium/src/base/task.h:307
#17 0x41f25fa0 in mozilla::ipc::RPCChannel::RefCountedTask::Run (this=0x45c3d838) at ../../dist/include/mozilla/ipc/RPCChannel.h:397
#18 0x41f2606c in mozilla::ipc::RPCChannel::DequeueTask::Run (this=0x452cd968) at ../../dist/include/mozilla/ipc/RPCChannel.h:414
#19 0x424e0776 in MessageLoop::RunTask (this=0x4042c0c0, task=0x452cd968) at /media/huseby/fxos/B2G/gecko/ipc/chromium/src/base/message_loop.cc:338
#20 0x424e07cc in MessageLoop::DeferOrRunPendingTask (this=0x4042c0c0, pending_task=...) at /media/huseby/fxos/B2G/gecko/ipc/chromium/src/base/message_loop.cc:346
#21 0x424e0afa in MessageLoop::DoWork (this=0x4042c0c0) at /media/huseby/fxos/B2G/gecko/ipc/chromium/src/base/message_loop.cc:446
#22 0x41f24bb0 in mozilla::ipc::DoWorkRunnable::Run (this=0x404046f0) at /media/huseby/fxos/B2G/gecko/ipc/glue/MessagePump.cpp:41
#23 0x424a2f66 in nsThread::ProcessNextEvent (this=0x4041e9a0, mayWait=true, result=0xbe932767) at /media/huseby/fxos/B2G/gecko/xpcom/threads/nsThread.cpp:622
#24 0x4245986a in NS_ProcessNextEvent (thread=0x4041e9a0, mayWait=true) at /media/huseby/fxos/B2G/objdir-gecko-noopt/xpcom/build/nsThreadUtils.cpp:238
#25 0x41f24d9c in mozilla::ipc::MessagePump::Run (this=0x40401d30, aDelegate=0x4042c0c0) at /media/huseby/fxos/B2G/gecko/ipc/glue/MessagePump.cpp:116
#26 0x424e04a0 in MessageLoop::RunInternal (this=0x4042c0c0) at /media/huseby/fxos/B2G/gecko/ipc/chromium/src/base/message_loop.cc:220
#27 0x424e0472 in MessageLoop::RunHandler (this=0x4042c0c0) at /media/huseby/fxos/B2G/gecko/ipc/chromium/src/base/message_loop.cc:213
#28 0x424e0452 in MessageLoop::Run (this=0x4042c0c0) at /media/huseby/fxos/B2G/gecko/ipc/chromium/src/base/message_loop.cc:187
#29 0x41e79662 in nsBaseAppShell::Run (this=0x450ed280) at /media/huseby/fxos/B2G/gecko/widget/xpwidgets/nsBaseAppShell.cpp:163
#30 0x41d2d030 in nsAppStartup::Run (this=0x44f46d30) at /media/huseby/fxos/B2G/gecko/toolkit/components/startup/nsAppStartup.cpp:269
#31 0x40e9c100 in XREMain::XRE_mainRun (this=0xbe9329e0) at /media/huseby/fxos/B2G/gecko/toolkit/xre/nsAppRunner.cpp:3858
#32 0x40e9c356 in XREMain::XRE_main (this=0xbe9329e0, argc=1, argv=0xbe934bf4, aAppData=0x3a188) at /media/huseby/fxos/B2G/gecko/toolkit/xre/nsAppRunner.cpp:3926
#33 0x40e9c50e in XRE_main (argc=1, argv=0xbe934bf4, aAppData=0x3a188, aFlags=0) at /media/huseby/fxos/B2G/gecko/toolkit/xre/nsAppRunner.cpp:4128
#34 0x00009dd4 in do_main (argc=1, argv=0xbe934bf4) at /media/huseby/fxos/B2G/gecko/b2g/app/nsBrowserApp.cpp:168
#35 0x0000a0ba in main (argc=1, argv=0xbe934bf4) at /media/huseby/fxos/B2G/gecko/b2g/app/nsBrowserApp.cpp:261

Comment 9

[Dave Huseby [:huseby]]

leo+?

Comment 10

[Dave Huseby [:huseby]]

nvrmnd, this bug is only present in mozilla-central which is 1.2.

Comment 11

[Dave Huseby [:huseby]]

got it figured out.

Comment 12

[Dave Huseby [:huseby]]

So this bug is only in the mozilla-central tip and NOT in the mozilla-b2g18 tip.  As I said in Comment 10, I think this is a koi bug.

Comment 13

[Dave Huseby [:huseby]]

so, bisecting mozilla-central came up with this:

The first bad revision is:
changeset:   135661:f1ce5983b285
parent:      135659:32bffdedafee
user:        Guilherme Gonçalves <[e-mail]>
date:        Wed Jun 19 12:08:10 2013 -0700
summary:     Bug 874996 - Part 1 - Simplify handling of geolocation requests. r=jdm

Comment 14

[Hubert Figuiere [:hub]]

Uh oh, 

Adding as Cc the author of the patch and its reviewer.

Comment 15

[Hubert Figuiere [:hub]]

Also I believe we should write a test to prevent that kind of breakages caused by desktop changes in the future.

Comment 16

[Guilherme Gonçalves [:ggp]]

It looks like some geolocation request is being kept alive for longer than the apps, either because was not fulfilled (and didn't set a timeout) or was an un-cleared watchPosition request.

Is it possible to reproduce this on the simulator? What are the steps?

Comment 17

[Dave Huseby [:huseby]]

So it appears that the bug isn't present in the Firefox OS simulator.  The steps for reproducing the bug are this:

1. Launch any app that uses geolocation (here maps, geolocation test, maps.google.com in the browser).
2. Say "allow" when the geolocaiton permission dialog is shown.
3. Exit out of the app by hitting the home button.
4. Close the app by holding down the home button until the app + close button show up, click the close button.
5. Watch the geolocation icon in the status bar at the top.

If the bug is present, the geolocation icon stays bright until the battery dies.  If the bug is not present, the geolocaiton icon will first dim, then go away as the geolocation manager detects the idle state (no more geolocation callbacks) and then turns off geolocation altogether after some time in the idle state.

Comment 18

[Dave Huseby [:huseby]]

I don't know what repo/version of fxos is running in the simulator.  I do know that the tip of mozilla-central has the bug.

Comment 19

[Dave Huseby [:huseby]]

Just dumping some notes in here.  I'm using the Geoloc test app and building gecko from the tip of mozilla-central.  After attacking this with GDB tonight, I learned a few things:

1. When I hit the start button in Geoloc, two instances of the Geolocation object get created.  The first one then receives a call to Geolocation::WatchPosition which creates a new instance of nsGeolocationRequest that does not get put into the mPendingRequests list because sGeoInitPending is true (the initializer value).

2. I think this causes the geolocation permissions dialog to open up and when I choose to allow it, the nsGeolocationRequest::Allow() callback happens which puts the instance in the mWatchingCallbacks list.

3. A second instance of Geolocation gets created immediately afterwards and two calls to Geolocation::WatchPending create two new instances of nsGeolocationRequest.  This time though, sGeoInitPending is false so they get added to the mPendingRequests list.

4. Callbacks to the second Geolocation instance's Geolocation::ServiceReady function remove the two nsGeolocationRequest instances from the mPendingRequests list and adds them to the mWatchingRequests list.

5. At this point, all three nsGeolocationRequest instances are receiving timeout callbacks to their SendLocation() function which feeds the geolocation data back to the JS runtime.

6. When I close and then exit the geoloc app, there is a call to the first Geolocation instance's Shutdown() method which removes the first instance of nsGeolocationRequest that was created in step 1 above.

7. There is also a call to the second Geolocation instance to its ClearWatch function with the watch ID of the third instance of nsGeolocationRequest.

8. The end result is that there is an abandoned instance of nsGeolocationRequest in the second instance of Geolocation.  This could be for two reason: the second Geolocation instance should be receiving a Shutdown instead of a ClearWatch, or there should be a second call to ClearWatch with the ID of the orphaned nsGeolocationRequest instance.

I was looking at the diff between the parent and the changeset identified above using bisect.  The only things that look suspicious are the changes to Geolocation::Shutdown() that remove the calls to nsGeolocationRequest::Shutdown() and the changes in the logic around resetting the timers.

I tried re-adding the removed lines in Geolocation::Shutdown() and rebuilding but something got stuck in an incorrect state on my device.  I'm rebuilding from scratch right now, but I also need to sleep tonight.  I will pick this up in the morning.

Comment 20

[bweng]

(In reply to Hubert Figuiere [:hub] from comment #15)
> Also I believe we should write a test to prevent that kind of breakages
> caused by desktop changes in the future.

I have created a test case to check GPS status after Here maps is terminated. for V1.2. Thank you for the information.

Comment 21

[Hubert Figuiere [:hub]]

Where is that test? It must be failing, isn't it?

Comment 22

[bweng]

(In reply to Hubert Figuiere [:hub] from comment #21)
> Where is that test? It must be failing, isn't it?

Test case is created at here.
https://moztrap.mozilla.org/manage/cases/?filter-id=9564

My observation on my device is quiet tricky. When I moved back to home page from Here maps by pressing the home key, I observed the GPS icon in notification bar actually grayed out in 10 seconds and then it disappeared after one minute. 

The device I am using is IKURA
Gaia:     dc0afe9fe346a21e8927639978ed99628e1d0a36
B-D     2013-08-10 07:34:39
Gecko: 
BuildID   20130810074647
Version   18.0

Comment 23

[Hubert Figuiere [:hub]]

(In reply to bweng from comment #22)
> (In reply to Hubert Figuiere [:hub] from comment #21)
> > Where is that test? It must be failing, isn't it?
> 
> Test case is created at here.
> https://moztrap.mozilla.org/manage/cases/?filter-id=9564
> 
> My observation on my device is quiet tricky. When I moved back to home page
> from Here maps by pressing the home key, I observed the GPS icon in
> notification bar actually grayed out in 10 seconds and then it disappeared
> after one minute. 
> 
> The device I am using is IKURA
> Gaia:     dc0afe9fe346a21e8927639978ed99628e1d0a36
> B-D     2013-08-10 07:34:39
> Gecko: 
> BuildID   20130810074647
> Version   18.0

How about you test with master that runs mozilla-central. It is a regression and the bug doesn't occur in 18.0.

Comment 24

[Dave Huseby [:huseby]]

Attachment: 898240.patch

This patch (against b2g-incoming) fixes the GPS device not shutting off.  It fixes a very subtle bug in nsGeolocationRequest state tracking.

Comment 25

[Hubert Figuiere [:hub]]

Comment on attachment 793780 [details] [diff] [review]
898240.patch

Can't review this as I'm not peer.

Comment 26

[Hubert Figuiere [:hub]]

See https://wiki.mozilla.org/Modules/Core#Geolocation for the owners/peers for review.

Comment 27

[Kan-Ru Chen [:kanru] (UTC+9)]

Comment on attachment 793780 [details] [diff] [review]
898240.patch

Review of attachment 793780 [details] [diff] [review]:
-----------------------------------------------------------------

Steal review.

Nice catch! Next time please provide more lines of context in your patch.

Comment 28

[Hubert Figuiere [:hub]]

Dave, do you want me to commit this?

Comment 29

[bweng]

(In reply to Hubert Figuiere [:hub] from comment #23)
> (In reply to bweng from comment #22)
> > (In reply to Hubert Figuiere [:hub] from comment #21)
> > > Where is that test? It must be failing, isn't it?
> > 
> > Test case is created at here.
> > https://moztrap.mozilla.org/manage/cases/?filter-id=9564
> > 
> > My observation on my device is quiet tricky. When I moved back to home page
> > from Here maps by pressing the home key, I observed the GPS icon in
> > notification bar actually grayed out in 10 seconds and then it disappeared
> > after one minute. 
> > 
> > The device I am using is IKURA
> > Gaia:     dc0afe9fe346a21e8927639978ed99628e1d0a36
> > B-D     2013-08-10 07:34:39
> > Gecko: 
> > BuildID   20130810074647
> > Version   18.0
> 
> How about you test with master that runs mozilla-central. It is a regression
> and the bug doesn't occur in 18.0.

Hi Hubert,
After checked mater build, this issue does exist. Thanks for the information.

* Test Build: Mozilla-central-unagi/2013-08-19-04-02-03
+ Gecko revision:"c8c9bd74cc40
+ Gaia revision: "f6de05c135913f2cb790759335875bb1b3c4f9bb

Comment 30

[Hubert Figuiere [:hub]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/0a4e64df6549

Comment 31

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/0a4e64df6549

Comment 33

[Stephen Li]

Even though GPS does switch off with this fix, but we see an additional "StartUp" getting called just before "ShutDown" if a high accuracy fix is requested.

Steps to reproduce the issue:
Issue a high accuracy single shot request.
Let it timeout
Just before shutdown gets called, i see a Startup getting called in the provider.

Expected Behavior:
Only Shutdown should get called.

Comment 34

[Stephen Li]

Should we open a different bug for this issue ?
I am not sure how to reopen this bug.

Comment 35

[Dave Huseby [:huseby]]

Opened Bug 910463