1681819 - Assertion failure: !mReportedUseCounters, at /builds/worker/workspace/obj-build/dist/include/mozilla/dom/WorkerPrivate.h:936

Status: VERIFIED FIXED

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

Description

[Jason Kratzer [:jkratzer]]

Attachment: testcase.zip

Testcase found while fuzzing mozilla-central rev 73f050da7d20 (built with --enable-debug). Testcase is not fully reduced and may take several reloads to trigger. I will upload a pernosco trace for this issue shortly.

Assertion failure: !mReportedUseCounters, at /builds/worker/workspace/obj-build/dist/include/mozilla/dom/WorkerPrivate.h:936

    #0 0x7f12013f2c7e in SetUseCounter /builds/worker/workspace/obj-build/dist/include/mozilla/dom/WorkerPrivate.h:936:5
    #1 0x7f12013f2c7e in mozilla::dom::SetUseCounter(mozilla::UseCounterWorker) /builds/worker/checkouts/gecko/dom/bindings/BindingUtils.cpp:3981:20
    #2 0x7f12007a3753 in subscribe /builds/worker/workspace/obj-build/dom/bindings/PushManagerBinding.cpp:517:5
    #3 0x7f12007a3753 in mozilla::dom::PushManager_Binding::subscribe_promiseWrapper(JSContext*, JS::Handle<JSObject*>, void*, JSJitMethodCallArgs const&) /builds/worker/workspace/obj-build/dom/bindings/PushManagerBinding.cpp:529:13
    #4 0x7f12013e273f in bool mozilla::dom::binding_detail::GenericMethod<mozilla::dom::binding_detail::NormalThisPolicy, mozilla::dom::binding_detail::ConvertExceptionsToPromises>(JSContext*, unsigned int, JS::Value*) /builds/worker/checkouts/gecko/dom/bindings/BindingUtils.cpp:3231:13
    #5 0x7f12043dbd41 in CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), js::CallReason, JS::CallArgs const&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:503:13
    #6 0x7f12043db60c in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:594:12
    #7 0x7f12043dcd73 in InternalCall(JSContext*, js::AnyInvokeArgs const&, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:647:10
    #8 0x7f12043d1262 in CallFromStack /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:651:10
    #9 0x7f12043d1262 in Interpret(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:3309:16
    #10 0x7f12043c8378 in js::RunScript(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:473:13
    #11 0x7f12043db576 in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:619:13
    #12 0x7f12043dcd73 in InternalCall(JSContext*, js::AnyInvokeArgs const&, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:647:10
    #13 0x7f12043dcfaf in js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:664:8
    #14 0x7f1204981ecb in JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) /builds/worker/checkouts/gecko/js/src/jsapi.cpp:2838:10
    #15 0x7f120118afc0 in mozilla::dom::VoidFunction::Call(mozilla::dom::BindingCallContext&, JS::Handle<JS::Value>, mozilla::ErrorResult&) /builds/worker/workspace/obj-build/dom/bindings/FunctionBinding.cpp:77:8
    #16 0x7f120022637c in mozilla::dom::VoidFunction::Call(mozilla::ErrorResult&, char const*, mozilla::dom::CallbackObject::ExceptionHandling, JS::Realm*) /builds/worker/workspace/obj-build/dist/include/mozilla/dom/FunctionBinding.h:173:12
    #17 0x7f120022615e in QueuedMicrotask::Run(mozilla::AutoSlowOperation&) /builds/worker/checkouts/gecko/dom/base/nsIGlobalObject.cpp:266:31
    #18 0x7f11fe3bda04 in mozilla::CycleCollectedJSContext::PerformMicroTaskCheckPoint(bool) /builds/worker/checkouts/gecko/xpcom/base/CycleCollectedJSContext.cpp:644:17
    #19 0x7f11fe3be679 in mozilla::CycleCollectedJSContext::AfterProcessTask(unsigned int) /builds/worker/checkouts/gecko/xpcom/base/CycleCollectedJSContext.cpp:461:3
    #20 0x7f11fe4ca70c in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1236:24
    #21 0x7f11fe4d04aa in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:548:10
    #22 0x7f1202688038 in mozilla::dom::WorkerPrivate::DoRunLoop(JSContext*) /builds/worker/checkouts/gecko/dom/workers/WorkerPrivate.cpp:2991:7
    #23 0x7f12026688b5 in mozilla::dom::workerinternals::(anonymous namespace)::WorkerThreadPrimaryRunnable::Run() /builds/worker/checkouts/gecko/dom/workers/RuntimeService.cpp:2240:40
    #24 0x7f11fe4ca48f in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1200:14
    #25 0x7f11fe4d04aa in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:548:10
    #26 0x7f11fedd3876 in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:332:5
    #27 0x7f11fed3eb23 in MessageLoop::RunInternal() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:334:10
    #28 0x7f11fed3ea3d in RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:327:3
    #29 0x7f11fed3ea3d in MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:309:3
    #30 0x7f11fe4c6b8e in nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:441:10
    #31 0x7f121498babb in _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5
    #32 0x7f1214efd608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477:8
    #33 0x7f1214ac6292 in clone /build/glibc-ZN95T4/glibc-2.31/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment 1

[Jason Kratzer [:jkratzer]]

Bugmon Analysis:
Verified bug as reproducible on mozilla-central 20201210155912-7a6d6b986a1e.
Failed to bisect testcase (Testcase reproduces on start build!):

Start: 61ec58edfd13861591d5cd4b6387de92b35f23e3 (20191213040758)
End: 7b5facb4df3a77bd60d21045be212161c91cea12 (20201210034702)
BuildFlags: BuildFlags(asan=False, tsan=False, debug=True, fuzzing=False, coverage=False, valgrind=False)

Comment 2

[Tom Tung [:tt, :ttung]]

Looks like mReportedUseCounters was introduced in bug 1202706 so put it in see also.

Comment 3

[Jens Stutte [:jstutte]]

mReportedUseCounters is set through ClearMainEventQueue. There seem to be several code paths that can bring us there. Especially the WorkerPrivate::NotifyInternal could happen anytime?

Probably instead of asserting we should just do nothing in case?

Comment 4

[Edgar Chen [:edgar]]

When I wrote the code, I thought that https://searchfox.org/mozilla-central/rev/23c25cd32a1e87095301273937b4ee162f41e860/dom/workers/WorkerPrivate.cpp#3585 is a good place to hook when a worker is about to be destroyed, but apparently, it seems it is not. What we wanna do is probably to move the ReportUseCounters to a suitable point that could ensure there won't be any use counter need to report after that.

Comment 5

[Intermittent Failures Robot]

1 failures in 1450 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1681819&startday=2020-12-21&endday=2020-12-27&tree=all

Comment 6

[Intermittent Failures Robot]

1 failures in 3810 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux1804-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1681819&startday=2021-01-11&endday=2021-01-17&tree=all

Comment 7

[Intermittent Failures Robot]

4 failures in 3488 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3
• mozilla-central: 1

Platform and build breakdown:

• linux1804-64: 3
  • debug: 3
• macosx1014-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1681819&startday=2021-01-18&endday=2021-01-24&tree=all

Comment 8

[Jens Stutte [:jstutte]]

(In reply to Edgar Chen [:edgar] from comment #4)

When I wrote the code, I thought that https://searchfox.org/mozilla-central/rev/23c25cd32a1e87095301273937b4ee162f41e860/dom/workers/WorkerPrivate.cpp#3585 is a good place to hook when a worker is about to be destroyed, but apparently, it seems it is not. What we wanna do is probably to move the ReportUseCounters to a suitable point that could ensure there won't be any use counter need to report after that.

At least it seems, that after this point we can still happen to call SetUseCounters which is called from quite some places. IIUC, currently we are not supposed to change the counter any more once we reported it. Are we sure we can even find a "late enough" moment for reporting in order to exclude any interference with other pending events? Or should we just ignore them afterwards rather than asserting?

Comment 9

[Edgar Chen [:edgar]]

(In reply to Jason Kratzer [:jkratzer] from comment #0)

Testcase found while fuzzing mozilla-central rev 73f050da7d20 (built with --enable-debug). Testcase is not fully reduced and may take several reloads to trigger. I will upload a pernosco trace for this issue shortly.

ni for pernosco trace if possible, thanks!

Comment 10

[Tyson Smith [:tsmith]]

A Pernosco session is available here: https://pernos.co/debug/9CP4yuOyONZ9jLnvw2t-gA/index.html

Comment 11

[Intermittent Failures Robot]

2 failures in 3891 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• linux1804-64: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1681819&startday=2021-01-25&endday=2021-01-31&tree=all

Comment 12

[Intermittent Failures Robot]

1 failures in 3966 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1681819&startday=2021-02-01&endday=2021-02-07&tree=all

Comment 13

[Intermittent Failures Robot]

3 failures in 4322 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3

Platform and build breakdown:

• windows10-64: 2
  • debug: 2
• linux1804-64: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1681819&startday=2021-02-08&endday=2021-02-14&tree=all

Comment 14

[Intermittent Failures Robot]

2 failures in 4327 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• macosx1014-64-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1681819&startday=2021-02-22&endday=2021-02-28&tree=all

Comment 15

[Edgar Chen [:edgar]]

Okay, so the js execution is from mircotask after WorkerPrivate::ClearMainEventQueue

Comment 16

[Edgar Chen [:edgar]]

Attachment: Bug 1681819 - Report usecounter when worker is in killing state;

Previously, we report usecounter when clearing main event queue, but js execution
could still happen on the microtask after that. So defer the reporting to worker
is in killing state.

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/9e371861963a
Report usecounter when worker is in killing state; r=asuth

Comment 18

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/9e371861963a

Comment 19

[Bugmon [:jkratzer for issues]]

Bugmon Analysis:
Verified bug as fixed on rev mozilla-central 20210302034602-8d43bd9291a5.
Removing bugmon keyword as no further action possible.
Please review the bug and re-add the keyword for further analysis.

Comment 20

[BugBot [:suhaib / :marco/ :calixte]]

:edgar, since this bug contains a bisection range, could you fill (if possible) the regressed_by field?
For more information, please visit auto_nag documentation.