Closed Bug 1222617 Opened 4 years ago Closed 4 years ago

Service worker logs should disappear after a reload and opening the console

Categories

(DevTools :: Console, defect)

defect
Not set

Tracking

(firefox44 fixed, firefox45 fixed)

RESOLVED FIXED
Firefox 45
Tracking Status
firefox44 --- fixed
firefox45 --- fixed

People

(Reporter: bgrins, Assigned: bgrins)

References

(Blocks 1 open bug)

Details

Attachments

(1 file, 1 obsolete file)

Usually console API messages are removed when a window is reloaded.  For SW messages they persist beyond the lifetime of a page so if you reload a page and they open the console you will see messages that happened way earlier.

SW messages should match the behavior of normal messages in this regard.  We probably need to somehow compare the timeStamp of a message with the time that a page was last destroyed.  I believe this happens here for normal messages: https://dxr.mozilla.org/mozilla-central/source/dom/base/ConsoleAPIStorage.js#66
Attached patch console-sw-cached-messages.patch (obsolete) — Splinter Review
I started working on this and have something that appears to fix this particular case, but I noticed something weird when working on a test for it.  Since shouldReportToWindow is only called once getCachedMessages is called, it will decide to filter out or include messages based on the state of the page when that function is called instead of the state of the page when the message is logged.

As a user, I'd expect that any messages that were relevant at the time they were logged would show up.  The changes to the test case here demonstrate the issue.  Specifically, notice that we need to re-navigate to a scoped URL on the frame before calling getCachedMessages or else no messages are returned.  And after we do the navigation, ALL messages are returned (even those that are expected to be filtered like 'message event: Tic Tock').

Ben, does the problem here make sense?  Any ideas of ways that we could encode the shouldReportToWindow decision into the message itself (my best idea so far would be to somehow serialize relevant window ids into the innerID field on the message).
Flags: needinfo?(bkelly)
Ok, so if I understand correctly a nested iframe is becoming controlled, but we're not changing the top level window.  So the code here only checks the timestamp of the top level window we end up replaying all console messages and get the new state.

IMO this is not going to be something devs see very much.  The code does, however, make the current situation materially better because the vast majority of duplicate logs are filtered out.

I would like to land this change, enable service worker logging, and file a bug about nested iframe weirdness.  What do you think?
Flags: needinfo?(bkelly)
Blocks: 1226061
Filed Bug 1226061 to handle this less critical case, and I'll wrap this one up by writing a new test without frames involved.
Assignee: nobody → bgrinstead
Status: NEW → ASSIGNED
Bug 1222617 - Filter out service worker messages that happened before a page load;r=bkelly
Attachment #8689833 - Flags: review?(bkelly)
Ben, can you please review that this is filtering out what you'd expect?  I've added a new test case that attaches two tabs to check to be sure the script eval / install / activate logs don't happen on the second tab (although a fetch for the page itself does).

I'm not positive that performance.timing.requestStart is exactly the timestamp what we want in all cases (like I'm not sure *exactly* the moment when the SW is controlling a window), but it seems to work for me on all my test pages and in this new test.
Attachment #8689218 - Attachment is obsolete: true
Comment on attachment 8689833 [details]
MozReview Request: Bug 1222617 - Filter out service worker messages that happened before a page load;r=bkelly

https://reviewboard.mozilla.org/r/25731/#review23151

Looks great.  Thanks!
Attachment #8689833 - Flags: review?(bkelly) → review+
Brian, can you flag this for uplift to aurora after you land it?
Flags: needinfo?(bgrinstead)
Blocks: sw-devtools
Flags: needinfo?(bgrinstead)
https://hg.mozilla.org/mozilla-central/rev/8cab032fa1e9
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 45
Comment on attachment 8689833 [details]
MozReview Request: Bug 1222617 - Filter out service worker messages that happened before a page load;r=bkelly

Approval Request Comment
[Feature/regressing bug #]: Service workers (bug 1059784)
[User impact if declined]: Webconsole logs coming from a service worker will show up in a tab even if the log statement happened before the tab was loaded
[Describe test coverage new/current, TreeHerder]: A new mochitest for the webconsole was added for this chagne
[Risks and why]: Pretty small code change that affects webconsole filtering, specifically targeted at only Service Worker logs.  As such it won't affect 'normal' logs and isn't super risky.
[String/UUID change made/needed]:
Attachment #8689833 - Flags: approval-mozilla-aurora?
Depends on: 1227139
Comment on attachment 8689833 [details]
MozReview Request: Bug 1222617 - Filter out service worker messages that happened before a page load;r=bkelly

This fix has been on Nightly for a few days so it seems safe. Also, removing SW logs from webconsole when a page is closed and re-opened makes sense. Let's uplift to Aurora44.
Attachment #8689833 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
sorry had to back this out for test failures like https://treeherder.mozilla.org/logviewer.html#?job_id=1537006&repo=mozilla-aurora
Flags: needinfo?(bgrinstead)
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.