Closed Bug 1664730 Opened 5 years ago Closed 3 years ago

Intermittent toolkit/content/tests/mochitest/test_mousecapture.xhtml | selection scroll position after timer is at least 140

Categories

(Core :: DOM: UI Events & Focus Handling, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1777052

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disabled][retriggered][stockwell unknown])

Attachments

(3 files)

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


[task 2020-09-14T00:49:21.144Z] 00:49:21 INFO - TEST-START | toolkit/content/tests/mochitest/test_mousecapture.xhtml
[task 2020-09-14T00:49:21.292Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/base/nsContentUtils.cpp, line 3779
[task 2020-09-14T00:49:21.691Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] ###!!! ASSERTION: Unexpected document: 'aCapturingContent->OwnerDoc() == GetDocument()', file /builds/worker/checkouts/gecko/layout/base/PresShell.cpp, line 7799
[task 2020-09-14T00:49:21.691Z] 00:49:21 INFO - GECKO(2465) | #01: mozilla::PresShell::EventHandler::HandleEventUsingCoordinates(nsIFrame*, mozilla::WidgetGUIEvent*, nsEventStatus*, bool) [layout/base/PresShell.cpp:6946]
[task 2020-09-14T00:49:21.693Z] 00:49:21 INFO - GECKO(2465) | #02: mozilla::PresShell::EventHandler::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6880]
[task 2020-09-14T00:49:21.693Z] 00:49:21 INFO - GECKO(2465) | #03: mozilla::PresShell::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6805]
[task 2020-09-14T00:49:21.694Z] 00:49:21 INFO - GECKO(2465) | #04: nsViewManager::DispatchEvent(mozilla::WidgetGUIEvent*, nsView*, nsEventStatus*) [view/nsViewManager.cpp:749]
[task 2020-09-14T00:49:21.694Z] 00:49:21 INFO - GECKO(2465) | #05: nsView::HandleEvent(mozilla::WidgetGUIEvent*, bool) [view/nsView.cpp:1134]
[task 2020-09-14T00:49:21.694Z] 00:49:21 INFO - GECKO(2465) | #06: mozilla::widget::PuppetWidget::DispatchEvent(mozilla::WidgetGUIEvent*, nsEventStatus&) [widget/PuppetWidget.cpp:381]
[task 2020-09-14T00:49:21.694Z] 00:49:21 INFO - GECKO(2465) | #07: nsContentUtils::SendMouseEvent(mozilla::PresShell*, nsTSubstring<char16_t> const&, float, float, int, int, int, int, bool, float, unsigned short, unsigned int, bool, bool*, bool, bool) [dom/base/nsContentUtils.cpp:7918]
[task 2020-09-14T00:49:21.700Z] 00:49:21 INFO - GECKO(2465) | #08: nsDOMWindowUtils::SendMouseEvent(nsTSubstring<char16_t> const&, float, float, int, int, int, bool, float, unsigned short, bool, bool, int, unsigned int, unsigned char, bool*) [dom/base/nsDOMWindowUtils.cpp:652]
[task 2020-09-14T00:49:21.701Z] 00:49:21 INFO - GECKO(2465) | #09: NS_InvokeByIndex [/Users/cltbld/tasks/task_1600039967/build/application/Firefox NightlyDebug.app/Contents/MacOS/XUL + 0x1cc97e]
[task 2020-09-14T00:49:21.701Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] ###!!! ASSERTION: Unexpected document: 'capturingContent->OwnerDoc() == GetDocument()', file /builds/worker/checkouts/gecko/layout/base/PresShell.cpp, line 7020
[task 2020-09-14T00:49:21.701Z] 00:49:21 INFO - GECKO(2465) | #01: mozilla::PresShell::EventHandler::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6880]
[task 2020-09-14T00:49:21.701Z] 00:49:21 INFO - GECKO(2465) | #02: mozilla::PresShell::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6805]
[task 2020-09-14T00:49:21.701Z] 00:49:21 INFO - GECKO(2465) | #03: nsViewManager::DispatchEvent(mozilla::WidgetGUIEvent*, nsView*, nsEventStatus*) [view/nsViewManager.cpp:749]
[task 2020-09-14T00:49:21.702Z] 00:49:21 INFO - GECKO(2465) | #04: nsView::HandleEvent(mozilla::WidgetGUIEvent*, bool) [view/nsView.cpp:1134]
[task 2020-09-14T00:49:21.702Z] 00:49:21 INFO - GECKO(2465) | #05: mozilla::widget::PuppetWidget::DispatchEvent(mozilla::WidgetGUIEvent*, nsEventStatus&) [widget/PuppetWidget.cpp:381]
[task 2020-09-14T00:49:21.702Z] 00:49:21 INFO - GECKO(2465) | #06: nsContentUtils::SendMouseEvent(mozilla::PresShell*, nsTSubstring<char16_t> const&, float, float, int, int, int, int, bool, float, unsigned short, unsigned int, bool, bool*, bool, bool) [dom/base/nsContentUtils.cpp:7918]
[task 2020-09-14T00:49:21.702Z] 00:49:21 INFO - GECKO(2465) | #07: nsDOMWindowUtils::SendMouseEvent(nsTSubstring<char16_t> const&, float, float, int, int, int, bool, float, unsigned short, bool, bool, int, unsigned int, unsigned char, bool*) [dom/base/nsDOMWindowUtils.cpp:652]
[task 2020-09-14T00:49:21.702Z] 00:49:21 INFO - GECKO(2465) | #08: NS_InvokeByIndex [/Users/cltbld/tasks/task_1600039967/build/application/Firefox NightlyDebug.app/Contents/MacOS/XUL + 0x1cc97e]
[task 2020-09-14T00:49:21.703Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] ###!!! ASSERTION: Unexpected document: 'aCapturingContent->OwnerDoc() == GetDocument()', file /builds/worker/checkouts/gecko/layout/base/PresShell.cpp, line 7799
[task 2020-09-14T00:49:21.703Z] 00:49:21 INFO - GECKO(2465) | #01: mozilla::PresShell::EventHandler::HandleEventUsingCoordinates(nsIFrame*, mozilla::WidgetGUIEvent*, nsEventStatus*, bool) [layout/base/PresShell.cpp:6946]
[task 2020-09-14T00:49:21.703Z] 00:49:21 INFO - GECKO(2465) | #02: mozilla::PresShell::EventHandler::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6880]
[task 2020-09-14T00:49:21.704Z] 00:49:21 INFO - GECKO(2465) | #03: mozilla::PresShell::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6805]
[task 2020-09-14T00:49:21.705Z] 00:49:21 INFO - GECKO(2465) | #04: nsViewManager::DispatchEvent(mozilla::WidgetGUIEvent*, nsView*, nsEventStatus*) [view/nsViewManager.cpp:749]
[task 2020-09-14T00:49:21.705Z] 00:49:21 INFO - GECKO(2465) | #05: nsView::HandleEvent(mozilla::WidgetGUIEvent*, bool) [view/nsView.cpp:1134]
[task 2020-09-14T00:49:21.705Z] 00:49:21 INFO - GECKO(2465) | #06: mozilla::widget::PuppetWidget::DispatchEvent(mozilla::WidgetGUIEvent*, nsEventStatus&) [widget/PuppetWidget.cpp:381]
[task 2020-09-14T00:49:21.705Z] 00:49:21 INFO - GECKO(2465) | #07: nsContentUtils::SendMouseEvent(mozilla::PresShell*, nsTSubstring<char16_t> const&, float, float, int, int, int, int, bool, float, unsigned short, unsigned int, bool, bool*, bool, bool) [dom/base/nsContentUtils.cpp:7918]
[task 2020-09-14T00:49:21.706Z] 00:49:21 INFO - GECKO(2465) | #08: nsDOMWindowUtils::SendMouseEvent(nsTSubstring<char16_t> const&, float, float, int, int, int, bool, float, unsigned short, bool, bool, int, unsigned int, unsigned char, bool*) [dom/base/nsDOMWindowUtils.cpp:652]
[task 2020-09-14T00:49:21.706Z] 00:49:21 INFO - GECKO(2465) | #09: NS_InvokeByIndex [/Users/cltbld/tasks/task_1600039967/build/application/Firefox NightlyDebug.app/Contents/MacOS/XUL + 0x1cc97e]
[task 2020-09-14T00:49:21.706Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] ###!!! ASSERTION: Unexpected document: 'capturingContent->OwnerDoc() == GetDocument()', file /builds/worker/checkouts/gecko/layout/base/PresShell.cpp, line 7020
[task 2020-09-14T00:49:21.706Z] 00:49:21 INFO - GECKO(2465) | #01: mozilla::PresShell::EventHandler::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6880]
[task 2020-09-14T00:49:21.707Z] 00:49:21 INFO - GECKO(2465) | #02: mozilla::PresShell::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6805]
[task 2020-09-14T00:49:21.708Z] 00:49:21 INFO - GECKO(2465) | #03: nsViewManager::DispatchEvent(mozilla::WidgetGUIEvent*, nsView*, nsEventStatus*) [view/nsViewManager.cpp:749]
[task 2020-09-14T00:49:21.708Z] 00:49:21 INFO - GECKO(2465) | #04: nsView::HandleEvent(mozilla::WidgetGUIEvent*, bool) [view/nsView.cpp:1134]
[task 2020-09-14T00:49:21.708Z] 00:49:21 INFO - GECKO(2465) | #05: mozilla::widget::PuppetWidget::DispatchEvent(mozilla::WidgetGUIEvent*, nsEventStatus&) [widget/PuppetWidget.cpp:381]
[task 2020-09-14T00:49:21.708Z] 00:49:21 INFO - GECKO(2465) | #06: nsContentUtils::SendMouseEvent(mozilla::PresShell*, nsTSubstring<char16_t> const&, float, float, int, int, int, int, bool, float, unsigned short, unsigned int, bool, bool*, bool, bool) [dom/base/nsContentUtils.cpp:7918]
[task 2020-09-14T00:49:21.711Z] 00:49:21 INFO - GECKO(2465) | #07: nsDOMWindowUtils::SendMouseEvent(nsTSubstring<char16_t> const&, float, float, int, int, int, bool, float, unsigned short, bool, bool, int, unsigned int, unsigned char, bool*) [dom/base/nsDOMWindowUtils.cpp:652]
[task 2020-09-14T00:49:21.711Z] 00:49:21 INFO - GECKO(2465) | #08: NS_InvokeByIndex [/Users/cltbld/tasks/task_1600039967/build/application/Firefox NightlyDebug.app/Contents/MacOS/XUL + 0x1cc97e]
[task 2020-09-14T00:49:21.836Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/checkouts/gecko/layout/generic/nsFrameSelection.cpp, line 1598
[task 2020-09-14T00:49:21.836Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: 'selection.mReply.mContentsRoot != mRootContent', file /builds/worker/checkouts/gecko/dom/events/IMEContentObserver.cpp, line 1314
[task 2020-09-14T00:49:21.836Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: 'aEvent->mReply.mContentsRoot != mRootContent', file /builds/worker/checkouts/gecko/dom/events/IMEContentObserver.cpp, line 707
[task 2020-09-14T00:49:21.836Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: '!queryText.mSucceeded', file /builds/worker/checkouts/gecko/widget/ContentCache.cpp, line 236
[task 2020-09-14T00:49:21.836Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: '!CacheText(aWidget, aNotification)', file /builds/worker/checkouts/gecko/widget/ContentCache.cpp, line 123
[task 2020-09-14T00:49:21.836Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: '!mContentCache.CacheAll(this, &aIMENotification)', file /builds/worker/checkouts/gecko/widget/PuppetWidget.cpp, line 755
[task 2020-09-14T00:49:21.836Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] ###!!! ASSERTION: Unexpected document: 'aCapturingContent->OwnerDoc() == GetDocument()', file /builds/worker/checkouts/gecko/layout/base/PresShell.cpp, line 7799
[task 2020-09-14T00:49:21.837Z] 00:49:21 INFO - GECKO(2465) | #01: mozilla::PresShell::EventHandler::HandleEventUsingCoordinates(nsIFrame*, mozilla::WidgetGUIEvent*, nsEventStatus*, bool) [layout/base/PresShell.cpp:6946]
[task 2020-09-14T00:49:21.837Z] 00:49:21 INFO - GECKO(2465) | #02: mozilla::PresShell::EventHandler::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6880]
[task 2020-09-14T00:49:21.837Z] 00:49:21 INFO - GECKO(2465) | #03: mozilla::PresShell::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6805]
[task 2020-09-14T00:49:21.837Z] 00:49:21 INFO - GECKO(2465) | #04: nsViewManager::DispatchEvent(mozilla::WidgetGUIEvent*, nsView*, nsEventStatus*) [view/nsViewManager.cpp:749]
[task 2020-09-14T00:49:21.837Z] 00:49:21 INFO - GECKO(2465) | #05: nsView::HandleEvent(mozilla::WidgetGUIEvent*, bool) [view/nsView.cpp:1134]
[task 2020-09-14T00:49:21.837Z] 00:49:21 INFO - GECKO(2465) | #06: mozilla::widget::PuppetWidget::DispatchEvent(mozilla::WidgetGUIEvent*, nsEventStatus&) [widget/PuppetWidget.cpp:381]
[task 2020-09-14T00:49:21.837Z] 00:49:21 INFO - GECKO(2465) | #07: nsContentUtils::SendMouseEvent(mozilla::PresShell*, nsTSubstring<char16_t> const&, float, float, int, int, int, int, bool, float, unsigned short, unsigned int, bool, bool*, bool, bool) [dom/base/nsContentUtils.cpp:7918]
[task 2020-09-14T00:49:21.837Z] 00:49:21 INFO - GECKO(2465) | #08: nsDOMWindowUtils::SendMouseEvent(nsTSubstring<char16_t> const&, float, float, int, int, int, bool, float, unsigned short, bool, bool, int, unsigned int, unsigned char, bool*) [dom/base/nsDOMWindowUtils.cpp:652]
[task 2020-09-14T00:49:21.838Z] 00:49:21 INFO - GECKO(2465) | #09: NS_InvokeByIndex [/Users/cltbld/tasks/task_1600039967/build/application/Firefox NightlyDebug.app/Contents/MacOS/XUL + 0x1cc97e]
[task 2020-09-14T00:49:21.838Z] 00:49:21 INFO - GECKO(2465) | [Child 2467, Main Thread] ###!!! ASSERTION: Unexpected document: 'capturingContent->OwnerDoc() == GetDocument()', file /builds/worker/checkouts/gecko/layout/base/PresShell.cpp, line 7020
[task 2020-09-14T00:49:21.838Z] 00:49:21 INFO - GECKO(2465) | #01: mozilla::PresShell::EventHandler::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6880]
[task 2020-09-14T00:49:21.838Z] 00:49:21 INFO - GECKO(2465) | #02: mozilla::PresShell::HandleEvent(nsIFrame*, mozilla::WidgetGUIEvent*, bool, nsEventStatus*) [layout/base/PresShell.cpp:6805]
[task 2020-09-14T00:49:21.838Z] 00:49:21 INFO - GECKO(2465) | #03: nsViewManager::DispatchEvent(mozilla::WidgetGUIEvent*, nsView*, nsEventStatus*) [view/nsViewManager.cpp:749]
[task 2020-09-14T00:49:21.838Z] 00:49:21 INFO - GECKO(2465) | #04: nsView::HandleEvent(mozilla::WidgetGUIEvent*, bool) [view/nsView.cpp:1134]
[task 2020-09-14T00:49:21.838Z] 00:49:21 INFO - GECKO(2465) | #05: mozilla::widget::PuppetWidget::DispatchEvent(mozilla::WidgetGUIEvent*, nsEventStatus&) [widget/PuppetWidget.cpp:381]
[task 2020-09-14T00:49:21.838Z] 00:49:21 INFO - GECKO(2465) | #06: nsContentUtils::SendMouseEvent(mozilla::PresShell*, nsTSubstring<char16_t> const&, float, float, int, int, int, int, bool, float, unsigned short, unsigned int, bool, bool*, bool, bool) [dom/base/nsContentUtils.cpp:7918]
[task 2020-09-14T00:49:21.838Z] 00:49:21 INFO - GECKO(2465) | #07: nsDOMWindowUtils::SendMouseEvent(nsTSubstring<char16_t> const&, float, float, int, int, int, bool, float, unsigned short, bool, bool, int, unsigned int, unsigned char, bool*) [dom/base/nsDOMWindowUtils.cpp:652]
[task 2020-09-14T00:49:21.839Z] 00:49:21 INFO - GECKO(2465) | #08: NS_InvokeByIndex [/Users/cltbld/tasks/task_1600039967/build/application/Firefox NightlyDebug.app/Contents/MacOS/XUL + 0x1cc97e]
[task 2020-09-14T00:49:22.569Z] 00:49:22 INFO - GECKO(2465) | [Child 2468, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp, line 8515
[task 2020-09-14T00:49:22.569Z] 00:49:22 INFO - GECKO(2465) | [Child 2468, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp, line 8515
[task 2020-09-14T00:49:22.569Z] 00:49:22 INFO - GECKO(2465) | [Child 2468, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp, line 8515
[task 2020-09-14T00:49:22.569Z] 00:49:22 INFO - GECKO(2465) | [Child 2468, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp, line 8515
[task 2020-09-14T00:49:22.569Z] 00:49:22 INFO - GECKO(2465) | [Child 2468, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp, line 8515
[task 2020-09-14T00:49:22.569Z] 00:49:22 INFO - GECKO(2465) | [Child 2468, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp, line 8515
[task 2020-09-14T00:49:23.084Z] 00:49:23 INFO - TEST-INFO | started process screencapture
[task 2020-09-14T00:49:23.243Z] 00:49:23 INFO - TEST-INFO | screencapture: exit 0
[task 2020-09-14T00:49:23.243Z] 00:49:23 INFO - Buffered messages logged at 00:49:21
[task 2020-09-14T00:49:23.243Z] 00:49:23 INFO - must wait for load
[task 2020-09-14T00:49:23.244Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter target for point 112,20
[task 2020-09-14T00:49:23.244Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (2)
[task 2020-09-14T00:49:23.244Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter target for point 137,43
[task 2020-09-14T00:49:23.244Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (25)
[task 2020-09-14T00:49:23.244Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter target for point 4137,4018
[task 2020-09-14T00:49:23.245Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (4000)
[task 2020-09-14T00:49:23.245Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter target for point 198,6
[task 2020-09-14T00:49:23.245Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (-12)
[task 2020-09-14T00:49:23.245Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 2,2
[task 2020-09-14T00:49:23.245Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (0)
[task 2020-09-14T00:49:23.245Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom target for point 12,29
[task 2020-09-14T00:49:23.246Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom target for point 35,52
[task 2020-09-14T00:49:23.246Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom target for point 4010,4027
[task 2020-09-14T00:49:23.246Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom target for point -2,15
[task 2020-09-14T00:49:23.246Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 2,2
[task 2020-09-14T00:49:23.246Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture and releaseCapture mousemove event target
[task 2020-09-14T00:49:23.246Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture and releaseCapture mousemove event fired
[task 2020-09-14T00:49:23.247Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture fails on non mousedown mousemove event target
[task 2020-09-14T00:49:23.247Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture fails on non mousedown mousemove event fired
[task 2020-09-14T00:49:23.247Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | document.releaseCapture releases capture mousemove event target
[task 2020-09-14T00:49:23.247Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | document.releaseCapture releases capture mousemove event fired
[task 2020-09-14T00:49:23.247Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture releases capture mousemove event target
[task 2020-09-14T00:49:23.248Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture releases capture mousemove event fired
[task 2020-09-14T00:49:23.248Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture during mousemove before releaseCapture mousemove event target
[task 2020-09-14T00:49:23.248Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture during mousemove before releaseCapture mousemove event fired
[task 2020-09-14T00:49:23.248Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture during mousemove after releaseCapture mousemove event target
[task 2020-09-14T00:49:23.248Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture during mousemove after releaseCapture mousemove event fired
[task 2020-09-14T00:49:23.248Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5spacer target for point 12,69
[task 2020-09-14T00:49:23.249Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5inner target for point 35,92
[task 2020-09-14T00:49:23.249Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point 4010,4067
[task 2020-09-14T00:49:23.249Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point -2,55
[task 2020-09-14T00:49:23.249Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 2,2
[task 2020-09-14T00:49:23.249Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point 12,69
[task 2020-09-14T00:49:23.249Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point 35,92
[task 2020-09-14T00:49:23.250Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point 4010,4067
[task 2020-09-14T00:49:23.250Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point -2,55
[task 2020-09-14T00:49:23.250Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 2,2
[task 2020-09-14T00:49:23.250Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture only works on elements in documents mousemove event target
[task 2020-09-14T00:49:23.250Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture only works on elements in documents mousemove event fired
[task 2020-09-14T00:49:23.250Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture works on images mousemove event target
[task 2020-09-14T00:49:23.250Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture works on images mousemove event fired
[task 2020-09-14T00:49:23.251Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture on body retargets to root node mousemove event target
[task 2020-09-14T00:49:23.251Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture on body retargets to root node mousemove event fired
[task 2020-09-14T00:49:23.251Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 52,52
[task 2020-09-14T00:49:23.251Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (2), new width 49, expected 49
[task 2020-09-14T00:49:23.251Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 75,75
[task 2020-09-14T00:49:23.252Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (25), new width 72, expected 72
[task 2020-09-14T00:49:23.252Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 4050,4050
[task 2020-09-14T00:49:23.252Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (4000), new width 92, expected 92
[task 2020-09-14T00:49:23.252Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 38,38
[task 2020-09-14T00:49:23.252Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (-12), new width 35, expected 35
[task 2020-09-14T00:49:23.252Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (0), new width 35, expected 35
[task 2020-09-14T00:49:23.253Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | scroll select
[task 2020-09-14T00:49:23.253Z] 00:49:23 INFO - must wait for load
[task 2020-09-14T00:49:23.253Z] 00:49:23 INFO - Buffered messages logged at 00:49:23
[task 2020-09-14T00:49:23.253Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | text is selected
[task 2020-09-14T00:49:23.253Z] 00:49:23 INFO - Scrolled 120 pixels
[task 2020-09-14T00:49:23.253Z] 00:49:23 INFO - Buffered messages finished
[task 2020-09-14T00:49:23.254Z] 00:49:23 INFO - TEST-UNEXPECTED-FAIL | toolkit/content/tests/mochitest/test_mousecapture.xhtml | selection scroll position after timer is at least 140
[task 2020-09-14T00:49:23.254Z] 00:49:23 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-09-14T00:49:23.254Z] 00:49:23 INFO - selectionScrollDone@toolkit/content/tests/mochitest/test_mousecapture.xhtml:87:7
[task 2020-09-14T00:49:23.254Z] 00:49:23 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | selection scroll position after timer is multiple of 20
[task 2020-09-14T00:49:23.254Z] 00:49:23 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp, line 348
[task 2020-09-14T00:49:23.254Z] 00:49:23 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp, line 348
[task 2020-09-14T00:49:23.256Z] 00:49:23 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp, line 348
[task 2020-09-14T00:49:23.306Z] 00:49:23 INFO - GECKO(2465) | [Parent 2465, Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp, line 4272
[task 2020-09-14T00:49:23.650Z] 00:49:23 INFO - GECKO(2465) | [Parent 2465, Main Thread] WARNING: NS_ENSURE_TRUE(presShell) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp, line 4270
[task 2020-09-14T00:49:23.752Z] 00:49:23 INFO - must wait for load
[task 2020-09-14T00:49:23.752Z] 00:49:23 INFO - must wait for focus
[task 2020-09-14T00:49:24.612Z] 00:49:24 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | text is selected
[task 2020-09-14T00:49:24.613Z] 00:49:24 INFO - Scrolled 140 pixels
[task 2020-09-14T00:49:24.613Z] 00:49:24 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | selection scroll position after timer is at least 140
[task 2020-09-14T00:49:24.613Z] 00:49:24 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | selection scroll position after timer is multiple of 20
[task 2020-09-14T00:49:24.620Z] 00:49:24 INFO - GECKO(2465) | MEMORY STAT | vsize 6679MB | residentFast 160MB | heapAllocated 19MB
[task 2020-09-14T00:49:24.621Z] 00:49:24 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp, line 348
[task 2020-09-14T00:49:24.622Z] 00:49:24 INFO - GECKO(2465) | [Child 2467, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp, line 348
[task 2020-09-14T00:49:24.723Z] 00:49:24 INFO - TEST-OK | toolkit/content/tests/mochitest/test_mousecapture.xhtml | took 3577ms
[task 2020-09-14T00:49:24.785Z] 00:49:24 INFO - TEST-KNOWN-FAIL | toolkit/content/tests/mochitest/test_mousecapture.xhtml | assertion count 6 matches expected 6 to 12 assertions
[task 2020-09-14T00:49:24.786Z] 00:49:24 INFO - TEST-START | Shutdown
[task 2020-09-14T00:49:24.786Z] 00:49:24 INFO - Passed: 60
[task 2020-09-14T00:49:24.786Z] 00:49:24 INFO - Failed: 1
[task 2020-09-14T00:49:24.786Z] 00:49:24 INFO - Todo: 0
[task 2020-09-14T00:49:24.786Z] 00:49:24 INFO - Mode: e10s
[task 2020-09-14T00:49:24.786Z] 00:49:24 INFO - Slowest: 3577ms - /tests/toolkit/content/tests/mochitest/test_mousecapture.xhtml

Jens, could you redirect this to someone to take a look? It only fails on macosx1014-64-qr debug and has:

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=324392926&repo=autoland
Should we temporarily disable the test on that platform until a fix is in place?

Flags: needinfo?(jstutte)

Hi Edgar, can you please take a look?

Flags: needinfo?(jstutte) → needinfo?(echen)
Whiteboard: [stockwell needswork:owner][retriggered]
Assignee: nobody → apavel
Status: NEW → ASSIGNED
Pushed by apavel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/b96ff0fec882 disable test_mousecapture.xhtml on osx-qr debug r=aryx DONTBUILD

Edgar, please re-enable the test once there is a fix, if you're working on this. thank you.

Keywords: leave-open
Whiteboard: [stockwell needswork:owner][retriggered] → [stockwell disabled][retriggered]
Pushed by jmaher@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/8bbb5a2628de update disabling conditions for test_mousecapture.xhtml r=intermittent-reviewers,jmaher

There are 24 total failures in the last 7 days on

  • linux1804-64-asan opt
  • windows7-32 opt and debug

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=329280498&repo=autoland&lineNumber=8170

[task 2021-02-08T23:57:25.583Z] 23:57:25 INFO - TEST-START | toolkit/content/tests/mochitest/test_mousecapture.xhtml
[task 2021-02-08T23:57:26.329Z] 23:57:26 INFO - TEST-INFO | started process screenshot
[task 2021-02-08T23:57:26.411Z] 23:57:26 INFO - TEST-INFO | screenshot: exit 0
[task 2021-02-08T23:57:26.411Z] 23:57:26 INFO - Buffered messages logged at 23:57:25
[task 2021-02-08T23:57:26.411Z] 23:57:26 INFO - must wait for load
[task 2021-02-08T23:57:26.411Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter target for point 112,21
[task 2021-02-08T23:57:26.412Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (2)
[task 2021-02-08T23:57:26.412Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter target for point 137,44
[task 2021-02-08T23:57:26.412Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (25)
[task 2021-02-08T23:57:26.412Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter target for point 4137,4019
[task 2021-02-08T23:57:26.413Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (4000)
[task 2021-02-08T23:57:26.413Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter target for point 198,7
[task 2021-02-08T23:57:26.413Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (-12)
[task 2021-02-08T23:57:26.413Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 2,2
[task 2021-02-08T23:57:26.413Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | splitter left box size (0)
[task 2021-02-08T23:57:26.414Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom target for point 12,26
[task 2021-02-08T23:57:26.414Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom target for point 35,49
[task 2021-02-08T23:57:26.414Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom target for point 4010,4024
[task 2021-02-08T23:57:26.414Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom target for point -2,12
[task 2021-02-08T23:57:26.415Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 2,2
[task 2021-02-08T23:57:26.415Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture and releaseCapture mousemove event target
[task 2021-02-08T23:57:26.415Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture and releaseCapture mousemove event fired
[task 2021-02-08T23:57:26.415Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture fails on non mousedown mousemove event target
[task 2021-02-08T23:57:26.415Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture fails on non mousedown mousemove event fired
[task 2021-02-08T23:57:26.416Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | document.releaseCapture releases capture mousemove event target
[task 2021-02-08T23:57:26.416Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | document.releaseCapture releases capture mousemove event fired
[task 2021-02-08T23:57:26.416Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture releases capture mousemove event target
[task 2021-02-08T23:57:26.416Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture releases capture mousemove event fired
[task 2021-02-08T23:57:26.417Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture during mousemove before releaseCapture mousemove event target
[task 2021-02-08T23:57:26.419Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture during mousemove before releaseCapture mousemove event fired
[task 2021-02-08T23:57:26.419Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture during mousemove after releaseCapture mousemove event target
[task 2021-02-08T23:57:26.419Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | element.releaseCapture during mousemove after releaseCapture mousemove event fired
[task 2021-02-08T23:57:26.420Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5spacer target for point 12,66
[task 2021-02-08T23:57:26.420Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5inner target for point 35,89
[task 2021-02-08T23:57:26.420Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point 4010,4064
[task 2021-02-08T23:57:26.420Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point -2,52
[task 2021-02-08T23:57:26.420Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 2,2
[task 2021-02-08T23:57:26.421Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point 12,66
[task 2021-02-08T23:57:26.421Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point 35,89
[task 2021-02-08T23:57:26.421Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point 4010,4064
[task 2021-02-08T23:57:26.421Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | custom5 target for point -2,52
[task 2021-02-08T23:57:26.422Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 2,2
[task 2021-02-08T23:57:26.422Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture only works on elements in documents mousemove event target
[task 2021-02-08T23:57:26.422Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture only works on elements in documents mousemove event fired
[task 2021-02-08T23:57:26.422Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture works on images mousemove event target
[task 2021-02-08T23:57:26.422Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture works on images mousemove event fired
[task 2021-02-08T23:57:26.423Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture on body retargets to root node mousemove event target
[task 2021-02-08T23:57:26.423Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | setCapture on body retargets to root node mousemove event fired
[task 2021-02-08T23:57:26.423Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 52,52
[task 2021-02-08T23:57:26.424Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (2), new width 49, expected 49
[task 2021-02-08T23:57:26.424Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 75,75
[task 2021-02-08T23:57:26.424Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (25), new width 72, expected 72
[task 2021-02-08T23:57:26.425Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 4050,4050
[task 2021-02-08T23:57:26.425Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (4000), new width 92, expected 92
[task 2021-02-08T23:57:26.425Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | target for point 38,38
[task 2021-02-08T23:57:26.425Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (-12), new width 35, expected 35
[task 2021-02-08T23:57:26.425Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | frameset after drag (0), new width 35, expected 35
[task 2021-02-08T23:57:26.426Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | scroll select
[task 2021-02-08T23:57:26.426Z] 23:57:26 INFO - must wait for load
[task 2021-02-08T23:57:26.426Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | text is selected
[task 2021-02-08T23:57:26.426Z] 23:57:26 INFO - Scrolled 140 pixels
[task 2021-02-08T23:57:26.427Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | selection scroll position after timer is at least 140
[task 2021-02-08T23:57:26.427Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | selection scroll position after timer is multiple of 20
[task 2021-02-08T23:57:26.427Z] 23:57:26 INFO - Buffered messages logged at 23:57:26
[task 2021-02-08T23:57:26.427Z] 23:57:26 INFO - must wait for load
[task 2021-02-08T23:57:26.427Z] 23:57:26 INFO - must wait for focus
[task 2021-02-08T23:57:26.428Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | text is selected
[task 2021-02-08T23:57:26.428Z] 23:57:26 INFO - Scrolled 120 pixels
[task 2021-02-08T23:57:26.428Z] 23:57:26 INFO - Buffered messages finished
[task 2021-02-08T23:57:26.428Z] 23:57:26 INFO - TEST-UNEXPECTED-FAIL | toolkit/content/tests/mochitest/test_mousecapture.xhtml | selection scroll position after timer is at least 140
[task 2021-02-08T23:57:26.428Z] 23:57:26 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2021-02-08T23:57:26.429Z] 23:57:26 INFO - selectionScrollDone@toolkit/content/tests/mochitest/test_mousecapture.xhtml:87:7
[task 2021-02-08T23:57:26.429Z] 23:57:26 INFO - TEST-PASS | toolkit/content/tests/mochitest/test_mousecapture.xhtml | selection scroll position after timer is multiple of 20
[task 2021-02-08T23:57:26.429Z] 23:57:26 INFO - GECKO(4472) | MEMORY STAT | vsize 2103771MB | vsizeMaxContiguous 65607973MB | residentFast 75MB | heapAllocated 13MB
[task 2021-02-08T23:57:26.429Z] 23:57:26 INFO - TEST-OK | toolkit/content/tests/mochitest/test_mousecapture.xhtml | took 787ms
[task 2021-02-08T23:57:26.429Z] 23:57:26 INFO - TEST-START | Shutdown

Hi Jens, test is disabled on mac-qr debug and linux64 debug and opt. Can you take a look?

Assignee: apavel → nobody
Status: ASSIGNED → NEW
Flags: needinfo?(echen) → needinfo?(jstutte)
Whiteboard: [stockwell disabled][retriggered] → [stockwell disabled][retriggered][stockwell needswork:owner]

Hi Edgar, mousecapture sounds like you could know if this is actionable?

Flags: needinfo?(jstutte) → needinfo?(echen)

Update what I found so far,

  • Test wait for 6 scroll events and expect 20 pixels scrolled in each scroll event. When an intermittent failure occurs, scrolling doesn't happen in one scroll event.
  • It seems like AutoScroller::DoAutoScroll doesn't run for some reason.

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

AutoScroller::DoAutoScroll does run and also schedule next AutoScroll. We usually dispatch one scroll event between scheduled AutoScroll, when an intermittent failure occurs, there are two scroll events dispatched between scheduled AutoScroll, that is why we would see the scrolling doesn't happen between these two scroll events.

When an intermittent failure occurs, there is an additional scroll event from reflow, it happens between two AutoScroll.

#01: mozilla::ScrollFrameHelper::ScrollToImpl(nsPoint, nsRect const&, mozilla::ScrollOrigin) [layout/generic/nsGfxScrollFrame.cpp:3136]
#02: mozilla::ScrollFrameHelper::CompleteAsyncScroll(nsRect const&, mozilla::ScrollOrigin) [layout/generic/nsGfxScrollFrame.cpp:2321]
#03: mozilla::ScrollFrameHelper::ScrollToWithOrigin(nsPoint, mozilla::ScrollMode, mozilla::ScrollOrigin, nsRect const*, nsIScrollbarMediator::ScrollSnapMode) [layout/generic/nsGfxScrollFrame.cpp:2433]
#04: mozilla::ScrollFrameHelper::ScrollToRestoredPosition() [layout/generic/nsGfxScrollFrame.cpp:5034]
#05: mozilla::ScrollFrameHelper::ReflowFinished() [layout/generic/nsGfxScrollFrame.cpp:6398]
#06: mozilla::PresShell::HandlePostedReflowCallbacks(bool) [layout/base/PresShell.cpp:4007]
#07: mozilla::PresShell::DidDoReflow(bool) [layout/base/PresShell.cpp:9446]
#08: mozilla::PresShell::ProcessReflowCommands(bool) [layout/base/PresShell.cpp:9845]
#09: mozilla::PresShell::DoFlushPendingNotifications(mozilla::ChangesToFlush) [layout/base/PresShell.cpp:4252]
#10: nsRefreshDriver::Tick(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [layout/base/nsRefreshDriver.cpp:2240]
#11: mozilla::RefreshDriverTimer::TickRefreshDrivers(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp, nsTArray<RefPtr<nsRefreshDriver> >&) [layout/base/nsRefreshDriver.cpp:336]
#12: mozilla::RefreshDriverTimer::Tick(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [layout/base/nsRefreshDriver.cpp:353]
#13: mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::TickRefreshDriver(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [layout/base/nsRefreshDriver.cpp:724]
#14: mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::NotifyParentProcessVsync() [layout/base/nsRefreshDriver.cpp:625]
#15: mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::NotifyVsync(mozilla::VsyncEvent const&) [layout/base/nsRefreshDriver.cpp:545]
#16: mozilla::dom::VsyncChild::RecvNotify(mozilla::VsyncEvent const&, float const&) [dom/ipc/VsyncChild.cpp:67]

:botond, do you know if this is expected behavior, i.e. reflow might trigger scroll event from ScrollToRestoredPosition, even if scroll position isn't changed? Thanks!

Flags: needinfo?(echen) → needinfo?(botond)

It is expected that a reflow will trigger a call to ScrollToImpl via ScrollToRestoredPosition. The reason for this is that the reflow might change the scroll frame's scroll range, and the scroll position needs to be re-clamped to the new scroll range. (For example, if the document became shorter, and the scroll position was close to the end, the scroll position may decrease to remain within bounds.)

However, in the common case where the re-clamping does not actually result in a change to the scroll position, this early exit from ScrollToImpl should be taken, and the code to send a scroll event (later in that function) should not be reached.

Note that the comparison governing this early exit is done in app units aligned to layer pixels; sometimes, rounding issues can cause a small discrepancy and therefore a scroll event even when the scroll range didn't materially change (not sure if that's the case here).

Flags: needinfo?(botond)

(In reply to Botond Ballo [:botond] from comment #40)

However, in the common case where the re-clamping does not actually result in a change to the scroll position, this early exit from ScrollToImpl should be taken, and the code to send a scroll event (later in that function) should not be reached.

The curPos get from GetScrollPosition() is (0, 0) in reflow case, it looks suspicious.

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

(In reply to Botond Ballo [:botond] from comment #40)

However, in the common case where the re-clamping does not actually result in a change to the scroll position, this early exit from ScrollToImpl should be taken, and the code to send a scroll event (later in that function) should not be reached.

The curPos get from GetScrollPosition() is (0, 0) in reflow case, it looks suspicious.

So the early exit isn't taken, because the curPos get from GetScrollPosition() is (0, 0).
I tried to figure out why the scroll position is reset to (0, 0) and where it is from, but no luck.

Botond, do you have any idea why the scroll position is reset to (0,0)? Or is any possible place that causes scroll position to reset to (0, 0)? Thanks!

Flags: needinfo?(botond)

I realized I was slightly confused about something in my last comment.

The re-clamping of the scroll offset to the new scroll range is done using this direct call to ScrollToImpl() from ReflowFinished().

The purpose of the call to ScrollToRestoredPosition() a few lines earlier is to restore the frame's scroll position to a remembered value. This can happen after a frame reconstruction, or to scroll to a position remembered from the session store after a reload or such.

So, if you're seeing an extra scroll from ScrollToRestoredPosition() where the curPos is (0,0), I think the most likely explanation is that something triggered a reconstruction of the scroll frame (also called a "reframe"), and this call is setting the scroll position of the new frame to the value remembered from the old frame. (The (0,0) is likely the initial scroll position of the new frame upon construction.)

Flags: needinfo?(botond)

I think what's probably behind this is an "extra" reflow triggered by the async font fallback mechanism, which may have been kicked off by another testcase that ran just before this one.

I'm inclined to think that we should probably disable the async fallback while running mochitests, as we've seen it disrupt a variety of tests that are dependent on a particular expected sequence of events, and the async nature of the mechanism makes it impossible to accurately predict or control when an extra reflow may happen. We've tried turning the pref off for a few specific directories, but that's not entirely reliable if the fallback search may have already been triggered by something else before we apply that pref, so doing it globally in the test harness will solve this more reliably.

Pushed by jkew@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/c6ba3d142fb2 Disable async font fallback when running mochitests, to avoid unpredictable extra reflows that can disrupt event-/timing-sensitive tests. r=botond

There have been a total of 37 failures in the past 7 days on:

• macosx1014-64-qr debug

Recent failure log

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

Attachment

General

Created:
Updated:
Size: