Closed Bug 1478850 Opened 6 years ago Closed 6 years ago

Intermittent dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html, dom/serviceworkers/test/test_fetch_event.html | application crashed [@ JS::ReadableStreamDefaultReaderRead(JSContext*, JS::Handle<JSObject*>)]

Categories

(Core :: DOM: Service Workers, defect, P1)

Product:
Core
Component:
DOM: Service Workers
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla65
Tracking Flags:
Tracking Status
firefox-esr60 --- unaffected
firefox63 --- wontfix
firefox64 --- wontfix
firefox65 --- fixed

People

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

References

(Blocks 1 open bug)

Details

(Keywords: crash, intermittent-failure)

Crash Data

Attachments

(2 files)

Bug 1478850 - Safely handle nuked wrappers as arguments to stream-related JSAPI entry points. r?tcampbell
47 bytes, text/x-phabricator-request
Details | Review
fix.patch
1.17 KB, patch
smaug
: review+
Details | Diff | Splinter Review
Filed by: btara [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=190370625&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/YZ2TDzg5SyyNmSYeRVmbQQ/runs/0/artifacts/public/logs/live_backing.log [task 2018-07-26T20:51:19.242Z] 20:51:19 INFO - 319 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | Valid CORS request should receive valid response [task 2018-07-26T20:51:19.242Z] 20:51:19 INFO - 320 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | Response type should be CORS [task 2018-07-26T20:51:19.243Z] 20:51:19 INFO - 321 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | Response type should be opaque [task 2018-07-26T20:51:19.243Z] 20:51:19 INFO - 322 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | Status should be 0 [task 2018-07-26T20:51:19.244Z] 20:51:19 INFO - 323 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | cors response body should match [task 2018-07-26T20:51:19.244Z] 20:51:19 INFO - 324 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | opaque response body should be empty [task 2018-07-26T20:51:19.245Z] 20:51:19 INFO - 325 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | load should be successful [task 2018-07-26T20:51:19.245Z] 20:51:19 INFO - 326 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | Redirect to real file should complete. [task 2018-07-26T20:51:29.556Z] 20:51:29 INFO - 327 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | synth+redirect+synth load should be successful [task 2018-07-26T20:51:29.556Z] 20:51:29 INFO - 328 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | load should have redirected+synthesized response [task 2018-07-26T20:51:29.557Z] 20:51:29 INFO - 329 INFO TEST-PASS | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | worker load intercepted [task 2018-07-26T20:51:50.701Z] 20:51:50 INFO - INFO | automation.py | Application ran for: 0:10:07.699737 [task 2018-07-26T20:51:50.701Z] 20:51:50 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmp0WGXwgpidlog [task 2018-07-26T20:51:51.324Z] 20:51:51 INFO - /data/tombstones does not exist; tombstone check skipped [task 2018-07-26T20:51:52.144Z] 20:51:52 INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpf7LkqC/72b1aacf-7582-1053-5efb-bf706170fb6c.dmp /builds/worker/workspace/build/symbols [task 2018-07-26T20:52:01.275Z] 20:52:01 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/72b1aacf-7582-1053-5efb-bf706170fb6c.dmp [task 2018-07-26T20:52:01.275Z] 20:52:01 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/72b1aacf-7582-1053-5efb-bf706170fb6c.extra [task 2018-07-26T20:52:01.278Z] 20:52:01 WARNING - PROCESS-CRASH | dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | application crashed [@ JS::ReadableStreamDefaultReaderRead(JSContext*, JS::Handle<JSObject*>)] [task 2018-07-26T20:52:01.278Z] 20:52:01 INFO - Crash dump filename: /tmp/tmpf7LkqC/72b1aacf-7582-1053-5efb-bf706170fb6c.dmp [task 2018-07-26T20:52:01.279Z] 20:52:01 INFO - Operating system: Android [task 2018-07-26T20:52:01.279Z] 20:52:01 INFO - 0.0.0 Linux 2.6.29-gea477bb #1 Wed Sep 26 11:04:45 PDT 2012 armv7l [task 2018-07-26T20:52:01.279Z] 20:52:01 INFO - CPU: arm [task 2018-07-26T20:52:01.280Z] 20:52:01 INFO - ARMv7 ARM Cortex-A8 features: swp,half,thumb,fastmult,vfpv2,edsp,neon,vfpv3 [task 2018-07-26T20:52:01.280Z] 20:52:01 INFO - 1 CPU [task 2018-07-26T20:52:01.281Z] 20:52:01 INFO - GPU: UNKNOWN [task 2018-07-26T20:52:01.281Z] 20:52:01 INFO - Crash reason: SIGSEGV [task 2018-07-26T20:52:01.281Z] 20:52:01 INFO - Crash address: 0x0 [task 2018-07-26T20:52:01.281Z] 20:52:01 INFO - Process uptime: not available [task 2018-07-26T20:52:01.282Z] 20:52:01 INFO - Thread 48 (crashed) [task 2018-07-26T20:52:01.282Z] 20:52:01 INFO - 0 libxul.so!JS::ReadableStreamDefaultReaderRead(JSContext*, JS::Handle<JSObject*>) [RootingAPI.h:3268a54a7fab9e9565038d589229e9f2bf1cdff9 : 0 + 0x6] [task 2018-07-26T20:52:01.283Z] 20:52:01 INFO - r0 = 0x00000000 r1 = 0xb2b80778 r2 = 0xb2b80778 r3 = 0xb2b80778 [task 2018-07-26T20:52:01.283Z] 20:52:01 INFO - r4 = 0x00000213 r5 = 0x60cfb060 r6 = 0x60cfb064 r7 = 0x60cfb038 [task 2018-07-26T20:52:01.283Z] 20:52:01 INFO - r8 = 0x60cfb04c r9 = 0x00000000 r10 = 0x60cfb058 r12 = 0x00000003 [task 2018-07-26T20:52:01.284Z] 20:52:01 INFO - fp = 0x535384b1 sp = 0x60cfb020 lr = 0x55817ff7 pc = 0x55c2cf32 [task 2018-07-26T20:52:01.284Z] 20:52:01 INFO - Found by: given as instruction pointer in context [task 2018-07-26T20:52:01.285Z] 20:52:01 INFO - 1 libxul.so!mozilla::dom::FetchStreamReader::OnOutputStreamReady(nsIAsyncOutputStream*) [FetchStreamReader.cpp:3268a54a7fab9e9565038d589229e9f2bf1cdff9 : 201 + 0x3] [task 2018-07-26T20:52:01.285Z] 20:52:01 INFO - r4 = 0x5f013c80 r5 = 0x5f013ca0 r6 = 0x60cfb064 r7 = 0x60cfb0e0 [task 2018-07-26T20:52:01.286Z] 20:52:01 INFO - r8 = 0x60cfb04c r9 = 0x00000000 r10 = 0x60cfb058 fp = 0x535384b1 [task 2018-07-26T20:52:01.286Z] 20:52:01 INFO - sp = 0x60cfb040 lr = 0x5473f7b3 pc = 0x5473f7b3 [task 2018-07-26T20:52:01.286Z] 20:52:01 INFO - Found by: call frame info [task 2018-07-26T20:52:01.287Z] 20:52:01 INFO - 2 libxul.so!nsOutputStreamReadyEvent::Run() [nsStreamUtils.cpp:3268a54a7fab9e9565038d589229e9f2bf1cdff9 : 193 + 0x3] [task 2018-07-26T20:52:01.287Z] 20:52:01 INFO - r4 = 0x60686210 r5 = 0x606861f0 r6 = 0x5bee7000 r7 = 0x60cfb0f0 [task 2018-07-26T20:52:01.287Z] 20:52:01 INFO - r8 = 0x60cfb124 r9 = 0x80004005 r10 = 0x60cfb6df fp = 0x5edb8030 [task 2018-07-26T20:52:01.288Z] 20:52:01 INFO - sp = 0x60cfb0e8 lr = 0x53587c13 pc = 0x53587c13 [task 2018-07-26T20:52:01.288Z] 20:52:01 INFO - Found by: call frame info [task 2018-07-26T20:52:01.288Z] 20:52:01 INFO - 3 libxul.so!mozilla::dom::(anonymous namespace)::ExternalRunnableWrapper::WorkerRun(JSContext*, mozilla::dom::WorkerPrivate*) [WorkerPrivate.cpp:3268a54a7fab9e9565038d589229e9f2bf1cdff9 : 182 + 0x5] [task 2018-07-26T20:52:01.288Z] 20:52:01 INFO - r4 = 0x5bee7000 r5 = 0x00000001 r6 = 0x5bee7000 r7 = 0x60cfb100 [task 2018-07-26T20:52:01.289Z] 20:52:01 INFO - r8 = 0x60cfb124 r9 = 0x80004005 r10 = 0x60cfb6df fp = 0x5edb8030 [task 2018-07-26T20:52:01.289Z] 20:52:01 INFO - sp = 0x60cfb0f8 lr = 0x54b6c83f pc = 0x54b6c83f [task 2018-07-26T20:52:01.289Z] 20:52:01 INFO - Found by: call frame info [task 2018-07-26T20:52:01.289Z] 20:52:01 INFO - 4 libxul.so!mozilla::dom::WorkerRunnable::Run() [WorkerRunnable.cpp:3268a54a7fab9e9565038d589229e9f2bf1cdff9 : 380 + 0x5] [task 2018-07-26T20:52:01.290Z] 20:52:01 INFO - r4 = 0x606865b0 r5 = 0x00000001 r6 = 0x5bee7000 r7 = 0x60cfb1e8 [task 2018-07-26T20:52:01.290Z] 20:52:01 INFO - r8 = 0x60cfb124 r9 = 0x80004005 r10 = 0x60cfb6df fp = 0x5edb8030 [task 2018-07-26T20:52:01.290Z] 20:52:01 INFO - sp = 0x60cfb108 lr = 0x54b68875 pc = 0x54b68875 [task 2018-07-26T20:52:01.291Z] 20:52:01 INFO - Found by: call frame info [task 2018-07-26T20:52:01.291Z] 20:52:01 INFO - 5 libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:3268a54a7fab9e9565038d589229e9f2bf1cdff9 : 1205 + 0x5] [task 2018-07-26T20:52:01.291Z] 20:52:01 INFO - r4 = 0x00000000 r5 = 0x5359ec81 r6 = 0x00000000 r7 = 0x60cfb6d0 [task 2018-07-26T20:52:01.291Z] 20:52:01 INFO - r8 = 0x60cfb265 r9 = 0x60cfb268 r10 = 0x60cfb6df fp = 0x5edb8030 [task 2018-07-26T20:52:01.292Z] 20:52:01 INFO - sp = 0x60cfb1f0 lr = 0x535a58bf pc = 0x535a58bf
Summary: Intermittent dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html | application crashed [@ JS::ReadableStreamDefaultReaderRead(JSContext*, JS::Handle<JSObject*>)] → Intermittent dom/serviceworkers/test/test_fetch_event_with_thirdpartypref.html, dom/serviceworkers/test/test_fetch_event.html | application crashed [@ JS::ReadableStreamDefaultReaderRead(JSContext*, JS::Handle<JSObject*>)]
I suspect that this bug is already fixed by bug 1387503. let's wait a couple of weeks to see if there is a lower number of crash reports.
This is what would happen if the argument `readerObj` is a nuked wrapper. We can easily make that a TypeError instead. Taking.
Assignee: nobody → jorendorff
Priority: P5 → P1
The patch did not fix the bug. I just submitted a diagnostic patch to try to learn more.
OK, the link in comment 24 has nine failures. * In seven cases, the object being passed to JS::ReadableStreamDefaultReaderRead is an Array, according to the log. For example: https://treeherder.mozilla.org/logviewer.html#?job_id=212546013&repo=try&lineNumber=6070 https://treeherder.mozilla.org/logviewer.html#?job_id=212546104&repo=try&lineNumber=6139 https://treeherder.mozilla.org/logviewer.html#?job_id=212546016&repo=try&lineNumber=6218 * In one case, the object is a Promise. https://treeherder.mozilla.org/logviewer.html#?job_id=212546345&repo=try&lineNumber=5724 * In the other case, the object is from a different compartment. We check that before checking the type, so I didn't get the object's class in the log for this one. But my guess is, same bug, different symptom. https://treeherder.mozilla.org/logviewer.html#?job_id=212546326&repo=try&lineNumber=1892 The reader comes from FetchStreamReader::mReader. FetchStreamReader's constructor default-constructs mReader, which initializes it to null. mReader is only ever assigned the result of JS::ReadableStreamGetReader. Is JS::ReadableStreamGetReader really returning a Reader most of the time, but then an Array sometimes, and other objects other times... on Android only? I went and checked the source code just in case. This is impossible. That leaves a few possibilities, all undefined behavior: 1. Somehow mReader isn't really being initialized; the FetchStreamReader constructor isn't being called, or it's got a bug. 2. This FetchStreamReader has been freed, and another object has been allocated at the same address, overwriting mReader. So we're chasing a dangling FetchStreamReader pointer to get here. 3. The Reader object has been GC'd, and another object has been allocated at the same address, overwriting it with an Array, Promise, or something else. This means the Heap<JSObject*> FetchStreamReader::mReader isn't keeping the reader object rooted for some reason. 4. The FetchStreamReader object is getting tenured (moved from the nursery by GC), but FetchStreamReader::mReader isn't being updated for some reason. I can add more diagnostic output to distinguish these cases.
Cleaning the NI. Jason is working on this issue.
Flags: needinfo?(amarchesini)
+ LOG("FetchStreamReader::OnOutputStreamReady in\n"); Would be nice if you can add a "%p, this" here. I suspect that we are just reading random data here. https://taskcluster-artifacts.net/Y5zSMorOQuG5gyE_uWUjVA/0/public/logs/live_backing.log Here we see: [task 2018-11-19T18:39:08.761Z] 18:39:08 INFO - 11-19 10:38:29.561 F/MOZ_Assert( 2887): FetchStreamReader::OnOutputStreamReady in [task 2018-11-19T18:39:08.761Z] 18:39:08 INFO - 11-19 10:38:29.581 F/MOZ_Assert( 2887): OnOutputStreamReady: FetchStreamReader::mReader is 0x655b93a0 That pointer is completely unknown. We've never allocated a reader in that address.
Attached patch fix.patch — — Splinter Review
Could be just this missing?
Attachment #9026435 - Flags: review?(jorendorff)
Attachment #9026435 - Flags: review?(jorendorff) → review?(bugs)
Assignee: jorendorff → amarchesini
Attachment #9026435 - Flags: review?(bugs) → review+
Pushed by amarchesini@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/6ce084069f38 FetchStreamReader must call HoldJSObject()/DropJSObjects, r=smaug
Pushed by jorendorff@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/b4bc0fa77a1e Safely handle nuked wrappers as arguments to stream-related JSAPI entry points. r=tcampbell
https://hg.mozilla.org/mozilla-central/rev/6ce084069f38
Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox65: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla65
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: