SharedWorker error should not propagate to window
Categories
(Core :: DOM: Workers, defect)
Tracking
()
People
(Reporter: intermittent-bug-filer, Assigned: evilpies)
References
(Blocks 1 open bug, Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [retriggered])
Attachments
(2 files, 1 obsolete file)
Filed by: dluca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=295521709&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/OxpX5nRlRTKW1r_axoci-A/runs/0/artifacts/public/logs/live_backing.log
INFO - TEST-START | /workers/semantics/reporting-errors/002.html
[task 2020-03-31T03:18:47.917Z] 03:18:47 INFO - Closing window 28
[task 2020-03-31T03:18:47.963Z] 03:18:47 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: '!mInitSucceeded', file /builds/worker/checkouts/gecko/editor/libeditor/TextEditSubActionHandler.cpp, line 102
[task 2020-03-31T03:18:48.004Z] 03:18:48 INFO - PID 7484 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-03-31T03:18:48.022Z] 03:18:48 INFO - PID 7484 | [Child 9724, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/checkouts/gecko/layout/base/nsPresContext.cpp, line 839
[task 2020-03-31T03:18:48.148Z] 03:18:48 INFO - PID 7484 | [Child 2484, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp, line 3352
[task 2020-03-31T03:18:48.167Z] 03:18:48 INFO - PID 7484 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1585622234\appdata\local\temp\tmpfajz3f\runtests_leaks_7316_tab_pid5044.log
[task 2020-03-31T03:18:48.185Z] 03:18:48 INFO - PID 7484 | [Child 5044, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp, line 721
[task 2020-03-31T03:18:48.186Z] 03:18:48 INFO - PID 7484 | nsStringStats
[task 2020-03-31T03:18:48.186Z] 03:18:48 INFO - PID 7484 | => mAllocCount: 10611
[task 2020-03-31T03:18:48.186Z] 03:18:48 INFO - PID 7484 | => mReallocCount: 0
[task 2020-03-31T03:18:48.186Z] 03:18:48 INFO - PID 7484 | => mFreeCount: 10611
[task 2020-03-31T03:18:48.186Z] 03:18:48 INFO - PID 7484 | => mShareCount: 17096
[task 2020-03-31T03:18:48.186Z] 03:18:48 INFO - PID 7484 | => mAdoptCount: 581
[task 2020-03-31T03:18:48.187Z] 03:18:48 INFO - PID 7484 | => mAdoptFreeCount: 589
[task 2020-03-31T03:18:48.187Z] 03:18:48 INFO - PID 7484 | => Process ID: 2484, Thread ID: 10048
[task 2020-03-31T03:18:48.247Z] 03:18:48 INFO - PID 7484 | [Child 9724, Main Thread] WARNING: '!aWin', file /builds/worker/checkouts/gecko/dom/base/Document.cpp, line 1397
[task 2020-03-31T03:18:48.247Z] 03:18:48 INFO - PID 7484 | [Child 9724, Main Thread] WARNING: '!aWin', file /builds/worker/checkouts/gecko/dom/base/Document.cpp, line 1397
[task 2020-03-31T03:18:48.286Z] 03:18:48 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: '!mName', file /builds/worker/checkouts/gecko/editor/libeditor/EditAggregateTransaction.cpp, line 91
[task 2020-03-31T03:18:48.286Z] 03:18:48 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: EditAggregationTransaction::GetName() failed: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/editor/libeditor/PlaceholderTransaction.cpp, line 217
[task 2020-03-31T03:18:48.286Z] 03:18:48 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: nsIAbsorbingTransaction::GetTxnName() failed, but ignored: 'NS_SUCCEEDED(rvIgnored)', file /builds/worker/checkouts/gecko/editor/libeditor/PlaceholderTransaction.cpp, line 188
[task 2020-03-31T03:18:48.386Z] 03:18:48 INFO - PID 7484 | [Child 9724, Main Thread] WARNING: Workers don't support the 'mem.mem.' preference!: file /builds/worker/checkouts/gecko/dom/workers/RuntimeService.cpp, line 538
[task 2020-03-31T03:18:48.514Z] 03:18:48 INFO -
[task 2020-03-31T03:18:48.514Z] 03:18:48 INFO - TEST-UNEXPECTED-PASS | /workers/semantics/reporting-errors/002.html | shared worker, addEventListener - expected FAIL
[task 2020-03-31T03:18:48.514Z] 03:18:48 INFO - TEST-INFO | expected FAIL
[task 2020-03-31T03:18:48.515Z] 03:18:48 INFO - TEST-OK | /workers/semantics/reporting-errors/002.html | took 605ms
[task 2020-03-31T03:18:48.534Z] 03:18:48 INFO - PID 7484 | 1585624728530 Marionette INFO Stopped listening on port 55599
[task 2020-03-31T03:18:48.776Z] 03:18:48 INFO - PID 7484 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-03-31T03:18:48.786Z] 03:18:48 INFO - PID 7484 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-03-31T03:18:48.909Z] 03:18:48 INFO - PID 7484 | [2020-03-31T03:18:48Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2020-03-31T03:18:48.909Z] 03:18:48 INFO - PID 7484 | [2020-03-31T03:18:48Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2020-03-31T03:18:48.914Z] 03:18:48 INFO - PID 7484 | [Child 9888, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp, line 3352
[task 2020-03-31T03:18:48.933Z] 03:18:48 INFO - PID 7484 | [Child 9724, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp, line 3352
[task 2020-03-31T03:18:48.942Z] 03:18:48 INFO - PID 7484 | nsStringStats
[task 2020-03-31T03:18:48.942Z] 03:18:48 INFO - PID 7484 | => mAllocCount: 9635
[task 2020-03-31T03:18:48.942Z] 03:18:48 INFO - PID 7484 | => mReallocCount: 0
[task 2020-03-31T03:18:48.942Z] 03:18:48 INFO - PID 7484 | => mFreeCount: 9635
[task 2020-03-31T03:18:48.942Z] 03:18:48 INFO - PID 7484 | => mShareCount: 14573
[task 2020-03-31T03:18:48.943Z] 03:18:48 INFO - PID 7484 | => mAdoptCount: 514
[task 2020-03-31T03:18:48.943Z] 03:18:48 INFO - PID 7484 | => mAdoptFreeCount: 518
[task 2020-03-31T03:18:48.943Z] 03:18:48 INFO - PID 7484 | => Process ID: 9888, Thread ID: 10704
[task 2020-03-31T03:18:48.943Z] 03:18:48 INFO - PID 7484 | [Child 11060, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp, line 3352
[task 2020-03-31T03:18:48.962Z] 03:18:48 INFO - PID 7484 | nsStringStats
[task 2020-03-31T03:18:48.962Z] 03:18:48 INFO - PID 7484 | => mAllocCount: 8285
[task 2020-03-31T03:18:48.963Z] 03:18:48 INFO - PID 7484 | => mReallocCount: 0
[task 2020-03-31T03:18:48.963Z] 03:18:48 INFO - PID 7484 | => mFreeCount: 8285
[task 2020-03-31T03:18:48.963Z] 03:18:48 INFO - PID 7484 | => mShareCount: 7704
[task 2020-03-31T03:18:48.964Z] 03:18:48 INFO - PID 7484 | => mAdoptCount: 448
[task 2020-03-31T03:18:48.964Z] 03:18:48 INFO - PID 7484 | => mAdoptFreeCount: 456
[task 2020-03-31T03:18:48.964Z] 03:18:48 INFO - PID 7484 | => Process ID: 9724, Thread ID: 9508
[task 2020-03-31T03:18:48.969Z] 03:18:48 INFO - PID 7484 | nsStringStats
[task 2020-03-31T03:18:48.969Z] 03:18:48 INFO - PID 7484 | => mAllocCount: 23422
[task 2020-03-31T03:18:48.970Z] 03:18:48 INFO - PID 7484 | => mReallocCount: 0
[task 2020-03-31T03:18:48.970Z] 03:18:48 INFO - PID 7484 | => mFreeCount: 23422
[task 2020-03-31T03:18:48.970Z] 03:18:48 INFO - PID 7484 | => mShareCount: 18160
[task 2020-03-31T03:18:48.970Z] 03:18:48 INFO - PID 7484 | => mAdoptCount: 448
[task 2020-03-31T03:18:48.970Z] 03:18:48 INFO - PID 7484 | => mAdoptFreeCount: 480
[task 2020-03-31T03:18:48.970Z] 03:18:48 INFO - PID 7484 | => Process ID: 11060, Thread ID: 7372
[task 2020-03-31T03:18:49.214Z] 03:18:49 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp, line 476
[task 2020-03-31T03:18:49.214Z] 03:18:49 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp, line 11402
[task 2020-03-31T03:18:49.214Z] 03:18:49 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp, line 476
[task 2020-03-31T03:18:49.215Z] 03:18:49 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp, line 11402
[task 2020-03-31T03:18:49.217Z] 03:18:49 INFO - PID 7484 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-03-31T03:18:49.217Z] 03:18:49 INFO - PID 7484 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-03-31T03:18:49.235Z] 03:18:49 INFO - PID 7484 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-03-31T03:18:49.265Z] 03:18:49 INFO - PID 7484 | nsStringStats
[task 2020-03-31T03:18:49.265Z] 03:18:49 INFO - PID 7484 | => mAllocCount: 5472
[task 2020-03-31T03:18:49.265Z] 03:18:49 INFO - PID 7484 | => mReallocCount: 0
[task 2020-03-31T03:18:49.266Z] 03:18:49 INFO - PID 7484 | => mFreeCount: 5472
[task 2020-03-31T03:18:49.266Z] 03:18:49 INFO - PID 7484 | => mShareCount: 2953
[task 2020-03-31T03:18:49.267Z] 03:18:49 INFO - PID 7484 | => mAdoptCount: 72
[task 2020-03-31T03:18:49.267Z] 03:18:49 INFO - PID 7484 | => mAdoptFreeCount: 72
[task 2020-03-31T03:18:49.267Z] 03:18:49 INFO - PID 7484 | => Process ID: 5044, Thread ID: 8856
[task 2020-03-31T03:18:49.269Z] 03:18:49 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x80070057: file /builds/worker/checkouts/gecko/extensions/permissions/nsPermissionManager.cpp, line 1663
[task 2020-03-31T03:18:49.411Z] 03:18:49 INFO - PID 7484 | [Child 3012, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp, line 3352
[task 2020-03-31T03:18:49.430Z] 03:18:49 INFO - PID 7484 | nsStringStats
[task 2020-03-31T03:18:49.430Z] 03:18:49 INFO - PID 7484 | => mAllocCount: 11575
[task 2020-03-31T03:18:49.430Z] 03:18:49 INFO - PID 7484 | => mReallocCount: 0
[task 2020-03-31T03:18:49.430Z] 03:18:49 INFO - PID 7484 | => mFreeCount: 11575
[task 2020-03-31T03:18:49.430Z] 03:18:49 INFO - PID 7484 | => mShareCount: 21014
[task 2020-03-31T03:18:49.431Z] 03:18:49 INFO - PID 7484 | => mAdoptCount: 573
[task 2020-03-31T03:18:49.431Z] 03:18:49 INFO - PID 7484 | => mAdoptFreeCount: 577
[task 2020-03-31T03:18:49.431Z] 03:18:49 INFO - PID 7484 | => Process ID: 3012, Thread ID: 6196
[task 2020-03-31T03:18:49.436Z] 03:18:49 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: NS_ENSURE_TRUE(mDB) failed: file /builds/worker/checkouts/gecko/netwerk/cache/nsDiskCacheDeviceSQL.cpp, line 1279
[task 2020-03-31T03:18:49.436Z] 03:18:49 INFO - PID 7484 | ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-03-31T03:18:49.457Z] 03:18:49 INFO - PID 7484 | nsStringStats
[task 2020-03-31T03:18:49.457Z] 03:18:49 INFO - PID 7484 | => mAllocCount: 2285
[task 2020-03-31T03:18:49.458Z] 03:18:49 INFO - PID 7484 | => mReallocCount: 0
[task 2020-03-31T03:18:49.458Z] 03:18:49 INFO - PID 7484 | => mFreeCount: 2285
[task 2020-03-31T03:18:49.458Z] 03:18:49 INFO - PID 7484 | => mShareCount: 434
[task 2020-03-31T03:18:49.458Z] 03:18:49 INFO - PID 7484 | => mAdoptCount: 0
[task 2020-03-31T03:18:49.458Z] 03:18:49 INFO - PID 7484 | => mAdoptFreeCount: 0
[task 2020-03-31T03:18:49.459Z] 03:18:49 INFO - PID 7484 | => Process ID: 6964, Thread ID: 8204
[task 2020-03-31T03:18:49.489Z] 03:18:49 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/worker/checkouts/gecko/js/xpconnect/loader/mozJSComponentLoader.cpp, line 228
[task 2020-03-31T03:18:49.489Z] 03:18:49 INFO - PID 7484 | [Parent 1288, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/worker/checkouts/gecko/js/xpconnect/loader/mozJSComponentLoader.cpp, line 255
[task 2020-03-31T03:18:50.210Z] 03:18:50 INFO - PID 7484 | nsStringStats
[task 2020-03-31T03:18:50.210Z] 03:18:50 INFO - PID 7484 | => mAllocCount: 144724
[task 2020-03-31T03:18:50.210Z] 03:18:50 INFO - PID 7484 | => mReallocCount: 0
[task 2020-03-31T03:18:50.210Z] 03:18:50 INFO - PID 7484 | => mFreeCount: 144724
[task 2020-03-31T03:18:50.211Z] 03:18:50 INFO - PID 7484 | => mShareCount: 154644
[task 2020-03-31T03:18:50.211Z] 03:18:50 INFO - PID 7484 | => mAdoptCount: 2681
[task 2020-03-31T03:18:50.211Z] 03:18:50 INFO - PID 7484 | => mAdoptFreeCount: 2781
[task 2020-03-31T03:18:50.211Z] 03:18:50 INFO - PID 7484 | => Process ID: 1288, Thread ID: 8612
[task 2020-03-31T03:18:50.249Z] 03:18:50 INFO - Browser exited with return code 0
Comment 1•5 years ago
|
||
Please take a look at this bug as is a regression of Bug 1623226
Updated•5 years ago
|
Updated•5 years ago
|
Comment 2•5 years ago
|
||
Updated•5 years ago
|
Comment 3•5 years ago
|
||
Updated•5 years ago
|
Updated•5 years ago
|
Assignee | ||
Comment 7•5 years ago
|
||
We should figure out why this is intermittent.
Assignee | ||
Comment 8•5 years ago
|
||
So from what I understand this test seems to assume that an error inside a shared worker doesn't propagate to window.onerror
.
I think what happens is that sometimes window.onerror
is invoked after worker.port.onmessage
already finished successfully.
Comment 9•5 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Comment 11•5 years ago
|
||
There are several issues here.
The first one is that window.onerror should not be called.
https://html.spec.whatwg.org/multipage/workers.html#runtime-script-errors-2
"For shared workers, if the error is still not handled afterwards, the error may be reported to a developer console."
This means that basically all of this code should be removed:
https://searchfox.org/mozilla-central/rev/fa2df28a49883612bd7af4dacd80cdfedcccd2f6/dom/workers/sharedworkers/SharedWorkerChild.cpp#76-149
The second issue is that we don't log the error propertly because we don't pass the correct windowId here:
https://searchfox.org/mozilla-central/rev/fa2df28a49883612bd7af4dacd80cdfedcccd2f6/dom/workers/sharedworkers/SharedWorkerChild.cpp#72
We should take the window ID from mParent->GetOwner()
Third issue, this comment is invalid:
https://searchfox.org/mozilla-central/rev/fa2df28a49883612bd7af4dacd80cdfedcccd2f6/dom/workers/sharedworkers/SharedWorkerChild.cpp#71
We do broadcast the same message to all the active SharedWorker actor. See:
https://searchfox.org/mozilla-central/rev/fa2df28a49883612bd7af4dacd80cdfedcccd2f6/dom/workers/sharedworkers/SharedWorkerManager.cpp#215-217,228-230
So, just drop that comment.
Finally! the error event in the SharedWorker receives wrong parameters. The second argument should be the the filename but we pass an empty string.
Assignee | ||
Updated•5 years ago
|
Assignee | ||
Comment 12•5 years ago
|
||
Thank you. I wrote a patch based on your comment, which fixes all report-errors tests. I still need to run other tests.
(In reply to Andrea Marchesini [:baku] from comment #11)
Finally! the error event in the SharedWorker receives wrong parameters. The second argument should be the the filename but we pass an empty string.
That should have been fixed by bug 1623226. I get the right filename in 001.js.
We still do error propagation for nsresult (source). I think this is related to the actual creation of the worker, so it should probably stay.
Assignee | ||
Comment 13•5 years ago
|
||
Comment 14•5 years ago
|
||
(In reply to Andrea Marchesini [:baku] from comment #11)
There are several issues here.
The first one is that window.onerror should not be called.
https://html.spec.whatwg.org/multipage/workers.html#runtime-script-errors-2
"For shared workers, if the error is still not handled afterwards, the error may be reported to a developer console."
Note that there has been recent discussion about this. https://github.com/whatwg/html/issues/5323 had a discussion of reporting runtime errors which has been spun off into https://github.com/whatwg/html/issues/5363.
That said, the discussion doesn't need to impact these changes, I just want to xref the discussions.
Assignee | ||
Comment 15•5 years ago
|
||
So there a quite a few failures: https://treeherder.mozilla.org/#/jobs?repo=try&revision=116479c6c7e0f6a1464629cc74523e58c6be61c0
Assignee | ||
Comment 16•5 years ago
|
||
Ah we should presumably still fire the error
event on the SharedWorker reference, just not on the window: https://searchfox.org/mozilla-central/source/testing/web-platform/tests/workers/modules/shared-worker-import.any.js#13
Assignee | ||
Updated•5 years ago
|
Assignee | ||
Comment 17•5 years ago
|
||
I think I am passing all tests now.
http://wpt.live/workers/shared-worker-parse-error-failure.html is a weird failure. We produce an ErrorEvent
instead of Event
. That sounds reasonable to me.
Updated•5 years ago
|
Assignee | ||
Comment 19•5 years ago
|
||
There must still be something wrong that I don't understand. This test fails: https://searchfox.org/mozilla-central/source/testing/web-platform/tests/workers/semantics/reporting-errors/003.html (as well as 004.html)
So it seems like we should still suppress the error event when it's not handled? I don't understand this behavior at all. Considering that without the error even we seem to fail other tests.
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 22•5 years ago
|
||
I understand https://treeherder.mozilla.org/#/jobs?repo=try&author=evilpies%40gmail.com&selectedJob=295855832 to be the job where 003 and 004 are failing. The errors reported are:
- 003: shared worker, no error event on worker or port - assert_unreached: error on worker Reached unreachable code which comes from here
- 004: shared worker in two documents and window.onerror - assert_unreached: (outer) error on worker Reached unreachable code which is basically the same error and comes from here
So the tests are failing because we're reporting runtime errors, which, per my understanding of the spec, we shouldn't do.
(In reply to Tom Schuster [:evilpie] from comment #16)
Ah we should presumably still fire the
error
event on the SharedWorker reference, just not on the window: https://searchfox.org/mozilla-central/source/testing/web-platform/tests/workers/modules/shared-worker-import.any.js#13
I think this is where the confusion is. The current spec dictates that we only generate errors for:
- Fetch errors. (It's always been this way.)
- Parse errors. (New! Spec PR is https://github.com/whatwg/html/pull/5347, tests PR is https://github.com/web-platform-tests/wpt/pull/22185)
Either the test is intending to only catch those types of errors or the test is oblivious to current limitations on thrown errors.
Assignee | ||
Comment 23•5 years ago
|
||
That is pretty big difference. Right now we seem to create the error events for all runtime errors as well. So this probably means we need to properly annotate the error "kind" (parse/fetch) before sending it.
I think I will land this patch with just my current changes and disabling those two tests. It still seems like an improvement, especially now that we log errors to the right console.
Comment 24•5 years ago
|
||
Comment 25•5 years ago
|
||
Yes, we have been creating the error events for all runtime errors. It's also the case that there's spec discussion about at least reporting top-level evaluation errors and dealing with fundamental races in additional SharedWorkers joining the backing SharedWorkerGlobalScope. So it's very appropriate to not overhaul things that might then need to be un-overhauled! (Top-level evaluation errors being much easier to report, with specific control flow already in place thanks to ServiceWorker.)
Thanks very much for the cleanup and especially the console fix!
Comment 26•5 years ago
|
||
bugherder |
Assignee | ||
Updated•5 years ago
|
Description
•