Closed Bug 1253793 Opened 4 years ago Closed 4 years ago

Intermittent application crashed [@ `anonymous namespace'::CacheScriptLoader::OnStreamComplete(nsIStreamLoader *,nsISupports *,nsresult,unsigned int,unsigned char const *)] (Assertion failure: mLoadInfo.mCacheStatus == ScriptLoadInfo::ReadingFromCache)

Categories

(Core :: DOM: Service Workers, defect)

defect
Not set

Tracking

()

RESOLVED FIXED
mozilla48
Tracking Status
firefox47 --- fixed
firefox48 --- fixed

People

(Reporter: RyanVM, Assigned: bkelly)

References

Details

(Keywords: assertion, crash, intermittent-failure)

Attachments

(1 file)

https://treeherder.mozilla.org/logviewer.html#?job_id=23038755&repo=mozilla-inbound

10:48:27     INFO -  12 INFO TEST-START | devtools/client/aboutdebugging/test/browser_service_workers_start.js
10:48:27     INFO -  ++DOCSHELL 0E753800 == 16 [pid = 1872] [id = 19]
10:48:27     INFO -  ++DOMWINDOW == 38 (1D4A2C00) [pid = 1872] [serial = 50] [outer = 00000000]
10:48:27     INFO -  ++DOMWINDOW == 39 (1D7B5000) [pid = 1872] [serial = 51] [outer = 1D4A2C00]
10:48:27     INFO -  ++DOMWINDOW == 40 (1D83B000) [pid = 1872] [serial = 52] [outer = 1D4A2C00]
10:48:27     INFO -  --DOMWINDOW == 39 (26116C00) [pid = 1872] [serial = 42] [outer = 00000000] [url = about:blank]
10:48:27     INFO -  --DOMWINDOW == 38 (24A16000) [pid = 1872] [serial = 38] [outer = 00000000] [url = about:debugging#addons]
10:48:27     INFO -  --DOMWINDOW == 37 (1AF0C000) [pid = 1872] [serial = 21] [outer = 00000000] [url = about:debugging#addons]
10:48:27     INFO -  --DOMWINDOW == 36 (19331800) [pid = 1872] [serial = 45] [outer = 00000000] [url = about:blank]
10:48:28     INFO -  --DOCSHELL 0E095C00 == 15 [pid = 1872] [id = 13]
10:48:28     INFO -  --DOCSHELL 1D4A2400 == 14 [pid = 1872] [id = 14]
10:48:28     INFO -  --DOCSHELL 02212400 == 13 [pid = 1872] [id = 17]
10:48:28     INFO -  --DOCSHELL 24F88800 == 12 [pid = 1872] [id = 16]
10:48:28     INFO -  --DOCSHELL 24A15800 == 11 [pid = 1872] [id = 15]
10:48:28     INFO -  --DOCSHELL 19CE5400 == 10 [pid = 1872] [id = 12]
10:48:29     INFO -  --DOCSHELL 02281800 == 9 [pid = 1872] [id = 18]
10:48:30     INFO -  --DOMWINDOW == 35 (24A14000) [pid = 1872] [serial = 40] [outer = 00000000] [url = about:debugging#addons]
10:48:30     INFO -  --DOMWINDOW == 34 (1B6C6400) [pid = 1872] [serial = 23] [outer = 00000000] [url = about:debugging#addons]
10:48:32     INFO -  ++DOCSHELL 0EA68C00 == 4 [pid = 1404] [id = 9]
10:48:32     INFO -  ++DOMWINDOW == 17 (0EA69800) [pid = 1404] [serial = 19] [outer = 00000000]
10:48:32     INFO -  ++DOMWINDOW == 18 (0F102800) [pid = 1404] [serial = 20] [outer = 0EA69800]
10:48:32     INFO -  ++DOMWINDOW == 19 (0F107C00) [pid = 1404] [serial = 21] [outer = 0EA69800]
10:48:32     INFO -  SW registered
10:48:34     INFO -  [Parent 1872] WARNING: pipe error: 109: file c:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 333
10:48:35     INFO -  --DOCSHELL 0E92D000 == 3 [pid = 1404] [id = 6]
10:48:35     INFO -  --DOCSHELL 0F19B000 == 2 [pid = 1404] [id = 7]
10:48:37     INFO -  --DOMWINDOW == 18 (0E49C800) [pid = 1404] [serial = 6] [outer = 00000000] [url = about:blank]
10:48:37     INFO -  --DOMWINDOW == 17 (0AC4BC00) [pid = 1404] [serial = 2] [outer = 00000000] [url = about:blank]
10:48:37     INFO -  --DOMWINDOW == 16 (0A737000) [pid = 1404] [serial = 7] [outer = 00000000] [url = about:blank]
10:48:37     INFO -  --DOMWINDOW == 15 (0E498400) [pid = 1404] [serial = 5] [outer = 00000000] [url = about:blank]
10:48:37     INFO -  --DOMWINDOW == 14 (0D942400) [pid = 1404] [serial = 1] [outer = 00000000] [url = about:blank]
10:48:37     INFO -  --DOMWINDOW == 13 (0AC4E000) [pid = 1404] [serial = 9] [outer = 00000000] [url = http://mochi.test:8888/browser/devtools/client/aboutdebugging/test/service-workers/empty-sw.html]
10:48:38     INFO -  Assertion failure: mLoadInfo.mCacheStatus == ScriptLoadInfo::ReadingFromCache, at c:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/src/dom/workers/ScriptLoader.cpp:1618
10:48:54     INFO -  #01: nsStreamLoader::OnStopRequest(nsIRequest *,nsISupports *,nsresult) [netwerk/base/nsStreamLoader.cpp:104]
10:48:54     INFO -  #02: nsInputStreamPump::OnStateStop() [netwerk/base/nsInputStreamPump.cpp:716]
10:48:54     INFO -  #03: nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream *) [netwerk/base/nsInputStreamPump.cpp:435]
10:48:54     INFO -  #04: nsInputStreamReadyEvent::Run() [xpcom/io/nsStreamUtils.cpp:96]
10:48:54     INFO -  #05: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:994]
10:48:54     INFO -  #06: NS_ProcessNextEvent(nsIThread *,bool) [xpcom/glue/nsThreadUtils.cpp:297]
10:48:54     INFO -  #07: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:95]
10:48:54     INFO -  #08: mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:289]
10:48:54     INFO -  #09: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:234]
10:48:54     INFO -  #10: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:228]
10:48:54     INFO -  #11: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:202]
10:48:54     INFO -  #12: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:158]
10:48:54     INFO -  #13: nsAppShell::Run() [widget/windows/nsAppShell.cpp:259]
10:48:54     INFO -  #14: XRE_RunAppShell [toolkit/xre/nsEmbedFunctions.cpp:786]
10:48:54     INFO -  #15: mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:259]
10:48:54     INFO -  #16: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:234]
10:48:54     INFO -  #17: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:228]
10:48:54     INFO -  #18: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:202]
10:48:54     INFO -  #19: XRE_InitChildProcess [toolkit/xre/nsEmbedFunctions.cpp:626]
10:48:54     INFO -  #20: content_process_main(int,char * * const) [ipc/contentproc/plugin-container.cpp:238]
10:48:54     INFO -  #21: wmain [toolkit/xre/nsWindowsWMain.cpp:138]
10:48:54     INFO -  #22: __tmainCRTStartup [f:/dd/vctools/crt/crtw32/startup/crt0.c:255]
10:48:54     INFO -  #23: kernel32.dll + 0x53c45
10:48:54     INFO -  #24: ntdll.dll + 0x637f5
10:48:54     INFO -  #25: ntdll.dll + 0x637c8
10:48:54     INFO -  MEMORY STAT | vsize 710MB | vsizeMaxContiguous 562MB | residentFast 281MB | heapAllocated 74MB
10:48:54     INFO -  13 INFO TEST-OK | devtools/client/aboutdebugging/test/browser_service_workers_start.js | took 10602ms

10:49:22  WARNING -  PROCESS-CRASH | Main app process exited normally | application crashed [@ `anonymous namespace'::CacheScriptLoader::OnStreamComplete(nsIStreamLoader *,nsISupports *,nsresult,unsigned int,unsigned char const *)]
10:49:22     INFO -  Crash dump filename: c:\users\cltbld\appdata\local\temp\tmpzufgut.mozrunner\minidumps\4e4310ce-0824-4d6a-bef9-7b67bb0c71e3.dmp
10:49:22     INFO -  Operating system: Windows NT
10:49:22     INFO -                    6.1.7601 Service Pack 1
10:49:22     INFO -  CPU: x86
10:49:22     INFO -       GenuineIntel family 6 model 30 stepping 5
10:49:22     INFO -       8 CPUs
10:49:22     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
10:49:22     INFO -  Crash address: 0x62cccddb
10:49:22     INFO -  Assertion: Unknown assertion type 0x00000000
10:49:22     INFO -  Process uptime: 35 seconds
10:49:22     INFO -  Thread 0 (crashed)
10:49:22     INFO -   0  xul.dll!`anonymous namespace'::CacheScriptLoader::OnStreamComplete(nsIStreamLoader *,nsISupports *,nsresult,unsigned int,unsigned char const *) [ScriptLoader.cpp:310ca84e24fa : 1618 + 0x2e]
10:49:22     INFO -      eip = 0x62cccddb   esp = 0x001af498   ebp = 0x001af4a0   ebx = 0x0fe101e0
10:49:22     INFO -      esi = 0x00000652   edi = 0x0acaae44   eax = 0x64b85348   ecx = 0x68ef0ad9
10:49:22     INFO -      edx = 0x012eff29   efl = 0x00000202
10:49:22     INFO -      Found by: given as instruction pointer in context
10:49:22     INFO -   1  xul.dll!nsStreamLoader::OnStopRequest(nsIRequest *,nsISupports *,nsresult) [nsStreamLoader.cpp:310ca84e24fa : 103 + 0x1d]
10:49:22     INFO -      eip = 0x61357c29   esp = 0x001af4a8   ebp = 0x001af4d8
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -   2  xul.dll!nsInputStreamPump::OnStateStop() [nsInputStreamPump.cpp:310ca84e24fa : 715 + 0x15]
10:49:22     INFO -      eip = 0x61338dfe   esp = 0x001af4e0   ebp = 0x001af508
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -   3  xul.dll!nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream *) [nsInputStreamPump.cpp:310ca84e24fa : 434 + 0xa]
10:49:22     INFO -      eip = 0x61337b35   esp = 0x001af510   ebp = 0x001af52c
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -   4  xul.dll!nsInputStreamReadyEvent::Run() [nsStreamUtils.cpp:310ca84e24fa : 94 + 0x10]
10:49:22     INFO -      eip = 0x61278181   esp = 0x001af534   ebp = 0x001af544
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -   5  xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:310ca84e24fa : 994 + 0xe]
10:49:22     INFO -      eip = 0x612937c3   esp = 0x001af54c   ebp = 0x001af62c
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -   6  xul.dll!NS_ProcessNextEvent(nsIThread *,bool) [nsThreadUtils.cpp:310ca84e24fa : 297 + 0xd]
10:49:22     INFO -      eip = 0x612c2460   esp = 0x001af634   ebp = 0x001af640
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -   7  xul.dll!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [MessagePump.cpp:310ca84e24fa : 95 + 0xa]
10:49:22     INFO -      eip = 0x61591315   esp = 0x001af648   ebp = 0x001af670
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -   8  xul.dll!mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate *) [MessagePump.cpp:310ca84e24fa : 289 + 0x8]
10:49:22     INFO -      eip = 0x61591493   esp = 0x001af678   ebp = 0x001af688
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -   9  xul.dll!MessageLoop::RunInternal() [message_loop.cc:310ca84e24fa : 234 + 0xf]
10:49:22     INFO -      eip = 0x6155ff0f   esp = 0x001af690   ebp = 0x001af6a8
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -  10  xul.dll!MessageLoop::RunHandler() [message_loop.cc:310ca84e24fa : 227 + 0x5]
10:49:22     INFO -      eip = 0x6155fec7   esp = 0x001af6b0   ebp = 0x001af6dc
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -  11  xul.dll!MessageLoop::Run() [message_loop.cc:310ca84e24fa : 201 + 0x7]
10:49:22     INFO -      eip = 0x6155fc11   esp = 0x001af6e4   ebp = 0x001af6fc
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -  12  xul.dll!nsBaseAppShell::Run() [nsBaseAppShell.cpp:310ca84e24fa : 156 + 0xc]
10:49:22     INFO -      eip = 0x62e73f07   esp = 0x001af704   ebp = 0x001af70c
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -  13  xul.dll!nsAppShell::Run() [nsAppShell.cpp:310ca84e24fa : 257 + 0x8]
10:49:22     INFO -      eip = 0x62ec8fc4   esp = 0x001af714   ebp = 0x001af71c
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -  14  xul.dll!XRE_RunAppShell [nsEmbedFunctions.cpp:310ca84e24fa : 786 + 0xe]
10:49:22     INFO -      eip = 0x636889fb   esp = 0x001af724   ebp = 0x001af730
10:49:22     INFO -      Found by: call frame info
10:49:22     INFO -  15  xul.dll!mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate *) [MessagePump.cpp:310ca84e24fa : 259 + 0x5]
10:49:22     INFO -      eip = 0x615913ca   esp = 0x001af738   ebp = 0x001af744
10:49:22     INFO -      Found by: call frame info
Status: NEW → RESOLVED
Closed: 4 years ago
Component: Networking → DOM: Workers
Resolution: --- → DUPLICATE
Duplicate of bug: 1212195
Depends on: 1212195
See Also: 1212195
(In reply to Ryan VanderMeulen [:RyanVM] from bug 1212195 comment #7)
> Let's leave bug 1253793 open for the sake of Treeherder starring.
Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---
This path is only taken by service workers.  Its using the DOM Cache API.
Assignee: nobody → bkelly
Status: REOPENED → ASSIGNED
Component: DOM: Workers → DOM: Service Workers
This has only ever triggered once, so its difficult to test.  I do, however, have a theory.

If the script loading process is canceled, we call mPump->Cancel() and set mCacheState=Cancel.  I believe in this case its possible to get an OnStopRequest() from the stream loader.  The assertion in our OnStopRequest(), however, does not allow for the Cancel state.

So I think we should keep our current assert, but only for OnStopRequest() calls with successful status codes.  If an error is encountered we should all the Cancel state to be set.

I have a hard time seeing how we would enter this canceled state in this test, but its possible for the worker to start, stop, and start again based on timing.  Its also possible this is a service worker from an earlier test getting stopped.

Regardless, I think this patch is correct.  I don't, however, have a good way to trigger this condition in a test.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=f1fb738a96b8
Attachment #8729702 - Flags: review?(khuey)
This is the same as bug 1253821, right?  Which I have a recording of ... so there should be no need for you to guess at what's going on.
Flags: needinfo?(bkelly)
Ah, I didn't realize they were the same.  Can you look and see if this patch is correct?  I am working on three bugs at the same time, so I don't feel like I have the bandwidth to stop and learn a new tool.

It seems I can do retriggers, however, since bug 1253821 does trigger more frequently.
Flags: needinfo?(bkelly)
I can, but it'll be a few days.  ni? to myself.
Flags: needinfo?(khuey)
I think this patch fixes it.  A try build with no modifications hits errors around a 5% to 10% rate:

  https://treeherder.mozilla.org/#/jobs?repo=try&revision=2aed7bb644dd

With the patch I did over 60 pushes per platform without any failures.

  https://treeherder.mozilla.org/#/jobs?repo=try&revision=f1fb738a96b8
Well, I updated my machine which replaced system libs and broke the recording :P
Flags: needinfo?(khuey)
https://hg.mozilla.org/mozilla-central/rev/8d7ed429bf85
Status: ASSIGNED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla48
Duplicate of this bug: 1253821
Please request Aurora approval on this when you get a chance.
Flags: needinfo?(bkelly)
Comment on attachment 8729702 [details] [diff] [review]
Update ScriptLoader assertion to handle cancelation case. r=khuey

Approval Request Comment
[Feature/regressing bug #]: Service workers
[User impact if declined]: Test automation intermittent failures.  Ryan requested the uplift in comment 13.
[Describe test coverage new/current, TreeHerder]: Existing tests.
[Risks and why]: Minimal.  This just corrects an overly strict assertion.
[String/UUID change made/needed]: None.
Flags: needinfo?(bkelly)
Attachment #8729702 - Flags: approval-mozilla-aurora?
Comment on attachment 8729702 [details] [diff] [review]
Update ScriptLoader assertion to handle cancelation case. r=khuey

Fixes an intermittent failure, Aurora47+
Attachment #8729702 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
You need to log in before you can comment on or make changes to this bug.