Closed Bug 1052090 Opened 10 years ago Closed 10 years ago

Intermittent test_bug1002702.html | application crashed [@ mozilla::dom::workers::WorkerRunnable::Run()] after "Assertion failure: isMainThread == NS_IsMainThread(), at dom/workers/WorkerRunnable.cpp:267"

Categories

(Core :: DOM: Workers, defect)

Product:
Core
Component:
DOM: Workers
Platform:
x86
Windows XP
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla34
Tracking Flags:
Tracking Status
firefox32 --- unaffected
firefox33 --- unaffected
firefox34 --- fixed
firefox-esr24 --- unaffected
firefox-esr31 --- unaffected
b2g-v2.0 --- unaffected
b2g-v2.1 --- fixed

People

(Reporter: RyanVM, Assigned: bholley)

References

Details

(Keywords: assertion, crash, intermittent-failure)

Attachments

(1 file)

Don't try to compute main-thread-ness until after we're done with cancel shenanigans. v1
(deleted), patch
bkelly
: review+
Details | Diff | Splinter Review 
Spun off from bug 1049801 comment 13 and comment 15.

https://tbpl.mozilla.org/php/getParsedLog.php?id=45677230&tree=Mozilla-Inbound

Windows 7 32-bit mozilla-inbound debug test mochitest-4 on 2014-08-11 10:24:31 PDT for push d7ddaaa69b5a
slave: t-w732-ix-009

10:29:45     INFO -  3408 INFO TEST-START | /tests/dom/workers/test/test_bug1002702.html
10:29:45     INFO -  3409 INFO ++DOMWINDOW == 119 (12279800) [pid = 2500] [serial = 888] [outer = 18ABB400]
10:29:45     INFO -  3410 INFO [2500] WARNING: Called close() before start()!: 'mStarted', file c:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/dom/workers/MessagePort.cpp, line 214
10:29:46     INFO -  3411 INFO --DOCSHELL 11E1C800 == 10 [pid = 2500] [id = 205]
10:29:46     INFO -  3412 INFO --DOCSHELL 113CD800 == 9 [pid = 2500] [id = 204]
10:29:46     INFO -  3413 INFO --DOMWINDOW == 118 (113C8000) [pid = 2500] [serial = 853] [outer = 00000000] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
10:29:46     INFO -  3414 INFO --DOMWINDOW == 117 (16283800) [pid = 2500] [serial = 666] [outer = 00000000] [url = http://example.org/tests/dom/tests/mochitest/sessionstorage/frameReplace.html?clean&window]
10:29:46     INFO -  3415 INFO --DOMWINDOW == 116 (11E60800) [pid = 2500] [serial = 645] [outer = 00000000] [url = http://example.com/tests/dom/tests/mochitest/sessionstorage/frameNotEqual.html]
10:29:46     INFO -  3416 INFO --DOMWINDOW == 115 (12DFF000) [pid = 2500] [serial = 826] [outer = 00000000] [url = http://sub1.xn--exaple-kqf.test/tests/dom/tests/mochitest/whatwg/postMessage_origin_helper.xhtml]
10:29:46     INFO -  3417 INFO --DOMWINDOW == 114 (14109800) [pid = 2500] [serial = 641] [outer = 00000000] [url = about:blank]
10:29:46     INFO -  3418 INFO --DOMWINDOW == 113 (12220000) [pid = 2500] [serial = 823] [outer = 00000000] [url = http://example.com/tests/dom/tests/mochitest/whatwg/postMessage_origin_helper.xhtml]
10:29:46     INFO -  3419 INFO --DOMWINDOW == 112 (0E461C00) [pid = 2500] [serial = 822] [outer = 00000000] [url = http://mochi.test:8888/tests/dom/tests/mochitest/whatwg/postMessage_origin_helper.xhtml]
10:29:46     INFO -  3420 INFO --DOMWINDOW == 111 (132B1000) [pid = 2500] [serial = 665] [outer = 00000000] [url = http://example.com/tests/dom/tests/mochitest/sessionstorage/frameReplace.html?check&window]
10:29:46     INFO -  3421 INFO --DOMWINDOW == 110 (12DDAC00) [pid = 2500] [serial = 825] [outer = 00000000] [url = http://sub1.παράδειγμα.δοκιμή/tests/dom/tests/mochitest/whatwg/postMessage_origin_helper.xhtml]
10:29:46     INFO -  3422 INFO --DOMWINDOW == 109 (113CF400) [pid = 2500] [serial = 664] [outer = 00000000] [url = http://example.org/tests/dom/tests/mochitest/sessionstorage/frameReplace.html?init&window]
10:29:46     INFO -  3423 INFO --DOMWINDOW == 108 (16A82000) [pid = 2500] [serial = 663] [outer = 00000000] [url = about:blank]
10:29:46     INFO -  3424 INFO --DOMWINDOW == 107 (0ECEA000) [pid = 2500] [serial = 824] [outer = 00000000] [url = http://example.org:8000/tests/dom/tests/mochitest/whatwg/postMessage_origin_helper.xhtml]
10:29:46     INFO -  3425 INFO --DOMWINDOW == 106 (12D33400) [pid = 2500] [serial = 644] [outer = 00000000] [url = about:blank]
10:29:46     INFO -  3426 INFO --DOMWINDOW == 105 (140CFC00) [pid = 2500] [serial = 828] [outer = 00000000] [url = about:neterror?e=dnsNotFound&u=ftp%3A//mochi.test%3A27534/tests/dom/tests/mochitest/whatwg/postMessage_origin_helper.xhtml&c=UTF-8&f=regular&d=Firefox%20can%27t%20find%20the%20server%20at%20mochi.test.]
10:29:46     INFO -  3427 INFO --DOMWINDOW == 104 (18031000) [pid = 2500] [serial = 832] [outer = 00000000] [url = http://example.org:8000/tests/dom/tests/mochitest/whatwg/postMessage_override_helper.html]
10:29:46     INFO -  3428 INFO --DOMWINDOW == 103 (13E1F000) [pid = 2500] [serial = 830] [outer = 00000000] [url = http://mochi.test:8888/tests/dom/tests/mochitest/whatwg/test_postMessage_override.html]
10:29:46     INFO -  3429 INFO --DOMWINDOW == 102 (18876C00) [pid = 2500] [serial = 833] [outer = 00000000] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
10:29:46     INFO -  3430 INFO --DOMWINDOW == 101 (12DF9800) [pid = 2500] [serial = 841] [outer = 00000000] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
10:29:46     INFO -  3431 INFO --DOMWINDOW == 100 (11E68C00) [pid = 2500] [serial = 815] [outer = 00000000] [url = http://mochi.test:8888/tests/dom/tests/mochitest/whatwg/test_postMessage_origin.xhtml]
10:29:46     INFO -  3432 INFO --DOMWINDOW == 99 (1499C400) [pid = 2500] [serial = 829] [outer = 00000000] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
10:29:46     INFO -  3433 INFO ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
10:29:46     INFO -  3434 INFO ###!!! [Parent][MessageChannel] Error: Channel closing: too late to send/recv, messages will be lost
10:29:46     INFO -  3435 INFO IPDL protocol error: Handler for PBackgroundTest returned error code
10:29:46     INFO -  3436 INFO ###!!! [Parent][DispatchAsyncMessage] Error: Processing error: message was deserialized, but the handler returned false (indicating failure)
10:29:46     INFO -  3437 INFO Assertion failure: isMainThread == NS_IsMainThread(), at c:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/dom/workers/WorkerRunnable.cpp:267
10:29:53     INFO -  3438 INFO mozilla::dom::workers::WorkerPrivate::ClearMainEventQueue(mozilla::dom::workers::WorkerPrivate::WorkerRanOrNot) [dom/workers/WorkerPrivate.cpp:4494]
10:29:53     INFO -  3439 INFO mozilla::dom::workers::WorkerPrivate::ScheduleDeletion(mozilla::dom::workers::WorkerPrivate::WorkerRanOrNot) [dom/workers/WorkerPrivate.cpp:4258]
10:29:53     INFO -  3440 INFO mozilla::dom::workers::WorkerPrivateParent<mozilla::dom::workers::WorkerPrivate>::NotifyPrivate(JSContext *,mozilla::dom::workers::Status) [dom/workers/WorkerPrivate.cpp:2370]
10:29:53     INFO -  3441 INFO mozilla::dom::workers::WorkerPrivateParent<mozilla::dom::workers::WorkerPrivate>::UnregisterSharedWorker(JSContext *,mozilla::dom::workers::SharedWorker *) [dom/workers/WorkerPrivate.cpp:3068]
10:29:53     INFO -  3442 INFO mozilla::dom::workers::SharedWorker::NoteDeadWorker(JSContext *) [dom/workers/SharedWorker.cpp:170]
10:29:53     INFO -  3443 INFO mozilla::dom::workers::SharedWorker::Close() [dom/workers/SharedWorker.cpp:147]
10:29:53     INFO -  3444 INFO mozilla::dom::workers::SharedWorker::~SharedWorker() [dom/workers/SharedWorker.cpp:44]
10:29:53     INFO -  3445 INFO mozilla::DOMEventTargetHelper::DeleteCycleCollectable() [dom/events/DOMEventTargetHelper.cpp:76]
10:29:53     INFO -  3446 INFO mozilla::DOMEventTargetHelper::cycleCollection::DeleteCycleCollectable(void *) [dom/events/DOMEventTargetHelper.h:59]
10:29:53     INFO -  3447 INFO SnowWhiteKiller::~SnowWhiteKiller() [xpcom/base/nsCycleCollector.cpp:2615]
10:29:53     INFO -  3448 INFO nsCycleCollector::FreeSnowWhite(bool) [xpcom/base/nsCycleCollector.cpp:2794]
10:29:53     INFO -  3449 INFO nsCycleCollector_doDeferredDeletion() [xpcom/base/nsCycleCollector.cpp:4139]
10:29:53     INFO -  3450 INFO nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:770]
10:29:53     INFO -  3451 INFO NS_ProcessNextEvent(nsIThread *,bool) [xpcom/glue/nsThreadUtils.cpp:265]
10:29:53     INFO -  3452 INFO mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:99]
10:29:53     INFO -  3453 INFO MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:229]
10:29:53     INFO -  3454 INFO MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:223]
10:29:53     INFO -  3455 INFO MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:197]
10:29:53     INFO -  3456 INFO nsBaseAppShell::Run() [widget/xpwidgets/nsBaseAppShell.cpp:166]
10:29:53     INFO -  3457 INFO nsAppShell::Run() [widget/windows/nsAppShell.cpp:193]
10:29:53     INFO -  3458 INFO nsAppStartup::Run() [toolkit/components/startup/nsAppStartup.cpp:279]
10:29:53     INFO -  3459 INFO XREMain::XRE_mainRun() [toolkit/xre/nsAppRunner.cpp:4021]
10:29:53     INFO -  3460 INFO XREMain::XRE_main(int,char * * const,nsXREAppData const *) [toolkit/xre/nsAppRunner.cpp:4092]
10:29:53     INFO -  3461 INFO XRE_main [toolkit/xre/nsAppRunner.cpp:4306]
10:29:53     INFO -  3462 INFO do_main [browser/app/nsBrowserApp.cpp:282]
10:29:53     INFO -  3463 INFO NS_internal_main(int,char * *) [browser/app/nsBrowserApp.cpp:643]
10:29:53     INFO -  3464 INFO wmain [toolkit/xre/nsWindowsWMain.cpp:112]
10:29:53     INFO -  3465 INFO __tmainCRTStartup [f:/dd/vctools/crt_bld/self_x86/crt/src/crtexe.c:552]
10:29:53     INFO -  3466 INFO kernel32 + 0x53c45
10:29:53     INFO -  3467 INFO ntdll + 0x637f5
10:29:53     INFO -  3468 INFO ntdll + 0x637c8
10:29:53     INFO -  3469 INFO ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
10:29:53     INFO -  3470 INFO ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
10:29:53     INFO -  3471 INFO ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
10:29:53     INFO -  3472 INFO ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
10:29:53     INFO -  3473 INFO ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
10:29:54     INFO -  3474 INFO ###!!! [Parent][MessageChannel] Error: Channel closing: too late to send/recv, messages will be lost
10:29:54     INFO -  3475 INFO IPDL protocol error: Handler for PBackgroundTest returned error code
10:29:54     INFO -  3476 INFO ###!!! [Parent][DispatchAsyncMessage] Error: Processing error: message was deserialized, but the handler returned false (indicating failure)
10:29:54     INFO -  TEST-INFO | Main app process: exit status 80000003
10:29:54     INFO -  3477 INFO TEST-PASS | /tests/dom/workers/test/test_bug1002702.html | No crash \o/
10:29:54  WARNING -  TEST-UNEXPECTED-FAIL | /tests/dom/workers/test/test_bug1002702.html | application terminated with exit code 2147483651
10:29:54     INFO -  runtests.py | Application ran for: 0:03:16.448000
10:29:54     INFO -  zombiecheck | Reading PID log: c:\users\cltbld\appdata\local\temp\tmp65dqjypidlog
10:30:01  WARNING -  PROCESS-CRASH | /tests/dom/workers/test/test_bug1002702.html | application crashed [@ mozilla::dom::workers::WorkerRunnable::Run()]
10:30:01     INFO -  Crash dump filename: c:\users\cltbld\appdata\local\temp\tmp6k8tfw.mozrunner\minidumps\b8b0a540-cfa1-4c9a-89aa-c82b0deaffa0.dmp
10:30:01     INFO -  Operating system: Windows NT
10:30:01     INFO -                    6.1.7601 Service Pack 1
10:30:01     INFO -  CPU: x86
10:30:01     INFO -       GenuineIntel family 6 model 30 stepping 5
10:30:01     INFO -       8 CPUs
10:30:01     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
10:30:01     INFO -  Crash address: 0x661d5918
10:30:01     INFO -  Thread 0 (crashed)
10:30:01     INFO -   0  xul.dll!mozilla::dom::workers::WorkerRunnable::Run() [WorkerRunnable.cpp:d7ddaaa69b5a : 251 + 0x24]
10:30:01     INFO -      eip = 0x661d5918   esp = 0x0027ef24   ebp = 0x0027f018   ebx = 0x00000000
10:30:01     INFO -      esi = 0x10d80de0   edi = 0x10d80de0   eax = 0x00000000   ecx = 0x6856ff12
10:30:01     INFO -      edx = 0x778470b4   efl = 0x00000216
10:30:01     INFO -      Found by: given as instruction pointer in context
10:30:01     INFO -   1  xul.dll!mozilla::dom::workers::WorkerPrivate::ClearMainEventQueue(mozilla::dom::workers::WorkerPrivate::WorkerRanOrNot) [WorkerPrivate.cpp:d7ddaaa69b5a : 4493 + 0x5]
10:30:01     INFO -      eip = 0x661ceb23   esp = 0x0027f020   ebp = 0x0027f038
10:30:01     INFO -      Found by: call frame info
10:30:01     INFO -   2  xul.dll!mozilla::dom::workers::WorkerPrivate::ScheduleDeletion(mozilla::dom::workers::WorkerPrivate::WorkerRanOrNot) [WorkerPrivate.cpp:d7ddaaa69b5a : 4256 + 0x9]
10:30:01     INFO -      eip = 0x661d18c8   esp = 0x0027f040   ebp = 0x0027f050
10:30:01     INFO -      Found by: call frame info
10:30:01     INFO -   3  xul.dll!mozilla::dom::workers::WorkerPrivateParent<mozilla::dom::workers::WorkerPrivate>::NotifyPrivate(JSContext *,mozilla::dom::workers::Status) [WorkerPrivate.cpp:d7ddaaa69b5a : 2369 + 0x7]
10:30:01     INFO -      eip = 0x661d1e42   esp = 0x0027f058   ebp = 0x0027f074
10:30:01     INFO -      Found by: call frame info
10:30:01     INFO -   4  xul.dll!mozilla::dom::workers::WorkerPrivateParent<mozilla::dom::workers::WorkerPrivate>::UnregisterSharedWorker(JSContext *,mozilla::dom::workers::SharedWorker *) [WorkerPrivate.cpp:d7ddaaa69b5a : 3068 + 0xb]
10:30:01     INFO -      eip = 0x661d2763   esp = 0x0027f07c   ebp = 0x0027f0a4
10:30:01     INFO -      Found by: call frame info
10:30:01     INFO -   5  xul.dll!mozilla::dom::workers::SharedWorker::NoteDeadWorker(JSContext *) [SharedWorker.cpp:d7ddaaa69b5a : 169 + 0x12]
10:30:01     INFO -      eip = 0x661c07ff   esp = 0x0027f0ac   ebp = 0x0027f0bc
10:30:01     INFO -      Found by: call frame info
10:30:01     INFO -   6  xul.dll!mozilla::dom::workers::SharedWorker::Close() [SharedWorker.cpp:d7ddaaa69b5a : 146 + 0x12]
10:30:01     INFO -      eip = 0x661c08f6   esp = 0x0027f0c4   ebp = 0x0027f124
10:30:01     INFO -      Found by: call frame info
10:30:01     INFO -   7  xul.dll!mozilla::dom::workers::SharedWorker::~SharedWorker() [SharedWorker.cpp:d7ddaaa69b5a : 43 + 0x6]
10:30:01     INFO -      eip = 0x661c0988   esp = 0x0027f12c   ebp = 0x0027f138
10:30:01     INFO -      Found by: call frame info
10:30:01     INFO -   8  xul.dll!mozilla::dom::workers::SharedWorker::`scalar deleting destructor'(unsigned int) + 0xa
10:30:01     INFO -      eip = 0x661c0b4a   esp = 0x0027f134   ebp = 0x0027f138
10:30:01     INFO -      Found by: call frame info
Looking at the history for WorkerRunnable.cpp, it seems this assert was added recently in bug 1050795:

  http://hg.mozilla.org/mozilla-central/rev/9ea1fc4f59e0

Bob, can you take a look at this?
Blocks: 1050795
Flags: needinfo?(bobowencode)
Bob is on PTO.

I'm confused though - we're crashing on thread 0, but ClearMainEventQueue calls AssertIsOnWorkerThread. What's the deal?
Flags: needinfo?(bobowencode) → needinfo?(bkelly)
(In reply to Bobby Holley (:bholley) from comment #10)
> I'm confused though - we're crashing on thread 0, but ClearMainEventQueue
> calls AssertIsOnWorkerThread. What's the deal?

I believe this works because of the code in NotifyPrivate():

      // Fake a thread here just so that our assertions don't go off for no
      // reason.
      nsIThread* currentThread = NS_GetCurrentThread();
      MOZ_ASSERT(currentThread);

      MOZ_ASSERT(!self->mPRThread);
      self->mPRThread = PRThreadFromThread(currentThread);
      MOZ_ASSERT(self->mPRThread);

See here:

  http://dxr.mozilla.org/mozilla-central/source/dom/workers/WorkerPrivate.cpp#2363

Should this be compatible with the modified checking in WorkerRunnable.cpp?
Flags: needinfo?(bkelly) → needinfo?(bobbyholley)
Attachment #8471717 - Flags: review?(bkelly) → review+
Also, wouldn't this have asserted in the old at http://hg.mozilla.org/mozilla-central/file/db13bb9473cc/dom/workers/WorkerRunnable.cpp#l293(In reply to Bobby Holley (:bholley) from comment #25)
> Created attachment 8471717 [details] [diff] [review]
> Don't try to compute main-thread-ness until after we're done with cancel
> shenanigans. v1

Thanks for sorting this out.
I still can't work out why the assertions above this aren't firing, but haven't got time to look any further, sorry.
(In reply to Bob Owen (:bobowen) from comment #26)
> Also, wouldn't this have asserted in the old at
> http://hg.mozilla.org/mozilla-central/file/db13bb9473cc/dom/workers/
> WorkerRunnable.cpp#l293

> Thanks for sorting this out.
> I still can't work out why the assertions above this aren't firing, but
> haven't got time to look any further, sorry.

Bobby and I spoke on IRC.  In the case where a worker is canceled before it has a chance to ever run and get a thread, then it clears its pending event queue on the main thread with a faked out thread variable.

So that line you reference above would not fire because WorkerPrivate->GetParent() would return non-null.  (I think.)
https://hg.mozilla.org/mozilla-central/rev/4381dcc466e6
Assignee: nobody → bobbyholley
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla34
Comment 40 is before this has merged around.
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: