1818391 - Intermittent Assertion failure: sample >= 0 && sample <= 100, at /builds/worker/checkouts/gecko/js/src/vm/Runtime.h:275

Status: RESOLVED FIXED

(Core :: JavaScript: GC, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=406587251&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/UqZR7Z_RRO6C2NujJzGQxA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2023-02-22T23:38:49.011Z] 23:38:49     INFO - TEST-START | dom/events/test/test_event_screenXY_in_cross_origin_iframe.html
[task 2023-02-22T23:38:49.069Z] 23:38:49     INFO - GECKO(3792) | Assertion failure: sample >= 0 && sample <= 100, at /builds/worker/checkouts/gecko/js/src/vm/Runtime.h:275
[task 2023-02-22T23:38:49.233Z] 23:38:49     INFO -  Initializing stack-fixing for the first stack frame, this may take a while...
[task 2023-02-22T23:39:09.968Z] 23:39:09     INFO - GECKO(3792) | #01: js::gcstats::Statistics::sendGCTelemetry() [js/src/gc/Statistics.cpp:1079]
[task 2023-02-22T23:39:09.974Z] 23:39:09     INFO - GECKO(3792) | #02: js::gcstats::Statistics::endSlice() [js/src/gc/Statistics.cpp:1206]
[task 2023-02-22T23:39:09.974Z] 23:39:09     INFO - GECKO(3792) | #03: js::gc::GCRuntime::gcCycle(bool, js::SliceBudget const&, JS::GCReason) [js/src/gc/GC.cpp:4217]
[task 2023-02-22T23:39:09.975Z] 23:39:09     INFO - GECKO(3792) | #04: js::gc::GCRuntime::collect(bool, js::SliceBudget const&, JS::GCReason) [js/src/gc/GC.cpp:4398]
[task 2023-02-22T23:39:09.975Z] 23:39:09     INFO - GECKO(3792) | #05: js::gc::GCRuntime::gcIfRequestedImpl(bool) [js/src/gc/GC.cpp:4676]
[task 2023-02-22T23:39:09.976Z] 23:39:09     INFO - GECKO(3792) | #06: js::gc::GCRuntime::checkAllocatorState<1>(JSContext*, js::gc::AllocKind) [js/src/gc/Allocator.cpp:382]
[task 2023-02-22T23:39:09.976Z] 23:39:09     INFO - GECKO(3792) | #07: js::gc::detail::AllocateObject<1>(JSContext*, js::gc::AllocKind, unsigned long long, js::gc::InitialHeap, JSClass const*, js::gc::AllocSite*) [js/src/gc/Allocator.cpp:56]
[task 2023-02-22T23:39:09.977Z] 23:39:09     INFO - GECKO(3792) | #08: js::NativeObject::create(JSContext*, js::gc::AllocKind, js::gc::InitialHeap, JS::Handle<js::SharedShape *>, js::gc::AllocSite*) [js/src/vm/NativeObject-inl.h:447]
[task 2023-02-22T23:39:09.977Z] 23:39:09     INFO - GECKO(3792) | #09: NewObject(JSContext*, JSClass const*, JS::Handle<js::TaggedProto>, js::gc::AllocKind, js::NewObjectKind) [js/src/vm/JSObject.cpp:768]
[task 2023-02-22T23:39:09.978Z] 23:39:09     INFO - GECKO(3792) | #10: JS_NewObjectWithGivenProto(JSContext*, JSClass const*, JS::Handle<JSObject *>) [js/src/jsapi.cpp:1822]
[task 2023-02-22T23:39:09.978Z] 23:39:09     INFO - GECKO(3792) | #11: xpc::NewIDObjectHelper(JSContext*, JSClass const*) [js/xpconnect/src/XPCJSID.cpp:255]
[task 2023-02-22T23:39:09.979Z] 23:39:09     INFO - GECKO(3792) | #12: xpc::ID2JSValue(JSContext*, nsID const&, JS::MutableHandle<JS::Value>) [js/xpconnect/src/XPCJSID.cpp:261]
[task 2023-02-22T23:39:09.980Z] 23:39:09     INFO - GECKO(3792) | #13: mozilla::dom::CustomElementRegistry::CallGetCustomInterface(mozilla::dom::Element*, nsID const&) [dom/base/CustomElementRegistry.cpp:1373]
[task 2023-02-22T23:39:09.980Z] 23:39:09     INFO - GECKO(3792) | #14: mozilla::dom::Element::GetCustomInterface<nsIDOMXULControlElement>(nsGetterAddRefs<nsIDOMXULControlElement>) [dom/base/Element.cpp:4173]
[task 2023-02-22T23:39:09.980Z] 23:39:09     INFO - GECKO(3792) | #15: mozilla::dom::Element::AsXULControl() [dom/base/Element.cpp:4278]
[task 2023-02-22T23:39:09.981Z] 23:39:09     INFO - GECKO(3792) | #16: nsXULElement::IsFocusableInternal(int*, bool) [dom/xul/nsXULElement.cpp:413]
[task 2023-02-22T23:39:09.981Z] 23:39:09     INFO - GECKO(3792) | #17: nsIFrame::IsFocusable(bool, bool) [layout/generic/nsIFrame.cpp:10584]
[task 2023-02-22T23:39:09.982Z] 23:39:09     INFO - GECKO(3792) | #18: mozilla::PresShell::FixUpFocus() [layout/base/PresShell.cpp:1557]
[task 2023-02-22T23:39:09.982Z] 23:39:09     INFO - GECKO(3792) | #19: nsRefreshDriver::Tick(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp, nsRefreshDriver::IsExtraTick) [layout/base/nsRefreshDriver.cpp:2658]
[task 2023-02-22T23:39:09.983Z] 23:39:09     INFO - GECKO(3792) | #20: mozilla::detail::RunnableFunction<`lambda at /builds/worker/checkouts/gecko/layout/base/nsRefreshDriver.cpp:1775:15'>::Run() [xpcom/threads/nsThreadUtils.h:547]
[task 2023-02-22T23:39:09.983Z] 23:39:09     INFO - GECKO(3792) | #21: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:542]
[task 2023-02-22T23:39:09.984Z] 23:39:09     INFO - GECKO(3792) | #22: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex &> const&) [xpcom/threads/TaskController.cpp:855]
[task 2023-02-22T23:39:09.984Z] 23:39:09     INFO - GECKO(3792) | #23: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex &> const&) [xpcom/threads/TaskController.cpp:686]
[task 2023-02-22T23:39:09.984Z] 23:39:09     INFO - GECKO(3792) | #24: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:464]
[task 2023-02-22T23:39:09.985Z] 23:39:09     INFO - GECKO(3792) | #25: mozilla::detail::RunnableFunction<`lambda at /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:188:7'>::Run() [xpcom/threads/nsThreadUtils.h:547]
[task 2023-02-22T23:39:09.985Z] 23:39:09     INFO - GECKO(3792) | #26: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1229]
[task 2023-02-22T23:39:09.986Z] 23:39:09     INFO - GECKO(3792) | #27: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:477]
[task 2023-02-22T23:39:09.986Z] 23:39:09     INFO - GECKO(3792) | #28: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:86]
[task 2023-02-22T23:39:09.986Z] 23:39:09     INFO - GECKO(3792) | #29: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:375]
[task 2023-02-22T23:39:09.987Z] 23:39:09     INFO - GECKO(3792) | #30: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:357]
[task 2023-02-22T23:39:09.988Z] 23:39:09     INFO - GECKO(3792) | #31: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:150]
[task 2023-02-22T23:39:09.988Z] 23:39:09     INFO - GECKO(3792) | #32: nsAppShell::Run() [widget/windows/nsAppShell.cpp:614]
[task 2023-02-22T23:39:09.989Z] 23:39:09     INFO - GECKO(3792) | #33: nsAppStartup::Run() [toolkit/components/startup/nsAppStartup.cpp:296]
[task 2023-02-22T23:39:09.989Z] 23:39:09     INFO - GECKO(3792) | #34: XREMain::XRE_mainRun() [toolkit/xre/nsAppRunner.cpp:5650]
[task 2023-02-22T23:39:09.989Z] 23:39:09     INFO - GECKO(3792) | #35: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:5843]
[task 2023-02-22T23:39:09.990Z] 23:39:09     INFO - GECKO(3792) | #36: XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:5899]
[task 2023-02-22T23:39:10.048Z] 23:39:10     INFO - GECKO(3792) | #37: NS_internal_main(int, char**, char**) [browser/app/nsBrowserApp.cpp:423]
[task 2023-02-22T23:39:10.052Z] 23:39:10     INFO - GECKO(3792) | #38: wmain(int, wchar_t**) [toolkit/xre/nsWindowsWMain.cpp:167]
[task 2023-02-22T23:39:10.052Z] 23:39:10     INFO - GECKO(3792) | #39: __scrt_common_main_seh() [/builds/worker/workspace/obj-build/browser/app/d:/agent/_work/2/s/src/vctools/crt/vcstartup/src/startup/exe_common.inl:288]
[task 2023-02-22T23:39:10.054Z] 23:39:10     INFO -  fix-stacks: error: failed to read debug info file `wkernel32.pdb` for `C:\Windows\System32\KERNEL32.DLL`
[task 2023-02-22T23:39:10.054Z] 23:39:10     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2023-02-22T23:39:10.055Z] 23:39:10     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2023-02-22T23:39:10.055Z] 23:39:10     INFO - GECKO(3792) | #40: BaseThreadInitThunk [C:\Windows\System32\KERNEL32.DLL + 0x17034]
[task 2023-02-22T23:39:10.059Z] 23:39:10     INFO -  fix-stacks: error: failed to read debug info file `wntdll.pdb` for `C:\Windows\SYSTEM32\ntdll.dll`
[task 2023-02-22T23:39:10.059Z] 23:39:10     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2023-02-22T23:39:10.059Z] 23:39:10     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2023-02-22T23:39:10.059Z] 23:39:10     INFO - GECKO(3792) | #41: RtlUserThreadStart [C:\Windows\SYSTEM32\ntdll.dll + 0x52651]
[task 2023-02-22T23:39:10.060Z] 23:39:10     INFO - GECKO(3792) | [GPU 4532, IPC I/O Child] WARNING: [19090C93877FE0C5.4527E3B19D5D55B0]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-02-22T23:39:10.060Z] 23:39:10     INFO - GECKO(3792) | [GPU 4532, IPC I/O Child] WARNING: [19090C93877FE0C5.4527E3B19D5D55B0]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-02-22T23:39:10.061Z] 23:39:10     INFO - GECKO(3792) | [GPU 4532, IPC I/O Child] WARNING: [19090C93877FE0C5.4527E3B19D5D55B0]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-02-22T23:39:10.062Z] 23:39:10     INFO - GECKO(3792) | [GPU 4532, IPC I/O Child] WARNING: [19090C93877FE0C5.4527E3B19D5D55B0]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-02-22T23:39:10.062Z] 23:39:10     INFO - GECKO(3792) | [GPU 4532, IPC I/O Child] WARNING: [19090C93877FE0C5.4527E3B19D5D55B0]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-02-22T23:39:10.063Z] 23:39:10     INFO - GECKO(3792) | [GPU 4532, IPC I/O Child] WARNING: [19090C93877FE0C5.4527E3B19D5D55B0]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-02-22T23:39:10.063Z] 23:39:10     INFO - GECKO(3792) | [GPU 4532, IPC I/O Child] WARNING: [19090C93877FE0C5.4527E3B19D5D55B0]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-02-22T23:39:10.064Z] 23:39:10     INFO - GECKO(3792) | [GPU 4532, Compositor] WARNING: IPC message 'PCompositorWidget::Msg_UnobserveVsync' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:504
[task 2023-02-22T23:39:10.064Z] 23:39:10     INFO - GECKO(3792) | [GPU 4532, Main Thread] WARNING: Shutting down GPU process early due to a crash!: file /builds/worker/checkouts/gecko/gfx/ipc/GPUParent.cpp:662
[task 2023-02-22T23:39:10.064Z] 23:39:10     INFO - TEST-INFO | Main app process: exit 1

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1818391&startday=2023-02-20&endday=2023-02-26&tree=all

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1
• autoland: 2

Platform and build breakdown:

• windows11-64-2009-mingwclang-qr: 1
  • debug: 1
• windows11-32-2009-qr: 1
  • debug: 1
• windows11-64-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1818391&startday=2023-03-13&endday=2023-03-19&tree=all

Comment 3

[Jon Coppeard (:jonco)]

Seems likely that bug 1817741 caused this.

Comment 4

[Jon Coppeard (:jonco)]

Attachment: Bug 1818391 - Clamp parallel marking utilization telemetry value r?sfink

I don't know how this is generating a value that is outside these limits, but
we can sometimes get inconsistent timestamps so maybe that is happening. The
simplest thing to do is clamp the value to sensible limits.

Comment 5

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

Set release status flags based on info from the regressing bug 1817741

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/3f97a21c0099
Clamp parallel marking utilization telemetry value r=sfink

Comment 7

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/3f97a21c0099

Comment 8

[Sandor Molnar[:smolnar]]

This failure is still happening

Failure log: https://treeherder.mozilla.org/logviewer?job_id=409874078&repo=autoland&lineNumber=19123

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:

• comm-central: 1
• autoland: 1

Platform and build breakdown:

• windows11-64-2009-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1818391&startday=2023-03-20&endday=2023-03-26&tree=all