1092941 - mozSettings leaves orphan lock when running mnw tests.

Status: RESOLVED FIXED

(Core :: DOM: Device Interfaces, defect)

Description

[Jessica Jong [:jessica] (inactive)]

After bug 1082001, marionette-webapi tests time-out when getting settings using mozSettings. We have enabled settings log, and it seems that some locks are not finalized on OOP.

https://tbpl.mozilla.org/php/getParsedLog.php?id=51658340&tree=Try&full=1

You may not detect the failure cause mnw is currently hidden in treeherder.mozilla.org. :(

Comment 1

[Jessica Jong [:jessica] (inactive)]

Alexandre, Kyle, do you have any idea about this? Thanks.

Comment 2

[Edgar Chen [:edgar]]

Attachment: Patch, v1

Comment 3

[Edgar Chen [:edgar]]

Comment on attachment 8515881 [details] [diff] [review]
Patch, v1

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

Before starting b2g marionette-webapi tests, marionette framework will unload apps first (e.g. FTU).
And this leaves orphan lock, because SettingsRequestManager.jsm doesn't handle locks well when receiving `child-process-shutdown`.
1). `child-process-shutdown` doesn't come with principal [1], checking |lock._mm| seems enough.
2). The finalize task pushed in |enqueueForceFinalize| should be in running situation, just like how we handle |Settings:Finalize|.

Hi Ben, may I have your feedback about this patch? Thank you.

[1] http://dxr.mozilla.org/mozilla-central/source/dom/ipc/ContentParent.cpp#1506-1509

Comment 4

[:gerard-majax]

(In reply to Jessica Jong [:jjong] [:jessica] from comment #1)
> Alexandre, Kyle, do you have any idea about this? Thanks.

We did detect the failure but: I was not able to reproduce this locally. Only on B2G Emulator on TBPL. :mdas was working on getting us more logging capabilities to be able to investigate why this was failing.

Comment 5

[:gerard-majax]

Edgar, the code you removed is exactly code I added after ben reviewed :).
Do you mind providing a try run with multiple Mnw retrigger to show this fixes the issue ?

Comment 6

[:gerard-majax]

Confere comment 5.

Comment 7

[Edgar Chen [:edgar]]

Here is the try with the setting fix: https://tbpl.mozilla.org/?tree=Try&rev=98b8de915433
((with setting debug logging enabled))

But we encounter other telephony test failure :(, we are working on that now.
Will provide a try result again after we fixe them, keeps ni? to me for tracking.

Comment 8

[:gerard-majax]

(In reply to Edgar Chen [:edgar][:echen] from comment #7)
> Here is the try with the setting fix:
> https://tbpl.mozilla.org/?tree=Try&rev=98b8de915433
> ((with setting debug logging enabled))
> 
> But we encounter other telephony test failure :(, we are working on that now.
> Will provide a try result again after we fixe them, keeps ni? to me for
> tracking.

I took the liberty to do some retrigger. It seems to effectively improve things on Mnw.
I'm very sorry for the mess we created :(

Comment 9

[Ben Turner (not reading bugmail, use the needinfo flag!)]

Comment on attachment 8515881 [details] [diff] [review]
Patch, v1

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

I think Alexandre can manage this, otherwise feel free to kick it back to me.

Comment 10

[:gerard-majax]

Comment on attachment 8515881 [details] [diff] [review]
Patch, v1

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

That looks quite sane. And that will probably fix the Mnw bustage I landed :(
Make sure you also don't break the xpcshell test we wrote, in dom/settings/test/unit/, since it explicitely does a call to Settings:Run.

::: dom/settings/SettingsRequestManager.jsm
@@ +778,4 @@
>          }
>        );
> +      // Finalize is considered a task running situation, but it also needs to
> +      // queue a task.

Makes sense, but I'm a bit frightened, since we have a simiar logic running for the handling of messages. The switch() case handling Settings:Finalize message will do the same kind of forcing a Settings:Run operation, so I think we should share code.

Comment 11

[Edgar Chen [:edgar]]

Thanks for the feedback, Alexandre.
I am working on formal patch, will upload it and request review soon.

Comment 12

[Edgar Chen [:edgar]]

Attachment: Patch, v2

Address comment #10:
- Share the code of forcing running operation.

Try result is on the way.

Hi Alexandre, may I have your review? Thank you.

Comment 13

[:gerard-majax]

Comment on attachment 8517375 [details] [diff] [review]
Patch, v2

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

Looks good to me. I'll make sure to test on mulet oop and non oop and on device before r+ this, so keeping the r?, but I'll wait for the try run to do this.

::: dom/settings/SettingsRequestManager.jsm
@@ +800,5 @@
>          }
>        );
> +      // Finalize is considered a task running situation, but it also needs to
> +      // queue a task.
> +      this.startRunning(lock.lockID);

Shouldn't we run this in the success callback of the queueTask() call?

Comment 14

[Edgar Chen [:edgar]]

Try result looks good: https://tbpl.mozilla.org/?tree=Try&rev=d1d08f9640e8

Comment 15

[Edgar Chen [:edgar]]

(In reply to Alexandre LISSY :gerard-majax from comment #13)
> Comment on attachment 8517375 [details] [diff] [review]
> Patch, v2
> 
> Review of attachment 8517375 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: dom/settings/SettingsRequestManager.jsm
> @@ +800,5 @@
> >          }
> >        );
> > +      // Finalize is considered a task running situation, but it also needs to
> > +      // queue a task.
> > +      this.startRunning(lock.lockID);
> 
> Shouldn't we run this in the success callback of the queueTask() call?

No, we can not do it in the success callback.
The success callback of queueTask() is for the task is proccessed successfully, not for pushed into task queue successfully.

Comment 16

[:gerard-majax]

Right. I still have to check on device, sorry for the latency, got caught up in stuff :(

Comment 17

[:gerard-majax]

Comment on attachment 8517375 [details] [diff] [review]
Patch, v2

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

::: dom/settings/SettingsRequestManager.jsm
@@ +401,5 @@
> +  startRunning: function(aLockID) {
> +    let lock = this.lockInfo[aLockID];
> +
> +    if (!lock) {
> +      if (DEBUG) debug("Lock no longer alive, cannot run tasks");

Please make sure we don't collide debug messages. This one does collide with some in runTasks().
This will make reading logs easier in the future.

@@ +409,5 @@
> +    lock.consumable = true;
> +    if (aLockID == this.settingsLockQueue[0] || this.settingsLockQueue.length == 0) {
> +      // If a lock is currently at the head of the queue, run all tasks for
> +      // it.
> +      if (DEBUG) debug("Running tasks for " + aLockID);

Same.

Comment 18

[:gerard-majax]

Comment on attachment 8517375 [details] [diff] [review]
Patch, v2

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

That seems to be okay on device and on Mulet. Just fix the remaining nits regarding the debug messages :)
This try: https://tbpl.mozilla.org/?tree=Try&rev=d1d08f9640e8 is already mostly green.
I retriggered a couple of Mnw, just to be sure.

Comment 19

[Edgar Chen [:edgar]]

Attachment: Patch, v3, r=lissyx

Address review comment #17,
- Only modify the debug message which collides with some in runTasks().

Comment 20

[:gerard-majax]

Seems ok: https://tbpl.mozilla.org/?tree=Try&rev=d1d08f9640e8

Comment 21

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/b2g-inbound/rev/832e23a206cc

Comment 22

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/832e23a206cc

Comment 24

[Ryan VanderMeulen [:RyanVM]]

Please request b2g34 approval on this patch so bug 1076597 can re-land.

Comment 25

[Edgar Chen [:edgar]]

Hi Alexandre, this bug also depends on bug 1082001, do you think we should uplift bug 1082001 as well?

Comment 26

[:gerard-majax]

Ryan, Edgar, I agree that we should uplift: bug 1082001, this one and we could reland bug 1076597. But I think it would be good that we want a bit that those patch do live a bit more on master.

Comment 27

[:gerard-majax]

Comment on attachment 8518180 [details] [diff] [review]
Patch, v3, r=lissyx

NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings.

[Approval Request Comment]
Bug caused by (feature/regressing bug #): bug 1082001
User impact if declined: Marionette WebAPI tests failing to run
Testing completed: made Mnw green again, fixes bug 1093121 where keyboard never shows
Risk to taking this patch (and alternatives if risky): low
String or UUID changes made by this patch: none

Comment 28

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g34_v2_1/rev/a8e5d71d941d

Comment 30

[Julien Wajsberg [:julienw]]

It looks like the settings app is broken in v2.1, with the same symptomes I had in bug  1091542 that were fixed with this bug, with a build from yesterday.

Any clue?

Comment 31

[Julien Wajsberg [:julienw]]

Looks like this happen after the phone is running for a long time. Nical (Nicolas Silva) showed me on his phone flashed from yesterday.

It seems it's also breaking other apps too.

Comment 32

[Arthur Chen [:arthurcc][inactive after 6/30]]

(In reply to Julien Wajsberg [:julienw] from comment #31)
> Looks like this happen after the phone is running for a long time. Nical
> (Nicolas Silva) showed me on his phone flashed from yesterday.
> 
> It seems it's also breaking other apps too.

If it also affects other apps, it seems like an issue of the settings manager in gecko. But I haven't encountered this on v2.1 yet.

Comment 33

[Julien Wajsberg [:julienw]]

Nical, can you please file a bug for what you're seeing?

Comment 34

[Julien Wajsberg [:julienw]]

Bug 1105511 seems to be this bug.

Comment 35

[Kyle Machulis [:qdot] [:kmachulis] (INACTIVE)]

Confirmed :julienw's comment. We're pulling null principals and not checking their validity when checking permissions on them, which causes us to throw silently and lock up. This is causing bug 1105511, bug 1093932, as most likely many others.