1157219 - Intermittent test_https_fetch.html | application crashed [@ mozilla::dom::cache::CacheChild::ExecuteOp(nsIGlobalObject *,mozilla::dom::Promise *,mozilla::dom::cache::CacheOpArgs const &)]

Status: RESOLVED FIXED

(Core :: DOM: Workers, defect)

Description

[Ryan VanderMeulen [:RyanVM]]

16:56:44 INFO - 392 INFO TEST-OK | dom/workers/test/serviceworkers/test_empty_serviceworker.html | took 726ms
16:56:44 INFO - ++DOMWINDOW == 42 (0E02C400) [pid = 3216] [serial = 1028] [outer = 19724000]
16:56:44 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:44 INFO - [3216] WARNING: Performance Entry buffer size maximum reached!: file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\base\nsPerformance.cpp, line 598
16:56:44 INFO - ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
16:56:44 INFO - 393 INFO TEST-START | dom/workers/test/serviceworkers/test_https_fetch.html
16:56:45 INFO - ++DOMWINDOW == 43 (0E41C000) [pid = 3216] [serial = 1029] [outer = 19724000]
16:56:45 INFO - [3216] WARNING: Performance Entry buffer size maximum reached!: file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\base\nsPerformance.cpp, line 598
16:56:45 INFO - ++DOCSHELL 0DE72C00 == 11 [pid = 3216] [id = 230]
16:56:45 INFO - ++DOMWINDOW == 44 (0E471C00) [pid = 3216] [serial = 1030] [outer = 00000000]
16:56:45 INFO - [3216] WARNING: Subdocument container has no frame: file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\layout\base\nsDocumentViewer.cpp, line 2511
16:56:45 INFO - ++DOMWINDOW == 45 (0E479C00) [pid = 3216] [serial = 1031] [outer = 0E471C00]
16:56:45 INFO - [3216] WARNING: Subdocument container has no frame: file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\layout\base\nsDocumentViewer.cpp, line 2511
16:56:45 INFO - ++DOMWINDOW == 46 (0ACF5000) [pid = 3216] [serial = 1032] [outer = 0E471C00]
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:45 INFO - [3216] WARNING: Called close() before start()!: 'mStarted', file c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\src\dom\workers\MessagePort.cpp, line 214
16:56:47 INFO - TEST-INFO | Main app process: exit status 1
16:56:47 WARNING - TEST-UNEXPECTED-FAIL | dom/workers/test/serviceworkers/test_https_fetch.html | application terminated with exit code 1
16:56:47 INFO - runtests.py | Application ran for: 0:03:42.741000
16:56:47 INFO - zombiecheck | Reading PID log: c:\users\cltbld\appdata\local\temp\tmpzab2jkpidlog
16:56:57 INFO - mozcrash Saved minidump as C:\slave\test\build\blobber_upload_dir\1b8ac2f1-2a11-43db-bd29-eff98fb0f4ee.dmp
16:56:57 INFO - mozcrash Saved app info as C:\slave\test\build\blobber_upload_dir\1b8ac2f1-2a11-43db-bd29-eff98fb0f4ee.extra
16:56:57 WARNING - PROCESS-CRASH | dom/workers/test/serviceworkers/test_https_fetch.html | application crashed [@ mozilla::dom::cache::CacheChild::ExecuteOp(nsIGlobalObject *,mozilla::dom::Promise *,mozilla::dom::cache::CacheOpArgs const &)]
16:56:57 INFO - Crash dump filename: c:\users\cltbld\appdata\local\temp\tmpxm4shk.mozrunner\minidumps\1b8ac2f1-2a11-43db-bd29-eff98fb0f4ee.dmp
16:56:57 INFO - Operating system: Windows NT
16:56:57 INFO - 6.1.7601 Service Pack 1
16:56:57 INFO - CPU: x86
16:56:57 INFO - GenuineIntel family 6 model 30 stepping 5
16:56:57 INFO - 8 CPUs
16:56:57 INFO - Crash reason: EXCEPTION_ACCESS_VIOLATION_WRITE
16:56:57 INFO - Crash address: 0x30
16:56:57 INFO - Thread 58 (crashed)
16:56:57 INFO - 0 xul.dll!mozilla::dom::cache::CacheChild::ExecuteOp(nsIGlobalObject *,mozilla::dom::Promise *,mozilla::dom::cache::CacheOpArgs const &) [CacheChild.cpp:ec68bf489da0 : 69 + 0x0]
16:56:57 INFO - eip = 0x64f85725 esp = 0x2071e4d8 ebp = 0x2071e4e0 ebx = 0x0e08f350
16:56:57 INFO - esi = 0x00000000 edi = 0x0a21fbe0 eax = 0x2071e5cc ecx = 0x00000000
16:56:57 INFO - edx = 0x0defb6c4 efl = 0x00010246
16:56:57 INFO - Found by: given as instruction pointer in context
16:56:57 INFO - 1 xul.dll!mozilla::dom::cache::Cache::ExecuteOp(mozilla::dom::cache::AutoChildOpArgs &,mozilla::ErrorResult &) [Cache.cpp:ec68bf489da0 : 374 + 0x16]
16:56:57 INFO - eip = 0x64f85711 esp = 0x2071e4e8 ebp = 0x2071e500
16:56:57 INFO - Found by: call frame info
16:56:57 INFO - 2 xul.dll!mozilla::dom::cache::Cache::Add(mozilla::dom::RequestOrUSVString const &,mozilla::ErrorResult &) [Cache.cpp:ec68bf489da0 : 169 + 0x13]
16:56:57 INFO - eip = 0x64f82080 esp = 0x2071e508 ebp = 0x2071e66c
16:56:57 INFO - Found by: call frame info
16:56:57 INFO - 3 xul.dll!mozilla::dom::CacheBinding::add [CacheBinding.cpp:ec68bf489da0 : 657 + 0x19]
16:56:57 INFO - eip = 0x64a0b6f1 esp = 0x2071e674 ebp = 0x2071e760
16:56:57 INFO - Found by: call frame info
16:56:57 INFO - 4 xul.dll!mozilla::dom::CacheBinding::add_promiseWrapper [CacheBinding.cpp:ec68bf489da0 : 676 + 0x5]
16:56:57 INFO - eip = 0x649d5137 esp = 0x2071e768 ebp = 0x2071e794
16:56:57 INFO - Found by: call frame info
16:56:57 INFO - 5 xul.dll!mozilla::dom::GenericPromiseReturningBindingMethod(JSContext *,unsigned int,JS::Value *) [BindingUtils.cpp:ec68bf489da0 : 2620 + 0x14]
16:56:57 INFO - eip = 0x64f749e0 esp = 0x2071e79c ebp = 0x2071e7f0
16:56:57 INFO - Found by: call frame info
16:56:57 INFO - 6 xul.dll!js::CallJSNative(JSContext *,bool (*)(JSContext *,unsigned int,JS::Value *),JS::CallArgs const &) [jscntxtinlines.h:ec68bf489da0 : 235 + 0xd]
16:56:57 INFO - eip = 0x663fbb48 esp = 0x2071e7f8 ebp = 0x2071e818
16:56:57 INFO - Found by: call frame info
16:56:57 INFO - 7 xul.dll!js::Invoke(JSContext *,JS::CallArgs,js::MaybeConstruct) [Interpreter.cpp:ec68bf489da0 : 727 + 0x11]
16:56:57 INFO - eip = 0x66416b18 esp = 0x2071e820 ebp = 0x2071eb38
16:56:57 INFO - Found by: call frame info
16:56:57 INFO - 8 xul.dll!Interpret [Interpreter.cpp:ec68bf489da0 : 2956 + 0x20]
16:56:57 INFO - eip = 0x664103c0 esp = 0x2071eb40 ebp = 0x2071f168
16:56:57 INFO - Found by: call frame info
16:56:57 INFO - 9 xul.dll!js::RunScript(JSContext *,js::RunState &) [Interpreter.cpp:ec68bf489da0 : 677 + 0x6]
16:56:57 INFO - eip = 0x6641b744 esp = 0x2071f170 ebp = 0x2071f1cc
16:56:57 INFO - Found by: call frame info
16:56:57 INFO - 10 xul.dll!js::Invoke(JSContext *,JS::CallArgs,js::MaybeConstruct) [Interpreter.cpp:ec68bf489da0 : 746 + 0xc]
16:56:57 INFO - eip = 0x66416bd1 esp = 0x2071f1d4 ebp = 0x2071f4e8
16:56:57 INFO - Found by: call frame info

Comment 1

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=9157189
repository: mozilla-inbound
start_time: 2015-04-21T16:49:13
who: rvandermeulen[at]mozilla[dot]com
machine: t-w732-ix-020
buildname: Windows 7 32-bit mozilla-inbound debug test mochitest-4
revision: ec68bf489da0

TEST-UNEXPECTED-FAIL | dom/workers/test/serviceworkers/test_https_fetch.html | application terminated with exit code 1
PROCESS-CRASH | dom/workers/test/serviceworkers/test_https_fetch.html | application crashed [@ mozilla::dom::cache::CacheChild::ExecuteOp(nsIGlobalObject *,mozilla::dom::Promise *,mozilla::dom::cache::CacheOpArgs const &)]
TEST-UNEXPECTED-FAIL | leakcheck | default process: missing output line for total leaks!
Return code: 1
No tests run or test summary not found

Comment 2

[Ben Kelly [:bkelly, not reviewing]]

I'm in the process of re-writing the Add/AddAll code in bug 1120501.  I'll take this one to watch and see if it gets fixed as a side effect.  Also hoping to see some reproduction as its a bit unclear what the problem is from the stack.  An ASAN failure may be needed.

Comment 3

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=1390609
repository: mozilla-central
start_time: 2015-04-24T06:57:11
who: rvandermeulen[at]mozilla[dot]com
machine: t-w732-ix-026
buildname: Windows 7 32-bit mozilla-central debug test mochitest-4
revision: 9ddf7f40c874

TEST-UNEXPECTED-FAIL | dom/workers/test/serviceworkers/test_https_fetch.html | application terminated with exit code 1
PROCESS-CRASH | dom/workers/test/serviceworkers/test_https_fetch.html | application crashed [@ mozilla::dom::cache::CacheChild::ExecuteOp(nsIGlobalObject *,mozilla::dom::Promise *,mozilla::dom::cache::CacheOpArgs const &)]
TEST-UNEXPECTED-FAIL | leakcheck | default process: missing output line for total leaks!
Return code: 1
No tests run or test summary not found

Comment 4

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=b2g-inbound&job_id=1829714
repository: b2g-inbound
start_time: 2015-04-30T09:30:59
who: rvandermeulen[at]mozilla[dot]com
machine: t-w864-ix-098
buildname: Windows 8 64-bit b2g-inbound pgo test mochitest-4
revision: 5e958d738bbb

TEST-UNEXPECTED-FAIL | dom/workers/test/serviceworkers/test_https_fetch.html | application terminated with exit code 1
PROCESS-CRASH | dom/workers/test/serviceworkers/test_https_fetch.html | application crashed [@ mozilla::dom::cache::Cache::AddAll(mozilla::dom::GlobalObject const &,nsTArray<nsRefPtr<mozilla::dom::Request> > &&,mozilla::ErrorResult &)]
Return code: 1
No tests run or test summary not found

Comment 5

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=2902648
repository: fx-team
start_time: 2015-05-01T05:39:17
who: rvandermeulen[at]mozilla[dot]com
machine: t-w864-ix-068
buildname: Windows 8 64-bit fx-team opt test mochitest-4
revision: f27feb597c05

TEST-UNEXPECTED-FAIL | dom/workers/test/serviceworkers/test_https_fetch.html | application terminated with exit code 1
PROCESS-CRASH | dom/workers/test/serviceworkers/test_https_fetch.html | application crashed [@ mozilla::dom::cache::Cache::AddAll(mozilla::dom::GlobalObject const &,nsTArray<nsRefPtr<mozilla::dom::Request> > &&,mozilla::ErrorResult &)]
Return code: 1
No tests run or test summary not found

Comment 6

[Ben Kelly [:bkelly, not reviewing]]

In bug 1134841 I see evidence of the ServiceWorker being shutdown too soon.  This could cause us to clear the mActor pointer in Cache before the Cache::AddAll() call.  I'm switching the MOZ_ASSERT(mActor) to if(!mActor) { Fail() } in bug 1160147.  I think the fixes for those two bugs should resolve this one.

Comment 7

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=try&job_id=7175178
repository: try
start_time: 2015-05-01T18:53:44
who: cmanchester[at]mozilla[dot]com
machine: t-w864-ix-066
buildname: Windows 8 64-bit try opt test mochitest-4
revision: e22656e8151c

482 INFO TEST-UNEXPECTED-FAIL | dom/workers/test/serviceworkers/test_https_fetch.html | Test timed out. - expected PASS
Return code: 1

Comment 8

[Legacy TBPL/Treeherder Robot]

log: https://treeherder.mozilla.org/logviewer.html#?repo=try&job_id=7173954
repository: try
start_time: 2015-05-01T17:54:25
who: aklotz[at]mozilla[dot]com
machine: t-w732-ix-073
buildname: Windows 7 32-bit try opt test mochitest-4
revision: 8d3f1666e6a7

482 INFO TEST-UNEXPECTED-FAIL | dom/workers/test/serviceworkers/test_https_fetch.html | Test timed out. - expected PASS
Return code: 1