1800963 - High freq dom/base/crashtests/<test> | assertion count 1 is more than expected 0 assertions

Status: RESOLVED DUPLICATE of bug 1709012

(Core :: DOM: HTML Parser, defect)

Description

[Treeherder Bug Filer]

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=396755526&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Hmi8mgzYSEmaKNpCwpUvvg/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Hmi8mgzYSEmaKNpCwpUvvg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

[task 2022-11-16T18:54:17.948Z] 18:54:17     INFO - REFTEST TEST-PASS | dom/base/crashtests/830098.html | (LOAD ONLY)
[task 2022-11-16T18:54:17.950Z] 18:54:17     INFO - REFTEST TEST-END | dom/base/crashtests/830098.html
[task 2022-11-16T18:54:18.801Z] 18:54:18     INFO - [Child 1804, Main Thread] ###!!! ASSERTION: Somehow there's stuff in the op queue.: 'NS_FAILED(mBroken) || mOpQueue.IsEmpty()', file /builds/worker/checkouts/gecko/parser/html/nsHtml5TreeOpExecutor.cpp:145
[task 2022-11-16T18:54:18.803Z] 18:54:18     INFO - #01: NS_DebugBreak [xpcom/base/nsDebugImpl.cpp:0]
[task 2022-11-16T18:54:18.804Z] 18:54:18     INFO - #02: nsHtml5TreeOpExecutor::~nsHtml5TreeOpExecutor() [parser/html/nsHtml5TreeOpExecutor.cpp:146]
[task 2022-11-16T18:54:18.805Z] 18:54:18     INFO - #03: nsHtml5TreeOpExecutor::~nsHtml5TreeOpExecutor() [parser/html/nsHtml5TreeOpExecutor.cpp:131]
[task 2022-11-16T18:54:18.807Z] 18:54:18     INFO - #04: SnowWhiteKiller::MaybeKillObject(SnowWhiteKiller::SnowWhiteObject&) [xpcom/base/nsCycleCollector.cpp:0]
[task 2022-11-16T18:54:18.808Z] 18:54:18     INFO - #05: SnowWhiteKiller::~SnowWhiteKiller() [xpcom/base/nsCycleCollector.cpp:2432]
[task 2022-11-16T18:54:18.809Z] 18:54:18     INFO - #06: nsCycleCollector::FreeSnowWhite(bool) [xpcom/base/nsCycleCollector.cpp:0]
[task 2022-11-16T18:54:18.810Z] 18:54:18     INFO - #07: nsCycleCollector::BeginCollection(mozilla::CCReason, ccIsManual, nsICycleCollectorListener*) [xpcom/base/nsCycleCollector.cpp:3616]
[task 2022-11-16T18:54:18.812Z] 18:54:18     INFO - #08: nsCycleCollector::Collect(mozilla::CCReason, ccIsManual, js::SliceBudget&, nsICycleCollectorListener*, bool) [xpcom/base/nsCycleCollector.cpp:0]
[task 2022-11-16T18:54:18.813Z] 18:54:18     INFO - #09: nsCycleCollector_collectSlice(js::SliceBudget&, mozilla::CCReason, bool) [xpcom/base/nsCycleCollector.cpp:3964]
[task 2022-11-16T18:54:18.814Z] 18:54:18     INFO - #10: nsJSContext::RunCycleCollectorSlice(mozilla::CCReason, mozilla::TimeStamp) [dom/base/nsJSEnvironment.cpp:1462]
[task 2022-11-16T18:54:18.815Z] 18:54:18     INFO - #11: mozilla::CCGCScheduler::CCRunnerFired(mozilla::TimeStamp) [dom/base/nsJSEnvironment.cpp:0]
[task 2022-11-16T18:54:18.817Z] 18:54:18     INFO - #12: mozilla::IdleTaskRunner::Run() [xpcom/threads/IdleTaskRunner.cpp:130]
[task 2022-11-16T18:54:18.818Z] 18:54:18     INFO - #13: mozilla::IdleTaskRunnerTask::Run() [xpcom/threads/IdleTaskRunner.cpp:47]
[task 2022-11-16T18:54:18.819Z] 18:54:18     INFO - #14: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:851]
[task 2022-11-16T18:54:18.820Z] 18:54:18     INFO - #15: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:725]
[task 2022-11-16T18:54:18.822Z] 18:54:18     INFO - #16: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:461]
[task 2022-11-16T18:54:18.823Z] 18:54:18     INFO - #17: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_2>::Run() [xpcom/threads/nsThreadUtils.h:547]
[task 2022-11-16T18:54:18.824Z] 18:54:18     INFO - #18: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1208]
[task 2022-11-16T18:54:18.825Z] 18:54:18     INFO - #19: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:474]
[task 2022-11-16T18:54:18.826Z] 18:54:18     INFO - #20: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:86]
[task 2022-11-16T18:54:18.828Z] 18:54:18     INFO - #21: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:0]
[task 2022-11-16T18:54:18.829Z] 18:54:18     INFO - #22: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:357]
[task 2022-11-16T18:54:18.830Z] 18:54:18     INFO - #23: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:152]
[task 2022-11-16T18:54:18.831Z] 18:54:18     INFO - #24: XRE_RunAppShell() [toolkit/xre/nsEmbedFunctions.cpp:884]
[task 2022-11-16T18:54:18.832Z] 18:54:18     INFO - #25: mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:235]
[task 2022-11-16T18:54:18.834Z] 18:54:18     INFO - #26: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:0]
[task 2022-11-16T18:54:18.835Z] 18:54:18     INFO - #27: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:357]
[task 2022-11-16T18:54:18.836Z] 18:54:18     INFO - #28: XRE_InitChildProcess(int, char**, XREChildData const*) [toolkit/xre/nsEmbedFunctions.cpp:0]
[task 2022-11-16T18:54:18.837Z] 18:54:18     INFO - #29: content_process_main(mozilla::Bootstrap*, int, char**) [ipc/contentproc/plugin-container.cpp:58]
[task 2022-11-16T18:54:18.838Z] 18:54:18     INFO - #30: main [browser/app/nsBrowserApp.cpp:359]
[task 2022-11-16T18:54:18.839Z] 18:54:18     INFO - #31: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x21b97]
[task 2022-11-16T18:54:18.840Z] 18:54:18     INFO - #32: ??? [/builds/worker/workspace/build/application/firefox/firefox-bin + 0x46ec9]
[task 2022-11-16T18:54:18.841Z] 18:54:18     INFO - #33: ??? (???:???)
[task 2022-11-16T18:54:19.216Z] 18:54:19     INFO - REFTEST TEST-UNEXPECTED-FAIL | dom/base/crashtests/830098.html | assertion count 1 is more than expected 0 assertions
[task 2022-11-16T18:54:19.218Z] 18:54:19     INFO - REFTEST TEST-START | dom/base/crashtests/831287.html
[task 2022-11-16T18:54:19.218Z] 18:54:19     INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/dom/base/crashtests/831287.html | 268 / 3930 (6%)
[task 2022-11-16T18:54:19.322Z] 18:54:19     INFO - REFTEST TEST-PASS | dom/base/crashtests/831287.html | (LOAD ONLY)

Comment 1

[Cristian Tuns]

Backfills: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&fromchange=659083b7858bd86952ce52b157fd6ba200fda454&searchStr=linux%2C18.04%2Cx64%2Cwebrender%2Cdebug%2Creftests%2Ctest-linux1804-64-qr%2Fdebug-crashtest%2Cc&tochange=bcc0928c17b4a3b962f57b11f44ad53eca56ae9b
This is a bit weird, I can't tell where is this coming from. Can someone please take a look?
Thanks!

Comment 2

[Cristian Tuns]

Might be from this push: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&searchStr=linux%2C18.04%2Cx64%2Cwebrender%2Cdebug%2Creftests%2Ctest-linux1804-64-qr%2Fdebug-crashtest%2Cc&revision=b77125a16db163b497e5a43dcf03c6fa43359005&selectedTaskRun=U9UTb1wnQWWDTuyiXIzMCw.0
Olli can you please take a look?

Comment 3

[Olli Pettay [:smaug][[e-mail]]]

Oh, interesting that there has been similar bug before, bug 1759252.
My patch did change some scheduling, so yes, it is possible it might have triggered the issue which caused also bug 1759252
Looking.

Comment 4

[Olli Pettay [:smaug][[e-mail]]]

The assertion in bug 1759252 is the same, at least in the most recent logs there from August.

[task 2022-08-19T06:52:54.295Z] 06:52:54 INFO - [Child 1836, Main Thread] ###!!! ASSERTION: Somehow there's stuff in the op queue.: 'NS_FAILED(mBroken) || mOpQueue.IsEmpty()', file /builds/worker/checkouts/gecko/parser/html/nsHtml5TreeOpExecutor.cpp:145
[task 2022-08-19T06:52:54.297Z] 06:52:54 INFO - #01: NS_DebugBreak [xpcom/base/nsDebugImpl.cpp:492]
[task 2022-08-19T06:52:54.298Z] 06:52:54 INFO - #02: nsHtml5TreeOpExecutor::~nsHtml5TreeOpExecutor() [parser/html/nsHtml5TreeOpExecutor.cpp:146]
[task 2022-08-19T06:52:54.299Z] 06:52:54 INFO - #03: nsHtml5TreeOpExecutor::~nsHtml5TreeOpExecutor() [parser/html/nsHtml5TreeOpExecutor.cpp:131]
[task 2022-08-19T06:52:54.301Z] 06:52:54 INFO - #04: SnowWhiteKiller::MaybeKillObject(SnowWhiteKiller::SnowWhiteObject&) [xpcom/base/nsCycleCollector.cpp:2419]

So we're deleting nsHtml5TreeOpExecutor when it has still ops. Does this ring immediately some bells, hsivonen?

Comment 5

[Olli Pettay [:smaug][[e-mail]]]

There is also https://bugzilla.mozilla.org/show_bug.cgi?id=1746047 and
https://bugzilla.mozilla.org/show_bug.cgi?id=1709012

So, we may want to annotate the test to expect 0-1 assertions while investigating the root cause (which has been there for a long time)

Comment 6

[Olli Pettay [:smaug][[e-mail]]]

https://bugzilla.mozilla.org/show_bug.cgi?id=766792 fixed one instance of this but there is something else happening too.

Comment 7

[Intermittent Failures Robot]

20 failures in 629 pushes (0.032 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 20

Platform and build breakdown:

• linux1804-64-qr: 12
  • debug: 12
• windows10-64-2004-qr: 2
  • debug: 2
• macosx1015-64-qr: 2
  • debug: 2
• windows10-32-2004-qr: 2
  • debug: 2
• android-em-7-0-x86_64-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1800963&startday=2022-11-16&endday=2022-11-16&tree=all

Comment 9

[Intermittent Failures Robot]

83 failures in 717 pushes (0.116 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 61
• try: 5
• mozilla-central: 17

Platform and build breakdown:

• windows10-32-2004-qr: 5
  • debug: 5
• linux1804-64-qr: 23
  • debug: 23
• macosx1015-64-qr: 14
  • debug: 14
• windows10-64-2004-qr: 13
  • debug: 13
• android-em-7-0-x86_64-qr: 22
  • debug: 22
• linux1804-64-asan-qr: 4
  • opt: 4
• linux1804-64-ccov-qr: 2
  • opt: 2

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

Comment 12

[Intermittent Failures Robot]

66 failures in 671 pushes (0.098 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 45
• mozilla-central: 12
• try: 9

Platform and build breakdown:

• linux1804-64-qr: 23
  • debug: 23
• windows10-32-2004-qr: 7
  • debug: 7
• windows10-64-2004-qr: 10
  • debug: 10
• android-em-7-0-x86_64-qr: 21
  • debug: 21
• macosx1015-64-qr: 5
  • debug: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1800963&startday=2022-11-18&endday=2022-11-18&tree=all

Comment 13

[Intermittent Failures Robot]

48 failures in 142 pushes (0.338 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 34
• mozilla-central: 9
• try: 5

Platform and build breakdown:

• macosx1015-64-qr: 9
  • debug: 9
• windows10-64-2004-qr: 8
  • debug: 8
• linux1804-64-qr: 17
  • debug: 17
• windows10-32-2004-qr: 7
  • debug: 7
• android-em-7-0-x86_64-qr: 7
  • debug: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1800963&startday=2022-11-19&endday=2022-11-19&tree=all

Comment 14

[Intermittent Failures Robot]

246 failures in 3589 pushes (0.069 failures/push) were associated with this bug in the last 7 days.

This is the #3 most frequent failure this week.

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 174
• mozilla-central: 50
• try: 22

Platform and build breakdown:

• linux1804-64-qr: 88
  • debug: 88
• android-em-7-0-x86_64-qr: 56
  • debug: 56
• macosx1015-64-qr: 37
  • debug: 37
• windows10-64-2004-qr: 35
  • debug: 35
• windows10-32-2004-qr: 24
  • debug: 24
• linux1804-64-asan-qr: 4
  • opt: 4
• linux1804-64-ccov-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1800963&startday=2022-11-14&endday=2022-11-20&tree=all

Comment 15

[Intermittent Failures Robot]

68 failures in 795 pushes (0.086 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 49
• mozilla-central: 8
• try: 11

Platform and build breakdown:

• macosx1015-64-qr: 13
  • debug: 13
• linux1804-64-qr: 17
  • debug: 17
• windows10-32-2004-qr: 6
  • debug: 6
• windows10-64-2004-qr: 14
  • debug: 14
• android-em-7-0-x86_64-qr: 18
  • debug: 18

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1800963&startday=2022-11-21&endday=2022-11-21&tree=all

Comment 16

[Henri Sivonen (:hsivonen)]

I have a patch to remove the assertion in bug 1709012. Leaving this open instead of marking as a duplicate in order not to hide this from Treeherder just yet.

Comment 17

[Intermittent Failures Robot]

40 failures in 785 pushes (0.051 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 27
• mozilla-central: 4
• try: 9

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 12
  • debug: 12
• linux1804-64-qr: 10
  • debug: 10
• macosx1015-64-qr: 10
  • debug: 10
• windows10-64-2004-qr: 6
  • debug: 6
• windows10-32-2004-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1800963&startday=2022-11-22&endday=2022-11-22&tree=all