Closed Bug 1717091 Opened 3 years ago Closed 1 year ago

Disable Intermittent dom/serviceworkers/test/test_hsts_upgrade_intercept.html | This test left a service worker registered without cleaning it up

Categories

(Core :: DOM: Service Workers, defect)

defect

Tracking

()

RESOLVED FIXED

People

(Reporter: intermittent-bug-filer, Assigned: apavel)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Attachments

(2 files)

Filed by: cbrindusan [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=343103204&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZQgBq8mbRvqyHn5SS0_a6w/runs/0/artifacts/public/logs/live_backing.log


[task 2021-06-17T17:45:26.833Z] 17:45:26     INFO - TEST-START | dom/serviceworkers/test/test_hsts_upgrade_intercept.html
[task 2021-06-17T17:45:28.124Z] 17:45:28     INFO - TEST-INFO | started process screenshot
[task 2021-06-17T17:45:28.191Z] 17:45:28     INFO - TEST-INFO | screenshot: exit 0
[task 2021-06-17T17:45:28.191Z] 17:45:28     INFO - Buffered messages logged at 17:45:27
[task 2021-06-17T17:45:28.192Z] 17:45:28     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | The active worker should be available. 
[task 2021-06-17T17:45:28.193Z] 17:45:28     INFO - Buffered messages logged at 17:45:28
[task 2021-06-17T17:45:28.193Z] 17:45:28     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Correct protocol expected 
[task 2021-06-17T17:45:28.194Z] 17:45:28     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Security info present on intercepted value 
[task 2021-06-17T17:45:28.195Z] 17:45:28     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Correct protocol expected 
[task 2021-06-17T17:45:28.196Z] 17:45:28     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Security info present on intercepted value 
[task 2021-06-17T17:45:28.197Z] 17:45:28     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | The image request was upgraded before interception 
[task 2021-06-17T17:45:28.198Z] 17:45:28     INFO - Buffered messages finished
[task 2021-06-17T17:45:28.199Z] 17:45:28     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | This test left a service worker registered without cleaning it up
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

There have been 32 total failures in the last 7 days (recent failure log).
Affected platforms are:

  • windows10-64-2004-qr & windows10-64-2004-shippable-qr
  • One failure in linux1804-64-shippable-qr
Whiteboard: [stockwell needswork:owner]

Hello, Jens. Could you please take a look?

Flags: needinfo?(jstutte)

Update:

There have been 30 failures within the last 7 days:

  • 4 failures on Windows 10 x86 2004 WebRender opt
  • 4 failures on Windows 10 x86 2004 WebRender Shippable opt
  • 10 failures on Windows 10 x64 2004 WebRender opt
  • 12 failures on Windows 10 x64 2004 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=350535238&repo=mozilla-central&lineNumber=5794

[task 2021-09-04T11:26:02.546Z] 11:26:02     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | The image request was upgraded before interception 
[task 2021-09-04T11:26:02.546Z] 11:26:02     INFO - Buffered messages finished
[task 2021-09-04T11:26:02.547Z] 11:26:02     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | This test left a service worker registered without cleaning it up 
[task 2021-09-04T11:26:02.547Z] 11:26:02     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:417:16
[task 2021-09-04T11:26:02.547Z] 11:26:02     INFO - afterCleanup@https://example.com/tests/SimpleTest/SimpleTest.js:1436:18
[task 2021-09-04T11:26:02.547Z] 11:26:02     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-04T11:26:02.548Z] 11:26:02     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Left over worker: http://mochi.test:8888/tests/dom/serviceworkers/test/xslt_worker.js (scope: http://mochi.test:8888/tests/dom/serviceworkers/test/) 
[task 2021-09-04T11:26:02.548Z] 11:26:02     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:417:16
[task 2021-09-04T11:26:02.548Z] 11:26:02     INFO - afterCleanup@https://example.com/tests/SimpleTest/SimpleTest.js:1441:20
[task 2021-09-04T11:26:02.549Z] 11:26:02     INFO - GECKO(6768) | MEMORY STAT | vsize 564MB | vsizeMaxContiguous 1806MB | residentFast 51MB | heapAllocated 7MB
[task 2021-09-04T11:26:02.549Z] 11:26:02     INFO - TEST-OK | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | took 1349ms
Assignee: nobody → apavel
Assignee: apavel → nobody
Assignee: nobody → apavel
Assignee: apavel → nobody
Keywords: leave-open
Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][stockwell disabled]
Pushed by apavel@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/8649331815cd
disable test_hsts_upgrade_intercept.html on win10_2004 not debug r=intermittent-reviewers,bhearsum DONTBUILD
Pushed by apavel@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/9ccebcbe9247
fix disabling typo on a CLOSED TREE
Flags: needinfo?(jstutte)

There are 37 total failures in the last 7 days on

[task 2022-03-28T19:29:27.706Z] 19:29:27     INFO - TEST-START | dom/serviceworkers/test/test_hsts_upgrade_intercept.html
[task 2022-03-28T19:29:29.174Z] 19:29:29     INFO - TEST-INFO | started process screenshot
[task 2022-03-28T19:29:29.321Z] 19:29:29     INFO - TEST-INFO | screenshot: exit 0
[task 2022-03-28T19:29:29.337Z] 19:29:29     INFO - Buffered messages logged at 19:29:29
[task 2022-03-28T19:29:29.337Z] 19:29:29     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | The active worker should be available. 
[task 2022-03-28T19:29:29.338Z] 19:29:29     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Correct protocol expected 
[task 2022-03-28T19:29:29.338Z] 19:29:29     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Security info present on intercepted value 
[task 2022-03-28T19:29:29.338Z] 19:29:29     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Correct protocol expected 
[task 2022-03-28T19:29:29.339Z] 19:29:29     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Security info present on intercepted value 
[task 2022-03-28T19:29:29.339Z] 19:29:29     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | The image request was upgraded before interception 
[task 2022-03-28T19:29:29.340Z] 19:29:29     INFO - Buffered messages finished
[task 2022-03-28T19:29:29.340Z] 19:29:29     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | This test left a service worker registered without cleaning it up 
[task 2022-03-28T19:29:29.340Z] 19:29:29     INFO - SimpleTest.ok@https://example.org/tests/SimpleTest/SimpleTest.js:417:16
[task 2022-03-28T19:29:29.340Z] 19:29:29     INFO - afterCleanup@https://example.org/tests/SimpleTest/SimpleTest.js:1436:18
[task 2022-03-28T19:29:29.341Z] 19:29:29     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-28T19:29:29.341Z] 19:29:29     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Left over worker: http://mochi.test:8888/tests/dom/serviceworkers/test/xslt_worker.js (scope: http://mochi.test:8888/tests/dom/serviceworkers/test/) 
[task 2022-03-28T19:29:29.341Z] 19:29:29     INFO - SimpleTest.ok@https://example.org/tests/SimpleTest/SimpleTest.js:417:16
[task 2022-03-28T19:29:29.341Z] 19:29:29     INFO - afterCleanup@https://example.org/tests/SimpleTest/SimpleTest.js:1441:20
[task 2022-03-28T19:29:29.342Z] 19:29:29     INFO - GECKO(6360) | MEMORY STAT | vsize 506MB | vsizeMaxContiguous 1806MB | residentFast 48MB | heapAllocated 6MB
[task 2022-03-28T19:29:29.342Z] 19:29:29     INFO - TEST-OK | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | took 1483ms

Hi Jens, can you please take a look or assign this to someone who can?
Thank you.

Flags: needinfo?(jstutte)
Whiteboard: [stockwell unknown][stockwell needswork:owner] → [stockwell needswork:owner]

IIUC our unregister.html is run in an iframe and thus potentially in an own process. We might see a race from window.parent.postMessage({status: "registrationdone"}, "*"); with the message arriving earlier in the SimpleTest.finish() than unregister finishing and propagating to the parent process presumably at the end of the unregister().then task boundary?

Flags: needinfo?(jstutte) → needinfo?(echuang)

It seems not the problem caused by test_hsts_upgrade_intercept.html.

According to the log

TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Left over worker: http://mochi.test:8888/tests/dom/serviceworkers/test/xslt_worker.js (scope: http://mochi.test:8888/tests/dom/serviceworkers/test/)

the remaining serviceworker is not from test_hsts_upgrade_intercept.html.
I think https://searchfox.org/mozilla-central/source/dom/serviceworkers/test/test_xslt.html doesn't clean up its serviceworker properly and pollute the test environment.

Maybe this is also the root cause of bug 1749068

Assignee: nobody → echuang
Flags: needinfo?(echuang)

Update:
There were 38 failures within the last 7 days:

  • 15 failures on OS X 10.15 WebRender opt
  • 7 failures on OS X 10.15 WebRender Shippable opt
  • 9 failures on Windows 10 x86 2004 WebRender opt
  • 7 failures on Windows 10 x86 2004 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=381052297&repo=autoland&lineNumber=5397

[task 2022-06-12T21:17:36.639Z] 21:17:36     INFO - TEST-PASS | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | The image request was upgraded before interception 
[task 2022-06-12T21:17:36.639Z] 21:17:36     INFO - Buffered messages finished
[task 2022-06-12T21:17:36.640Z] 21:17:36     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | This test left a service worker registered without cleaning it up 
[task 2022-06-12T21:17:36.640Z] 21:17:36     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:417:16
[task 2022-06-12T21:17:36.640Z] 21:17:36     INFO - afterCleanup@https://example.com/tests/SimpleTest/SimpleTest.js:1442:20
[task 2022-06-12T21:17:36.640Z] 21:17:36     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-06-12T21:17:36.640Z] 21:17:36     INFO - TEST-UNEXPECTED-FAIL | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | Left over worker: http://mochi.test:8888/tests/dom/serviceworkers/test/xslt_worker.js (scope: http://mochi.test:8888/tests/dom/serviceworkers/test/) 
[task 2022-06-12T21:17:36.640Z] 21:17:36     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:417:16
[task 2022-06-12T21:17:36.640Z] 21:17:36     INFO - afterCleanup@https://example.com/tests/SimpleTest/SimpleTest.js:1452:20
[task 2022-06-12T21:17:36.641Z] 21:17:36     INFO - GECKO(1992) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2022-06-12T21:17:36.641Z] 21:17:36     INFO - GECKO(1992) | MEMORY STAT | vsize 6587MB | residentFast 73MB | heapAllocated 10MB
[task 2022-06-12T21:17:36.641Z] 21:17:36     INFO - TEST-OK | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | took 1228ms

Jens, as the triage owner of this component, can you help us assign the bug to someone?
Thank you.

Flags: needinfo?(jstutte)

It seems likely given the query https://bugzilla.mozilla.org/buglist.cgi?quicksearch=This%20test%20left%20a%20service%20worker%20registered%20without%20cleaning%20it%20up&list_id=16114346 provided by Jens that there is a problem in our special powers logic where there's a race as it relates to unregister actually having completed sufficiently. This is surprising but there may be a subtlety with when the unregister job completion resolves compared with when we remove the registration from the map. I may have also looked at this in other bugs before too so I want to see if I have a prior analysis.

Assignee: echuang → bugmail
Status: REOPENED → ASSIGNED
Flags: needinfo?(jstutte) → needinfo?(bugmail)

Hi Andrew. This has 129 total failures in the last 30 days on

  • macosx1015-64-qr opt
  • macosx1015-64-shippable-qr opt
  • windows10-32-2004-qr opt
  • windows10-32-2004-shippable-qr opt

Should we disable it until there is a fix or leave it be as it is?

Whiteboard: [stockwell unknown][stockwell needswork:owner] → [stockwell needswork:owner]
Pushed by apavel@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/1d98c5a7861b
update disabling condition to include mac and opt builds r=intermittent-reviewers,jmaher DONTBUILD

(In reply to Andrew Sutherland [:asuth] (he/him) from comment #63)

It seems likely given the query https://bugzilla.mozilla.org/buglist.cgi?quicksearch=This%20test%20left%20a%20service%20worker%20registered%20without%20cleaning%20it%20up&list_id=16114346 provided by Jens that there is a problem in our special powers logic where there's a race as it relates to unregister actually having completed sufficiently. This is surprising but there may be a subtlety with when the unregister job completion resolves compared with when we remove the registration from the map. I may have also looked at this in other bugs before too so I want to see if I have a prior analysis.

Should we better file a concrete bug for this and close this one?

(In reply to Jens Stutte [:jstutte] from comment #71)

Should we better file a concrete bug for this and close this one?

Yes. I've filed bug 1819507 with a revised search query (because all the prior bugs were duped to single tracking bugs), and am marking this as fixed by :apavel by disabling the test, having edited the subject to clarify what the patches did.

Assignee: bugmail → apavel
Status: ASSIGNED → RESOLVED
Closed: 3 years ago1 year ago
Flags: needinfo?(bugmail)
Resolution: --- → FIXED
See Also: → 1819507
Summary: Intermittent dom/serviceworkers/test/test_hsts_upgrade_intercept.html | This test left a service worker registered without cleaning it up → Disable Intermittent dom/serviceworkers/test/test_hsts_upgrade_intercept.html | This test left a service worker registered without cleaning it up
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: