1223116 - webconsole should filter service worker logs using same logic as ServiceWorkerManager

Status: RESOLVED FIXED

(DevTools :: Console, defect)

Description

[Ben Kelly [:bkelly, not reviewing]]

Once bug 1217909 lands we are going to have two slightly different approaches to reporting to the console.

A service worker console.log() follows this rule:

  "Show logs in a window if the service worker scope matches the window.location or any frame.src within the window."

In contrast, ServiceWorkerManager internally is going to use this rule for reporting exceptions:

  "Shows logs in a window if its controlled or if it called .register() for the given SW script/scope."

This is slightly better in that it will show messages in the console when a window registers a service worker for a scope that doesn't match the current window.  This will be common, for example, when using only push and not offline 
support.

We should expose the ServiceWorkerManager logic in a shouldReportToWindow() method on the nsIServiceWorkerManager interface.

Comment 1

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P1 Expose nsIServiceWorkerManager.shouldReportToWindow(). r=catalinb

Comment 2

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P2 Make webconsole use new nsIServiceWorkerManager.shouldReportToWindow(). r=bgrins

Work-in-progress.  I still need to do some cleanup.  Also, the logs are not showing when navigating from an uncontrolled page to a controlled page.  I may need to change it around to use outer window ID or something.

Comment 3

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P1 Expose nsIServiceWorkerManager.shouldReportToWindow(). r=catalinb

This essentially exposes the same logic from ServiceWorkerManager::ReportToAllClients() to chrome script.  This lets devtools then ask us if it should show a particular console message on any given window.

Comment 4

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P2 Make webconsole use new nsIServiceWorkerManager.shouldReportToWindow(). r=bgrins

Brian does this look right?

I still need to look and see if the test needs to be adjusted.

Comment 5

[Ben Kelly [:bkelly, not reviewing]]

Yea, it seems the test times out.  I will investigate tomorrow.

Comment 6

[Brian Grinstead [:bgrins]]

Ben, will this logic also handle the scenario in Bug 1221772?

Comment 7

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Brian Grinstead [:bgrins] from comment #6)
> Ben, will this logic also handle the scenario in Bug 1221772?

Well, we currently have bugs with SW treating the Worker as a client.  Part of fixing that would include extending the logic I'm providing here to include the Worker's parent document in the list of registering documents.

Comment 8

[Ben Kelly [:bkelly, not reviewing]]

More specifically, it should be part of fixing bug 1032521.

Comment 9

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P1 Expose nsIServiceWorkerManager.shouldReportToWindow(). r=catalinb

I had a bug in my ShouldReportToWindow() method.  It needs to use the top window when comparing IDs.  The test correctly caught this problem.  The test passes with these changes.

Comment 10

[Brian Grinstead [:bgrins]]

Comment on attachment 8685755 [details] [diff] [review]
P2 Make webconsole use new nsIServiceWorkerManager.shouldReportToWindow(). r=bgrins

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

This change looks good to me from the webconsole end, test_console_serviceworker.html should catch any regressions.  I'd like to extend that test to also register a non-matching service worker and make sure it's message doesn't appear.  Will registering a new SW with a non-matching scope do that, or do we need to register a new one on a different domain?

Comment 11

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P3 Extend the test to check console messages during navigation interceptions. r =bgrins

This tests the case where we navigate from an uncontrolled document to a controlled document.

Comment 12

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Brian Grinstead [:bgrins] from comment #10)

> I'd like to extend that test to also register a non-matching service worker and make
> sure it's message doesn't appear.  Will registering a new SW with a
> non-matching scope do that, or do we need to register a new one on a
> different domain?

I'll do this tomorrow or later tonight.  The non-matching scope should be enough.  In fact, I can even change the current register() to do that as its the same path for whats going on there now.  With my P3 patch the main thing thats missing is a test of the log showing up for a controlled frame.

Comment 13

[Brian Grinstead [:bgrins]]

Comment on attachment 8686283 [details] [diff] [review]
P3 Extend the test to check console messages during navigation interceptions. r =bgrins

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

::: devtools/shared/webconsole/test/test_console_serviceworker.html
@@ +20,3 @@
>  
>  let swClosed = new Promise(() => {});
>  let expectedConsoleCalls = [

Does expectedConsoleCalls need a new entry for the fetch log here?  According to the comment right before the navigation we are expecting an additional log to happen at that point

@@ +56,5 @@
>        win.navigator.serviceWorker.register(SERVICE_WORKER_URL).then(swr => {
> +        // Now navigate the frame to trigger another console message from
> +        // the fetch event handler.
> +        iframe.onload = function() {
> +          info("Service worker registered.  Unregistering");

Nit: move this info call outside of the onload

Comment 14

[Ben Kelly [:bkelly, not reviewing]]

Good catch.  I don't think the fetch event is firing.  Probably because I need to wait for the SW to be activated.  I'll fix tomorrow and expand to cover some more test cases.

Comment 15

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P3 Extend the test to check console messages for more service worker conditions . r=bgrins

Ok, there were a few problems before.  The service worker wasn't firing correctly, but the test was also terminating as soon as it got the number of expected console calls.  So additional console calls did not cause a failure either.

The modified test now tests these conditions:

1) Console calls from SW to registering, out-of-scope frame
2) Console calls from SW handling navigation from non-scope to in-scope
3) Console calls from SW handling non-navigation from a controlled frame

Comment 16

[Brian Grinstead [:bgrins]]

Comment on attachment 8686814 [details] [diff] [review]
P3 Extend the test to check console messages for more service worker conditions . r=bgrins

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

This is great, thanks!

::: devtools/shared/webconsole/test/test_console_serviceworker.html
@@ +62,5 @@
>    attachConsoleToTab(["ConsoleAPI"], onAttach);
>  });
>  addEventListener("load", startTest);
>  
> +function with_frame(url) {

Nit: camelcase to match webconsole style

@@ +114,1 @@
>  function onAttach(state, response) {

Nit: please use Task.async and yield to match other new webconsole tests.  Something like..

let onAttach = Task.async(function*(state, response) {
  ...
  let currentFrame = yield with_frame(NONSCOPE_FRAME_URL);
  yield with_active_service_worker(currentFrame.contentWindow,
                                   SERVICE_WORKER_URL, SCOPE);
  yield navigate_frame(currentFrame, SCOPE_FRAME_URL);
  yield currentFrame.contentWindow.fetch(SCOPE_FRAME_URL2);
  yield unregister_service_worker(currentFrame.contentWindow);
  ...
});

@@ +147,5 @@
> +    return unregister_service_worker(currentFrame.contentWindow);
> +  }).then(() => {
> +    info('Service worker unregistered.  Checking console calls.');
> +    state.dbgClient.removeListener("consoleAPICall", onConsoleAPICall);
> +    is(consoleCalls.length, expectedConsoleCalls.length,

This still doesn't add a case where a non-relevant SW does a log that should be ignored, right?  But at least now it will fail when we add that.

Comment 17

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Brian Grinstead [:bgrins] from comment #16)
> @@ +114,1 @@
> >  function onAttach(state, response) {
> 
> Nit: please use Task.async and yield to match other new webconsole tests. 
> Something like..

How important is this?  I did it, but it makes the .register() fail with an InvalidStateError.  It seems the entry document or something might not be right using Task.async here.

Comment 18

[Ben Kelly [:bkelly, not reviewing]]

Oh, the Task.async triggers bug 1224237.

Comment 19

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P3 Extend the test to check console messages for more service worker conditions . r=bgrins

Comment 20

[Ben Kelly [:bkelly, not reviewing]]

Attachment: bug1223116_p3_testnav.patch

Comment 21

[Brian Grinstead [:bgrins]]

(In reply to Ben Kelly [:bkelly] from comment #17)
> (In reply to Brian Grinstead [:bgrins] from comment #16)
> > @@ +114,1 @@
> > >  function onAttach(state, response) {
> > 
> > Nit: please use Task.async and yield to match other new webconsole tests. 
> > Something like..
> 
> How important is this?  I did it, but it makes the .register() fail with an
> InvalidStateError.  It seems the entry document or something might not be
> right using Task.async here.

That's weird, maybe some kind of timing issue?  It's not a huge deal, but if Bug 1224237 is going to fix this anyway then let's go with it.

Comment 22

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Brian Grinstead [:bgrins] from comment #21)
> That's weird, maybe some kind of timing issue?  It's not a huge deal, but if
> Bug 1224237 is going to fix this anyway then let's go with it.

Yea, I expect bug 1224237 to land before this.

Comment 23

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P3 Extend the test to check console messages for more service worker conditions . r=bgrins

Updated the test to perform a console.log() from the service worker while there are no controlling or registering documents and verify that the window does not get a console call.

Its good I did this because it revealed a bug in how I was handling detached documents in SWM::ShouldReportToWindow().

Comment 24

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P1 Expose nsIServiceWorkerManager.shouldReportToWindow(). r=catalinb

Update the patch to skip documents that return false from IsCurrentActiveDocument().  This makes it so we don't spam the console in windows that have a controlled or registering document in their bfcache history.

Also, check GetScriptableTop() return for nullptr.

Comment 25

[Ben Kelly [:bkelly, not reviewing]]

Attachment: P3 Extend the test to check console messages for more service worker condit ions. r=bgrins

One more to remove some stale code and add a comment I forgot to put in.

Comment 26

[Ben Kelly [:bkelly, not reviewing]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=42f5c1259930

Comment 27

[Ben Kelly [:bkelly, not reviewing]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=c4ef9efdb1b7

Comment 28

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/69f09bd56c59
https://hg.mozilla.org/integration/mozilla-inbound/rev/50cf666c196d
https://hg.mozilla.org/integration/mozilla-inbound/rev/d60d5f8ffda4

Comment 29

[Ben Kelly [:bkelly, not reviewing]]

Comment on attachment 8686979 [details] [diff] [review]
P1 Expose nsIServiceWorkerManager.shouldReportToWindow(). r=catalinb

Approval request for patches P1 to P3.  All the patches.

Approval Request Comment
[Feature/regressing bug #]:  Service workers
[User impact if declined]:  This is needed to provide a better developer experience for sites trying to use service workers on firefox.  It improves where console.log() messages from a service worker show up.
[Describe test coverage new/current, TreeHerder]: Included test.
[Risks and why]: Minimal.  Only affects service workers.
[String/UUID change made/needed]:  None.

Comment 30

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Will wait for these to land on m-c before approving uplift to m-a.

Comment 31

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

https://hg.mozilla.org/mozilla-central/rev/69f09bd56c59
https://hg.mozilla.org/mozilla-central/rev/50cf666c196d
https://hg.mozilla.org/mozilla-central/rev/d60d5f8ffda4

Comment 32

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Comment on attachment 8686979 [details] [diff] [review]
P1 Expose nsIServiceWorkerManager.shouldReportToWindow(). r=catalinb

SW is planned for FF44

Comment 33

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Comment on attachment 8685755 [details] [diff] [review]
P2 Make webconsole use new nsIServiceWorkerManager.shouldReportToWindow(). r=bgrins

Aurora44+

Comment 34

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Comment on attachment 8686986 [details] [diff] [review]
P3 Extend the test to check console messages for more service worker condit ions. r=bgrins

Aurora44+

Comment 35

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

I'm hitting conflicts uplifting this to aurora. Can we get rebased patches?

Comment 36

[Ben Kelly [:bkelly, not reviewing]]

Yea, this depends on bug 1217909.  I will uplift both later today.  Thanks.

Comment 37

[Ben Kelly [:bkelly, not reviewing]]

remote:   https://hg.mozilla.org/releases/mozilla-aurora/rev/a8babe14e557
remote:   https://hg.mozilla.org/releases/mozilla-aurora/rev/4ddcaa564eb8
remote:   https://hg.mozilla.org/releases/mozilla-aurora/rev/7e411051b2d6

Comment 38

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-b2g44_v2_5/rev/a8babe14e557
https://hg.mozilla.org/releases/mozilla-b2g44_v2_5/rev/4ddcaa564eb8
https://hg.mozilla.org/releases/mozilla-b2g44_v2_5/rev/7e411051b2d6