Closed Bug 1781944 Opened 2 years ago Closed 2 years ago

Intermittent TV gfx/tests/crashtests/1757054.html | assertion count 21 is more than expected 0 assertions | ASSERTION: InitialOverflowProperty must be set first.: 'frame->GetProperty(nsIFrame::DebugInitialOverflowPropertyApplied())

Categories

(Core :: Layout, defect, P5)

Product:
Core
Component:
Layout
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE
Tracking Flags:
Tracking Status
firefox-esr91 --- unaffected
firefox-esr102 --- unaffected
firefox103 --- unaffected
firefox104 --- unaffected
firefox105 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: assertion, intermittent-failure, regression)

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=385613647&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/VTek6O0GR7i-XxgEBHO0PA/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/VTek6O0GR7i-XxgEBHO0PA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2022-07-27T21:13:15.059Z] 21:13:15     INFO - REFTEST TEST-START | gfx/tests/crashtests/1757054.html
[task 2022-07-27T21:13:15.060Z] 21:13:15     INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/gfx/tests/crashtests/1757054.html | 0 / 1 (0%)
[task 2022-07-27T21:13:15.097Z] 21:13:15     INFO - [Child 1738, Main Thread] WARNING: '!CanHandleWith(aPresContext)', file /builds/worker/checkouts/gecko/dom/events/IMEStateManager.cpp:498
[task 2022-07-27T21:13:15.116Z] 21:13:15     INFO - [Parent 1574, Main Thread] WARNING: WebProgress Ignored: no longer current window global: file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp:3097
[task 2022-07-27T21:13:15.149Z] 21:13:15     INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp2uwivjr_.mozrunner/runreftest_leaks_tab_pid1876.log
[task 2022-07-27T21:13:15.160Z] 21:13:15     INFO - [1876, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:339
[task 2022-07-27T21:13:15.169Z] 21:13:15     INFO - [Parent 1574, Compositor] WARNING: IPC Connection Error: [Parent][PCompositorManagerParent] RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost: file /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:1876
[task 2022-07-27T21:13:15.169Z] 21:13:15     INFO - [Parent 1574, Compositor] WARNING: IPC Connection Error: [Parent][PImageBridgeParent] RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost: file /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:1876
[task 2022-07-27T21:13:15.224Z] 21:13:15     INFO - [Child 1738, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2022-07-27T21:13:15.246Z] 21:13:15     INFO - [Child 1738, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file /builds/worker/workspace/obj-build/dist/include/mozilla/Preferences.h:129
[task 2022-07-27T21:13:15.263Z] 21:13:15     INFO - [Child 1738, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4595
[task 2022-07-27T21:13:15.268Z] 21:13:15     INFO - [Child 1876, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:707
[task 2022-07-27T21:13:15.373Z] 21:13:15     INFO - [Child 1876, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012 (NS_ERROR_FILE_NOT_FOUND): file /builds/worker/checkouts/gecko/layout/style/Loader.cpp:2041
[task 2022-07-27T21:13:15.605Z] 21:13:15     INFO - [Child 1876, Main Thread] ###!!! ASSERTION: InitialOverflowProperty must be set first.: 'frame->GetProperty(nsIFrame::DebugInitialOverflowPropertyApplied())', file /builds/worker/checkouts/gecko/layout/base/OverflowChangedTracker.h:117
[task 2022-07-27T21:13:15.615Z] 21:13:15     INFO -  Initializing stack-fixing for the first stack frame, this may take a while...
[task 2022-07-27T21:13:23.906Z] 21:13:23     INFO - #01: NS_DebugBreak [xpcom/base/nsDebugImpl.cpp:492]
[task 2022-07-27T21:13:23.907Z] 21:13:23     INFO - #02: mozilla::OverflowChangedTracker::Flush() [layout/base/OverflowChangedTracker.h:120]
[task 2022-07-27T21:13:23.907Z] 21:13:23     INFO - #03: mozilla::RestyleManager::ProcessRestyledFrames(nsStyleChangeList&) [layout/base/RestyleManager.cpp:1812]
[task 2022-07-27T21:13:23.908Z] 21:13:23     INFO - #04: mozilla::RestyleManager::DoProcessPendingRestyles(mozilla::ServoTraversalFlags) [layout/base/RestyleManager.cpp:3124]
[task 2022-07-27T21:13:23.908Z] 21:13:23     INFO - #05: mozilla::RestyleManager::ProcessPendingRestyles() [layout/base/RestyleManager.cpp:3204]
[task 2022-07-27T21:13:23.909Z] 21:13:23     INFO - #06: mozilla::PresShell::DoFlushPendingNotifications(mozilla::ChangesToFlush) [layout/base/PresShell.cpp:4331]
[task 2022-07-27T21:13:23.909Z] 21:13:23     INFO - #07: nsRefreshDriver::Tick(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp, nsRefreshDriver::IsExtraTick) [layout/base/nsRefreshDriver.cpp:2556]
[task 2022-07-27T21:13:23.910Z] 21:13:23     INFO - #08: mozilla::RefreshDriverTimer::TickRefreshDrivers(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp, nsTArray<RefPtr<nsRefreshDriver> >&) [layout/base/nsRefreshDriver.cpp:347]
[task 2022-07-27T21:13:23.911Z] 21:13:23     INFO - #09: mozilla::RefreshDriverTimer::Tick(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [layout/base/nsRefreshDriver.cpp:371]
[task 2022-07-27T21:13:23.912Z] 21:13:23     INFO - #10: mozilla::VsyncRefreshDriverTimer::RunRefreshDrivers(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [layout/base/nsRefreshDriver.cpp:897]
[task 2022-07-27T21:13:23.912Z] 21:13:23     INFO - #11: mozilla::VsyncRefreshDriverTimer::TickRefreshDriver(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [layout/base/nsRefreshDriver.cpp:812]
[task 2022-07-27T21:13:23.913Z] 21:13:23     INFO - #12: mozilla::VsyncRefreshDriverTimer::NotifyVsyncOnMainThread(mozilla::VsyncEvent const&) [layout/base/nsRefreshDriver.cpp:731]
[task 2022-07-27T21:13:23.913Z] 21:13:23     INFO - #13: mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::NotifyVsyncTimerOnMainThread() [layout/base/nsRefreshDriver.cpp:595]
[task 2022-07-27T21:13:23.914Z] 21:13:23     INFO - #14: mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::NotifyVsync(mozilla::VsyncEvent const&) [layout/base/nsRefreshDriver.cpp:551]
[task 2022-07-27T21:13:23.915Z] 21:13:23     INFO - #15: mozilla::dom::VsyncMainChild::RecvNotify(mozilla::VsyncEvent const&, float const&) [dom/ipc/VsyncMainChild.cpp:69]
[task 2022-07-27T21:13:23.916Z] 21:13:23     INFO - #16: mozilla::dom::PVsyncChild::OnMessageReceived(IPC::Message const&) [s3:gecko-generated-sources:cddf90894e78d2341d16b9328e85134e5d2e952562bcc3d6423ba1da1513d2f3a9a8317feeecb4fa176ce8ead295e50eabb87d97a405cec3d3fed6556109e377/ipc/ipdl/PVsyncChild.cpp::220]
[task 2022-07-27T21:13:23.916Z] 21:13:23     INFO - #17: mozilla::ipc::PBackgroundChild::OnMessageReceived(IPC::Message const&) [s3:gecko-generated-sources:f43b8d9aa4ec167f4e7e19574d958c30362890a6b63de818d0495ebfec1a3c925a776e3cefa85a83740d45f9227345090aedc47a3eed36db29fcf48c0a572a06/ipc/ipdl/PBackgroundChild.cpp::6326]
[task 2022-07-27T21:13:23.916Z] 21:13:23     INFO - #18: mozilla::ipc::MessageChannel::DispatchAsyncMessage(mozilla::ipc::ActorLifecycleProxy*, IPC::Message const&) [ipc/glue/MessageChannel.cpp:1749]
[task 2022-07-27T21:13:23.917Z] 21:13:23     INFO - #19: mozilla::ipc::MessageChannel::DispatchMessage(mozilla::ipc::ActorLifecycleProxy*, mozilla::UniquePtr<IPC::Message, mozilla::DefaultDelete<IPC::Message> >) [ipc/glue/MessageChannel.cpp:1677]
[task 2022-07-27T21:13:23.917Z] 21:13:23     INFO - #20: mozilla::ipc::MessageChannel::RunMessage(mozilla::ipc::ActorLifecycleProxy*, mozilla::ipc::MessageChannel::MessageTask&) [ipc/glue/MessageChannel.cpp:1474]
[task 2022-07-27T21:13:23.918Z] 21:13:23     INFO - #21: mozilla::ipc::MessageChannel::MessageTask::Run() [ipc/glue/MessageChannel.cpp:1581]
[task 2022-07-27T21:13:23.918Z] 21:13:23     INFO - #22: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:539]
[task 2022-07-27T21:13:23.919Z] 21:13:23     INFO - #23: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:851]
[task 2022-07-27T21:13:23.920Z] 21:13:23     INFO - #24: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:683]
[task 2022-07-27T21:13:23.920Z] 21:13:23     INFO - #25: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:461]
[task 2022-07-27T21:13:23.921Z] 21:13:23     INFO - #26: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_1>::Run() [xpcom/threads/nsThreadUtils.h:532]
[task 2022-07-27T21:13:23.921Z] 21:13:23     INFO - #27: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1209]
[task 2022-07-27T21:13:23.921Z] 21:13:23     INFO - #28: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:465]
[task 2022-07-27T21:13:23.922Z] 21:13:23     INFO - #29: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:107]
[task 2022-07-27T21:13:23.922Z] 21:13:23     INFO - #30: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:380]
[task 2022-07-27T21:13:23.923Z] 21:13:23     INFO - #31: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:356]
[task 2022-07-27T21:13:23.923Z] 21:13:23     INFO - #32: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:152]
[task 2022-07-27T21:13:23.924Z] 21:13:23     INFO - #33: XRE_RunAppShell() [toolkit/xre/nsEmbedFunctions.cpp:887]
[task 2022-07-27T21:13:23.924Z] 21:13:23     INFO - #34: mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:235]
[task 2022-07-27T21:13:23.925Z] 21:13:23     INFO - #35: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:380]
[task 2022-07-27T21:13:23.926Z] 21:13:23     INFO - #36: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:356]
[task 2022-07-27T21:13:23.926Z] 21:13:23     INFO - #37: XRE_InitChildProcess(int, char**, XREChildData const*) [toolkit/xre/nsEmbedFunctions.cpp:746]
[task 2022-07-27T21:13:23.956Z] 21:13:23     INFO - #38: content_process_main(mozilla::Bootstrap*, int, char**) [ipc/contentproc/plugin-container.cpp:58]
[task 2022-07-27T21:13:23.957Z] 21:13:23     INFO - #39: main [browser/app/nsBrowserApp.cpp:346]
[task 2022-07-27T21:13:23.961Z] 21:13:23     INFO - #40: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x21b97]
[task 2022-07-27T21:13:23.962Z] 21:13:23     INFO - #41: ??? [/builds/worker/workspace/build/application/firefox/firefox-bin + 0x44a49]
[task 2022-07-27T21:13:23.963Z] 21:13:23     INFO - #42: ??? (???:???)
[task 2022-07-27T21:13:23.965Z] 21:13:23     INFO - 
[task 2022-07-27T21:13:23.967Z] 21:13:23     INFO - [Child 1876, Main Thread] ###!!! ASSERTION: InitialOverflowProperty must be set first.: 'frame->GetProperty(nsIFrame::DebugInitialOverflowPropertyApplied())', file /builds/worker/checkouts/gecko/layout/base/OverflowChangedTracker.h:117
[task 2022-07-27T21:13:23.967Z] 21:13:23     INFO - #01: NS_DebugBreak [xpcom/base/nsDebugImpl.cpp:492]
<...>
[task 2022-07-27T21:13:24.668Z] 21:13:24     INFO - #39: main [browser/app/nsBrowserApp.cpp:346]
[task 2022-07-27T21:13:24.669Z] 21:13:24     INFO - #40: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x21b97]
[task 2022-07-27T21:13:24.670Z] 21:13:24     INFO - #41: ??? [/builds/worker/workspace/build/application/firefox/firefox-bin + 0x44a49]
[task 2022-07-27T21:13:24.671Z] 21:13:24     INFO - #42: ??? (???:???)
[task 2022-07-27T21:13:24.672Z] 21:13:24     INFO - REFTEST TEST-UNEXPECTED-FAIL | gfx/tests/crashtests/1757054.html | assertion count 21 is more than expected 0 assertions
[task 2022-07-27T21:13:24.673Z] 21:13:24     INFO - REFTEST INFO | Result summary:
[task 2022-07-27T21:13:24.673Z] 21:13:24     INFO - REFTEST INFO | Successful: 1 (0 pass, 1 load only)
[task 2022-07-27T21:13:24.673Z] 21:13:24     INFO - REFTEST INFO | Unexpected: 1 (0 unexpected fail, 0 unexpected pass, 1 unexpected asserts, 0 failed load, 0 exception)
[task 2022-07-27T21:13:24.674Z] 21:13:24     INFO - REFTEST INFO | Known problems: 0 (0 known fail, 0 known asserts, 0 random, 0 skipped, 0 slow)
[task 2022-07-27T21:13:24.674Z] 21:13:24     INFO - REFTEST SUITE-END | Shutdown
[task 2022-07-27T21:13:24.675Z] 21:13:24     INFO - REFTEST INFO | Slowest test took 334ms (file:///builds/worker/workspace/build/tests/reftest/tests/gfx/tests/crashtests/1757054.html)
[task 2022-07-27T21:13:24.677Z] 21:13:24     INFO - REFTEST INFO | Total canvas count = 0
[task 2022-07-27T21:13:24.677Z] 21:13:24     INFO - [Child 1675, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-07-27T21:13:24.678Z] 21:13:24     INFO - [Child 1675, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-07-27T21:13:24.678Z] 21:13:24     INFO - [Child 1675, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-07-27T21:13:24.679Z] 21:13:24     INFO - [Child 1675, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-07-27T21:13:24.679Z] 21:13:24     INFO - [Child 1675, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-07-27T21:13:24.690Z] 21:13:24     INFO - [Child 1675, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-07-27T21:13:24.691Z] 21:13:24     INFO - [Child 1675, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-07-27T21:13:24.692Z] 21:13:24     INFO - [Child 1675, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-07-27T21:13:24.692Z] 21:13:24     INFO - [Child 1675, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-07-27T21:13:24.693Z] 21:13:24     INFO - 1658956396701	Marionette	TRACE	Received observer notification quit-application
[task 2022-07-27T21:13:24.694Z] 21:13:24     INFO - 1658956396702	Marionette	INFO	Stopped listening on port 2828
[task 2022-07-27T21:13:24.694Z] 21:13:24     INFO - 1658956396702	Marionette	DEBUG	Marionette stopped listening
[task 2022-07-27T21:13:24.695Z] 21:13:24     INFO - [Parent 1574, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:371
<...>

:gw, since you are the author of the regressor, bug 1757054, could you take a look?
For more information, please visit auto_nag documentation.

Flags: needinfo?(gwatson)

I don't think the regressor attribution is quite right here, if I'm interpreting the logs correctly.

This patch introduces a new crash test, to provide a regression test for the WR fix in this patch. However, it looks like that new crash test triggers another different assertion failure elsewhere in the firefox code - so I think this should be a separate bug?

Flags: needinfo?(gwatson) → needinfo?(mcastelluccio)

This crashtest was added in Bug 1757054 and it was later backed out for causing perma failures on 1757054.html.
Backout link: https://hg.mozilla.org/integration/autoland/rev/f9c02a16d6cad2491efc8105694dca7836cf6a03

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INVALID
Flags: needinfo?(mcastelluccio)
Status: RESOLVED → REOPENED
Component: Graphics: WebRender → Layout
Resolution: INVALID → ---
See Also: → https://bugzilla.mozilla.org/show_bug.cgi?id=1419641

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

status-firefox103: --- → unaffected
status-firefox104: --- → unaffected
status-firefox105: --- → affected
status-firefox-esr102: --- → unaffected
status-firefox-esr91: --- → unaffected

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 2 years ago → 2 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.