1107329 - Attach stacks to settings locks and add error for long lock waits

Status: RESOLVED FIXED

(Core :: DOM: Device Interfaces, defect)

Description

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

Settings locks should have their creation function stack attached to them (just create a new Error object at get a stack from it), and we should warn in logs when a settings lock is being held too long and may be blocking the rest of the system.

Comment 1

[:gerard-majax]

Now that settings should be less messy, let's fix this to help diagnose further issues.

Comment 2

[:gerard-majax]

I think we should be doing all of this on SettingsRequestManager's side:
 - because it lives in the parent process,
 - because it's here that the lockup will happen,
 - becaues it's used by both SettingsManager and SettingsService

The stack should be dumped in the createLock() implementation on SettingsManager/SettingsService lock, and passed with the Settings:CreateLock message.

Comment 3

[:gerard-majax]

Attachment: Capture du 2014-12-23 13:49:56.png

Comment 4

[:gerard-majax]

Attachment: Adding locks tasks queue vivacity checking r=qdot

To help diagnosing further issues with the Settings API getting blocked,
we add some tracking of the tasks and locks queue vivacity. We ensure to
keep track of the last lock id at the head of the queue, and we verify
whether it does not stays on top of it for too long.

Comment 5

[:gerard-majax]

https://tbpl.mozilla.org/?tree=Try&rev=1dcb825abc9d

Comment 6

[:gerard-majax]

Comment on attachment 8540685 [details] [diff] [review]
Adding locks tasks queue vivacity checking r=qdot

Screenshot was taken with the fix from bug 1110872 removed, in a mulet running oop, and with an app doing mozSettings use while reloading the page.

Comment 7

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

Comment on attachment 8540685 [details] [diff] [review]
Adding locks tasks queue vivacity checking r=qdot

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

LGTM, r+'ing now. I think we could check for lockup more frequently without issue, but that's not blocking this from landing.

::: dom/settings/SettingsRequestManager.jsm
@@ +1123,4 @@
>          break;
>        case "Settings:Get":
>          if (VERBOSE) debug("Received getRequest from " + msg.lockID);
> +        this.checkSoftLockup();

Why not just check any time we receive any message? It looks like a fairly quick procedure.

Comment 8

[:gerard-majax]

(In reply to Kyle Machulis [:kmachulis] [:qdot] (USE NEEDINFO?) from comment #7)
> Comment on attachment 8540685 [details] [diff] [review]
> Adding locks tasks queue vivacity checking r=qdot
> 
> Review of attachment 8540685 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> LGTM, r+'ing now. I think we could check for lockup more frequently without
> issue, but that's not blocking this from landing.
> 
> ::: dom/settings/SettingsRequestManager.jsm
> @@ +1123,4 @@
> >          break;
> >        case "Settings:Get":
> >          if (VERBOSE) debug("Received getRequest from " + msg.lockID);
> > +        this.checkSoftLockup();
> 
> Why not just check any time we receive any message? It looks like a fairly
> quick procedure.

I was not sure it would be useful to do it for anything else than Get/Set/Clear

Comment 9

[:gerard-majax]

Attachment: Adding locks tasks queue vivacity checking r=qdot

To help diagnosing further issues with the Settings API getting blocked,
we add some tracking of the tasks and locks queue vivacity. We ensure to
keep track of the last lock id at the head of the queue, and we verify
whether it does not stays on top of it for too long.

Comment 10

[:gerard-majax]

Comment on attachment 8541153 [details] [diff] [review]
Adding locks tasks queue vivacity checking r=qdot

Carrying r+ from :qdot

Comment 11

[:gerard-majax]

(In reply to Alexandre LISSY :gerard-majax from comment #10)
> Comment on attachment 8541153 [details] [diff] [review]
> Adding locks tasks queue vivacity checking r=qdot
> 
> Carrying r+ from :qdot

Try: https://tbpl.mozilla.org/?tree=Try&rev=4a50ed28c45e

Comment 12

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/b2g-inbound/rev/5e2f9cc33056

Comment 13

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/5e2f9cc33056

Comment 14

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

Did anyone investigate performance differences with and without this patch? In the not too distant past I thought getting a stack like this was slow...

Comment 15

[:gerard-majax]

(In reply to ben turner [:bent] (use the needinfo? flag!) from comment #14)
> Did anyone investigate performance differences with and without this patch?
> In the not too distant past I thought getting a stack like this was slow...

Nothing formal, but I have not noticed this as having a huge impact as a dogfood user of some slow devices. Also, the cost is at createLock() only.

If we get figures that shows it has a non neglictible impact, we may limit the stack itself under a pref.