Closed Bug 1540921 Opened 1 year ago Closed 7 months ago

Intermittent /workers/WorkerGlobalScope-close.html | Test sending a message after closing. -

Categories

(Core :: DOM: Workers, defect, P3)

Product:
Core
Component:
DOM: Workers
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla73
Tracking Flags:
Tracking Status
firefox-esr68 --- fixed
firefox71 --- wontfix
firefox72 --- fixed
firefox73 --- fixed

People

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

Details

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

Attachments

(1 file)

Bug 1540921 - try...catch postMessage call to a potentially closing/closed DedicatedWorker r?asuth
47 bytes, text/x-phabricator-request
jcristau
: approval-mozilla-beta+
RyanVM
: approval-mozilla-esr68+
Details | Review

#[markdown(off)]
Filed by: nbeleuzu [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=237487100&repo=autoland

https://queue.taskcluster.net/v1/task/f8mJyFPqRyqv2i2O18V3hw/runs/0/artifacts/public/logs/live_backing.log

03:52:29 INFO - TEST-START | /workers/WorkerGlobalScope-close.html
03:52:29 INFO - Closing window 79456894977
03:52:30 INFO -
03:52:30 INFO - TEST-PASS | /workers/WorkerGlobalScope-close.html | Test type of close function.
03:52:30 INFO - TEST-UNEXPECTED-FAIL | /workers/WorkerGlobalScope-close.html | Test sending a message after closing. -
03:52:30 INFO - worker.onmessage<@http://web-platform.test:8000/workers/WorkerGlobalScope-close.html:26:12
03:52:30 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1587:25
03:52:30 INFO - Test.prototype.step_func/<@http://web-platform.test:8000/resources/testharness.js:1611:35
03:52:30 INFO - EventHandlerNonNull*@http://web-platform.test:8000/workers/WorkerGlobalScope-close.html:19:26
03:52:30 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1587:25
03:52:30 INFO - async_test@http://web-platform.test:8000/resources/testharness.js:576:22
03:52:30 INFO - @http://web-platform.test:8000/workers/WorkerGlobalScope-close.html:16:1

Priority: -- → P3

Jens can you assign someone to take a look at this?

There are 25 total failures in the last 7 days

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=277585019&repo=mozilla-central&lineNumber=98385

[task 2019-11-22T10:53:59.700Z] 10:53:59 INFO - TEST-START | /workers/WorkerGlobalScope-close.html
[task 2019-11-22T10:53:59.715Z] 10:53:59 INFO - Closing window 107
[task 2019-11-22T10:53:59.825Z] 10:53:59 INFO - PID 29109 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-11-22T10:53:59.845Z] 10:53:59 INFO - PID 29109 | ++DOCSHELL 0x7f51457c4000 == 1 [pid = 30625] [id = {bfaae23d-06cf-4b16-86e1-65e86406982f}]
[task 2019-11-22T10:53:59.922Z] 10:53:59 INFO - PID 29109 | ++DOMWINDOW == 1 (0x7f51457dcf20) [pid = 30625] [serial = 1] [outer = (nil)]
[task 2019-11-22T10:53:59.923Z] 10:53:59 INFO - PID 29109 | ++DOMWINDOW == 2 (0x7f5146a26000) [pid = 30625] [serial = 2] [outer = 0x7f51457dcf20]
[task 2019-11-22T10:54:00.000Z] 10:53:59 INFO - PID 29109 | --DOCSHELL 0x7f55f63c4000 == 0 [pid = 30594] [id = {8d517f71-9485-43a4-bda5-369119735934}] [url = http://web-platform.test:8000/workers/Worker-timeout-increasing-order.html]
[task 2019-11-22T10:54:00.063Z] 10:54:00 INFO - PID 29109 | --DOMWINDOW == 3 (0x7f55f6384400) [pid = 30594] [serial = 4] [outer = (nil)] [url = http://web-platform.test:8000/workers/Worker-timeout-increasing-order.html]
[task 2019-11-22T10:54:00.065Z] 10:54:00 INFO - PID 29109 | --DOMWINDOW == 2 (0x7f55f6309f20) [pid = 30594] [serial = 1] [outer = (nil)] [url = http://web-platform.test:8000/workers/Worker-timeout-increasing-order.html]
[task 2019-11-22T10:54:00.066Z] 10:54:00 INFO - PID 29109 | --DOMWINDOW == 1 (0x7f55f622e000) [pid = 30594] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-11-22T10:54:00.068Z] 10:54:00 INFO - PID 29109 | --DOMWINDOW == 0 (0x7f55f6380400) [pid = 30594] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2019-11-22T10:54:00.128Z] 10:54:00 INFO - PID 29109 | nsStringStats
[task 2019-11-22T10:54:00.128Z] 10:54:00 INFO - PID 29109 | => mAllocCount: 8149
[task 2019-11-22T10:54:00.128Z] 10:54:00 INFO - PID 29109 | => mReallocCount: 0
[task 2019-11-22T10:54:00.128Z] 10:54:00 INFO - PID 29109 | => mFreeCount: 8149
[task 2019-11-22T10:54:00.128Z] 10:54:00 INFO - PID 29109 | => mShareCount: 7304
[task 2019-11-22T10:54:00.128Z] 10:54:00 INFO - PID 29109 | => mAdoptCount: 434
[task 2019-11-22T10:54:00.128Z] 10:54:00 INFO - PID 29109 | => mAdoptFreeCount: 442
[task 2019-11-22T10:54:00.128Z] 10:54:00 INFO - PID 29109 | => Process ID: 30594, Thread ID: 140007642953536
[task 2019-11-22T10:54:00.165Z] 10:54:00 INFO - PID 29109 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpokDY1T.mozrunner/runtests_leaks_865_tab_pid30656.log
[task 2019-11-22T10:54:00.180Z] 10:54:00 INFO - PID 29109 | [Child 30656, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 729
[task 2019-11-22T10:54:00.298Z] 10:54:00 INFO - PID 29109 | ++DOMWINDOW == 3 (0x7f5146a2ec00) [pid = 30625] [serial = 3] [outer = 0x7f51457dcf20]
[task 2019-11-22T10:54:00.302Z] 10:54:00 INFO - PID 29109 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-11-22T10:54:00.451Z] 10:54:00 INFO - PID 29109 | [Child 30656, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1799
[task 2019-11-22T10:54:00.451Z] 10:54:00 INFO - PID 29109 | ++DOMWINDOW == 4 (0x7f5146b5d400) [pid = 30625] [serial = 4] [outer = 0x7f51457dcf20]
[task 2019-11-22T10:54:00.560Z] 10:54:00 INFO - PID 29109 | [Child 30625, Main Thread] WARNING: Workers don't support the 'mem.mem.' preference!: file /builds/worker/workspace/build/src/dom/workers/RuntimeService.cpp, line 547
[task 2019-11-22T10:54:00.738Z] 10:54:00 INFO - PID 29109 | [Child 30625, Main Thread] WARNING: A runnable was posted to a worker that is already shutting down!: file /builds/worker/workspace/build/src/dom/workers/WorkerPrivate.cpp, line 1418
[task 2019-11-22T10:54:02.326Z] 10:54:02 INFO -
[task 2019-11-22T10:54:02.326Z] 10:54:02 INFO - TEST-PASS | /workers/WorkerGlobalScope-close.html | Test type of close function.
[task 2019-11-22T10:54:02.327Z] 10:54:02 INFO - TEST-UNEXPECTED-FAIL | /workers/WorkerGlobalScope-close.html | Test sending a message after closing. -
[task 2019-11-22T10:54:02.327Z] 10:54:02 INFO - worker.onmessage<@http://web-platform.test:8000/workers/WorkerGlobalScope-close.html:26:12
[task 2019-11-22T10:54:02.327Z] 10:54:02 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1908:25
[task 2019-11-22T10:54:02.328Z] 10:54:02 INFO - Test.prototype.step_func/<@http://web-platform.test:8000/resources/testharness.js:1932:35
[task 2019-11-22T10:54:02.328Z] 10:54:02 INFO - EventHandlerNonNull*@http://web-platform.test:8000/workers/WorkerGlobalScope-close.html:19:26
[task 2019-11-22T10:54:02.328Z] 10:54:02 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1908:25
[task 2019-11-22T10:54:02.329Z] 10:54:02 INFO - async_test@http://web-platform.test:8000/resources/testharness.js:576:22
[task 2019-11-22T10:54:02.329Z] 10:54:02 INFO - @http://web-platform.test:8000/workers/WorkerGlobalScope-close.html:16:11
[task 2019-11-22T10:54:02.329Z] 10:54:02 INFO - ...
[task 2019-11-22T10:54:02.330Z] 10:54:02 INFO - TEST-OK | /workers/WorkerGlobalScope-close.html | took 2626ms

Flags: needinfo?(jstutte)

I removed the priority to re-triage it.

Flags: needinfo?(jstutte)
Priority: P3 → --
Priority: -- → P3

_perry, can you please have a short look?

Flags: needinfo?(perry)

There are 14 total failures in the last 7 days on android-em-7-0-x86_64 debug and opt, linux32-shippable opt, macosx1014-64 debug and macosx1014-64-shippable opt.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=278960814&repo=mozilla-central&lineNumber=8021

[task 2019-12-01T22:17:42.139Z] 22:17:42 INFO - TEST-START | /workers/WorkerGlobalScope-close.html
[task 2019-12-01T22:17:42.147Z] 22:17:42 INFO - Closing window 174
[task 2019-12-01T22:17:43.962Z] 22:17:43 INFO -
[task 2019-12-01T22:17:43.962Z] 22:17:43 INFO - TEST-PASS | /workers/WorkerGlobalScope-close.html | Test type of close function.
[task 2019-12-01T22:17:43.962Z] 22:17:43 INFO - TEST-UNEXPECTED-FAIL | /workers/WorkerGlobalScope-close.html | Test sending a message after closing. -
[task 2019-12-01T22:17:43.962Z] 22:17:43 INFO - worker.onmessage<@http://web-platform.test:8000/workers/WorkerGlobalScope-close.html:26:12
[task 2019-12-01T22:17:43.962Z] 22:17:43 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1984:25
[task 2019-12-01T22:17:43.962Z] 22:17:43 INFO - Test.prototype.step_func/<@http://web-platform.test:8000/resources/testharness.js:2009:35
[task 2019-12-01T22:17:44.286Z] 22:17:44 INFO - ...
[task 2019-12-01T22:17:44.286Z] 22:17:44 INFO - TEST-OK | /workers/WorkerGlobalScope-close.html | took 2146ms

Whiteboard: [stockwell unknown] → [stockwell needswork:owner]

The test postMessages a worker for it to close itself and then postMessages the closed worker again. By the second postMessage the worker might already be closing/closed, in which case it won't be able to enqueue the message and our implementation throws. I don't see clear answer in the spec on how to handle this situation, but I looked at Chromium/Webkit source and it looks like they don't throw.

Flags: needinfo?(perry)
Assignee: nobody → perry
Attachment #9113548 - Attachment description: Bug 1540921 - try...catch postMessage call to a potentially closing/closed DedicatedWorker r?asuth → Bug 1540921 - don't throw when postMessage-ing a closing/closed DedicatedWorker r?asuth
Pushed by pjiang@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/45555bb975a2
don't throw when postMessage-ing a closing/closed DedicatedWorker r=asuth
Created web-platform-tests PR https://github.com/web-platform-tests/wpt/pull/20625 for changes under testing/web-platform/tests
Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner], [wptsync upstream]
Upstream web-platform-tests status checks passed, PR will merge once commit reaches central.

https://hg.mozilla.org/mozilla-central/rev/45555bb975a2

Status: NEW → RESOLVED
Closed: 7 months ago
status-firefox73: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla73
Upstream PR merged by moz-wptsync-bot

Please nominate this for Beta and ESR68 approval when you get a chance. It grafts cleanly as-landed.

status-firefox71: --- → wontfix
status-firefox72: --- → affected
status-firefox-esr68: --- → affected
Flags: needinfo?(perry)

Comment on attachment 9113548 [details]
Bug 1540921 - try...catch postMessage call to a potentially closing/closed DedicatedWorker r?asuth

ESR Uplift Approval Request

  • If this is not a sec:{high,crit} bug, please state case for ESR consideration: The patch makes Worker.postMessage behave more closely with what websites should expect.
  • User impact if declined: Worker.postMessage will be less consistent with the specification and may throw unexpectedly and non-deterministically.
  • Fix Landed on Version: 73
  • Risk to taking this patch: Low
  • Why is the change risky/not risky? (and alternatives if risky): It's not risky because it prevents Worker.postMessage from throwing an exception when it really shouldn't, which makes the implementation more consistent with its expectation, which is the behavior websites should expect.
  • String or UUID changes made by this patch:

Beta/Release Uplift Approval Request

  • User impact if declined: Worker.postMessage will be less consistent with its specification and may throw unexpectedly and non-deterministically.
  • Is this code covered by automated tests?: Yes
  • Has the fix been verified in Nightly?: No
  • Needs manual test from QE?: No
  • If yes, steps to reproduce:
  • List of other uplifts needed: None
  • Risk to taking this patch: Low
  • Why is the change risky/not risky? (and alternatives if risky): It's not risky because it prevents Worker.postMessage from throwing an exception when it really shouldn't, which makes the implementation more consistent with its expectation, which is the behavior websites should expect.
  • String changes made/needed:
Attachment #9113548 - Attachment description: Bug 1540921 - don't throw when postMessage-ing a closing/closed DedicatedWorker r?asuth → Bug 1540921 - try...catch postMessage call to a potentially closing/closed DedicatedWorker r?asuth
Flags: needinfo?(perry)
Attachment #9113548 - Flags: approval-mozilla-esr68?
Attachment #9113548 - Flags: approval-mozilla-beta?

Comment on attachment 9113548 [details]
Bug 1540921 - try...catch postMessage call to a potentially closing/closed DedicatedWorker r?asuth

workers fix, approved for 72.0b4

Attachment #9113548 - Flags: approval-mozilla-beta? → approval-mozilla-beta+

Comment on attachment 9113548 [details]
Bug 1540921 - try...catch postMessage call to a potentially closing/closed DedicatedWorker r?asuth

Approved for 68.4esr also.

Attachment #9113548 - Flags: approval-mozilla-esr68? → approval-mozilla-esr68+
You need to log in before you can comment on or make changes to this bug.