Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=305482748&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/GVe3iW1uR0aIESynoZqzoA/runs/0/artifacts/public/logs/live_backing.log
[task 2020-06-08T15:38:10.144Z] 15:38:10 INFO - TEST-START | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js
[task 2020-06-08T15:38:10.144Z] 15:38:10 INFO - GECKO(2023) | Chrome file doesn't exist: /Users/cltbld/tasks/task_1591629848/build/tests/mochitest/browser/gfx/layers/apz/test/mochitest/head.js
[task 2020-06-08T15:38:10.250Z] 15:38:10 INFO - GECKO(2023) | [2050, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-08T15:38:10.250Z] 15:38:10 INFO - GECKO(2023) | [2050, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-08T15:38:10.250Z] 15:38:10 INFO - GECKO(2023) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/lf/_bkv06z97sz7lng1644cky_h000017/T/tmp3p_L_Y.mozrunner/runtests_leaks_tab_pid2050.log
[task 2020-06-08T15:38:10.250Z] 15:38:10 INFO - GECKO(2023) | [2050, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-08T15:38:10.250Z] 15:38:10 INFO - GECKO(2023) | [2050, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-08T15:38:10.250Z] 15:38:10 INFO - GECKO(2023) | [2050, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp, line 243
[task 2020-06-08T15:38:10.378Z] 15:38:10 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/checkouts/gecko/layout/generic/nsFrameSelection.cpp, line 1616
[task 2020-06-08T15:38:10.784Z] 15:38:10 INFO - GECKO(2023) | [Child 2050: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x106c70400 == 1 [pid = 2050] [id = {54174913-d46b-164b-8f89-ad15cea20b8c}]
[task 2020-06-08T15:38:10.794Z] 15:38:10 INFO - GECKO(2023) | [Child 2050: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x10630b520) [pid = 2050] [serial = 1] [outer = 0x0]
[task 2020-06-08T15:38:10.794Z] 15:38:10 INFO - GECKO(2023) | [Child 2050: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x10aa52c00) [pid = 2050] [serial = 2] [outer = 0x10630b520]
[task 2020-06-08T15:38:10.925Z] 15:38:10 INFO - GECKO(2023) | [Child 2050: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x106c6fc00) [pid = 2050] [serial = 3] [outer = 0x10630b520]
[task 2020-06-08T15:38:11.455Z] 15:38:11 INFO - GECKO(2023) | WaitUntilApzStable: flushed APZ repaints in parent proc, waiting for callback...
[task 2020-06-08T15:38:11.456Z] 15:38:11 INFO - GECKO(2023) | WaitUntilApzStable: APZ flush done in parent proc
[task 2020-06-08T15:38:11.456Z] 15:38:11 INFO - GECKO(2023) | WaitUntilApzStable: got apz-flush-done in child proc
[task 2020-06-08T15:38:11.456Z] 15:38:11 INFO - GECKO(2023) | WaitUntilApzStable: done promiseFocus
[task 2020-06-08T15:38:11.456Z] 15:38:11 INFO - GECKO(2023) | WaitUntilApzStable: done promiseAllPaintsDone
[task 2020-06-08T15:38:11.456Z] 15:38:11 INFO - GECKO(2023) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2020-06-08T15:38:11.456Z] 15:38:11 INFO - GECKO(2023) | PromiseApzRepaintsFlushed: APZ flush done
[task 2020-06-08T15:38:11.458Z] 15:38:11 INFO - GECKO(2023) | WaitUntilApzStable: all done
[task 2020-06-08T15:38:11.539Z] 15:38:11 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!IsSelectionValid()', file /builds/worker/checkouts/gecko/widget/ContentCache.cpp, line 659
[task 2020-06-08T15:38:11.539Z] 15:38:11 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!aEvent.mSucceeded', file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp, line 2952
[task 2020-06-08T15:38:11.539Z] 15:38:11 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!IsSelectionValid()', file /builds/worker/checkouts/gecko/widget/ContentCache.cpp, line 659
[task 2020-06-08T15:38:11.539Z] 15:38:11 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!aEvent.mSucceeded', file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp, line 2952
[task 2020-06-08T15:38:11.539Z] 15:38:11 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!IsSelectionValid()', file /builds/worker/checkouts/gecko/widget/ContentCache.cpp, line 659
[task 2020-06-08T15:38:11.540Z] 15:38:11 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!aEvent.mSucceeded', file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp, line 2952
[task 2020-06-08T15:38:11.789Z] 15:38:11 INFO - GECKO(2023) | [2053, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-08T15:38:11.789Z] 15:38:11 INFO - GECKO(2023) | [2053, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-08T15:38:11.789Z] 15:38:11 INFO - GECKO(2023) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/lf/_bkv06z97sz7lng1644cky_h000017/T/tmp3p_L_Y.mozrunner/runtests_leaks_tab_pid2053.log
[task 2020-06-08T15:38:11.789Z] 15:38:11 INFO - GECKO(2023) | [2053, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-08T15:38:11.789Z] 15:38:11 INFO - GECKO(2023) | [2053, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp, line 202
[task 2020-06-08T15:38:11.792Z] 15:38:11 INFO - GECKO(2023) | [2053, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp, line 243
[task 2020-06-08T15:38:12.126Z] 15:38:12 INFO - GECKO(2023) | [Parent 2023: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x12a7ce800 == 6 [pid = 2023] [id = {c2d671bf-bed7-aa4b-905e-53cff593b455}] [url = about:blank]
[task 2020-06-08T15:38:12.382Z] 15:38:12 INFO - GECKO(2023) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2020-06-08T15:38:12.382Z] 15:38:12 INFO - GECKO(2023) | PromiseApzRepaintsFlushed: APZ flush done
[task 2020-06-08T15:38:12.387Z] 15:38:12 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!IsSelectionValid()', file /builds/worker/checkouts/gecko/widget/ContentCache.cpp, line 659
[task 2020-06-08T15:38:12.387Z] 15:38:12 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!aEvent.mSucceeded', file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp, line 2952
[task 2020-06-08T15:38:12.387Z] 15:38:12 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!IsSelectionValid()', file /builds/worker/checkouts/gecko/widget/ContentCache.cpp, line 659
[task 2020-06-08T15:38:12.387Z] 15:38:12 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!aEvent.mSucceeded', file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp, line 2952
[task 2020-06-08T15:38:12.388Z] 15:38:12 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!IsSelectionValid()', file /builds/worker/checkouts/gecko/widget/ContentCache.cpp, line 659
[task 2020-06-08T15:38:12.388Z] 15:38:12 INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: '!aEvent.mSucceeded', file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp, line 2952
[task 2020-06-08T15:38:12.467Z] 15:38:12 INFO - TEST-INFO | started process screencapture
[task 2020-06-08T15:38:12.584Z] 15:38:12 INFO - TEST-INFO | screencapture: exit 0
[task 2020-06-08T15:38:12.584Z] 15:38:12 INFO - Buffered messages logged at 15:38:10
[task 2020-06-08T15:38:12.587Z] 15:38:12 INFO - Entering test bound setup_pref
[task 2020-06-08T15:38:12.587Z] 15:38:12 INFO - Leaving test bound setup_pref
[task 2020-06-08T15:38:12.587Z] 15:38:12 INFO - Entering test bound
[task 2020-06-08T15:38:12.587Z] 15:38:12 INFO - Buffered messages logged at 15:38:11
[task 2020-06-08T15:38:12.588Z] 15:38:12 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://mochi.test:8888/browser/gfx/layers/apz/test/mochitest/helper_test_select_zoom.html" line: 0}]
[task 2020-06-08T15:38:12.588Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | The initial_resolution is 1, which is some sane value -
[task 2020-06-08T15:38:12.588Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | select position before zooming (x) 150 -
[task 2020-06-08T15:38:12.588Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | select position before zooming (y) 374 -
[task 2020-06-08T15:38:12.588Z] 15:38:12 INFO - Buffered messages logged at 15:38:12
[task 2020-06-08T15:38:12.590Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | The final resolution (2.2429492473602295) is greater after zooming in -
[task 2020-06-08T15:38:12.590Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | popup should have moved by more than one pixel (x) 136 150 -
[task 2020-06-08T15:38:12.590Z] 15:38:12 INFO - Buffered messages finished
[task 2020-06-08T15:38:12.590Z] 15:38:12 INFO - TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | popup should have moved by more than one pixel (y) 375 374 -
[task 2020-06-08T15:38:12.590Z] 15:38:12 INFO - Stack trace:
[task 2020-06-08T15:38:12.591Z] 15:38:12 INFO - chrome://mochikit/content/browser-test.js:test_ok:1299
[task 2020-06-08T15:38:12.591Z] 15:38:12 INFO - chrome://mochitests/content/browser/gfx/layers/apz/test/mochitest/browser_test_select_zoom.js:null:149
[task 2020-06-08T15:38:12.591Z] 15:38:12 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1064
[task 2020-06-08T15:38:12.591Z] 15:38:12 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1104
[task 2020-06-08T15:38:12.591Z] 15:38:12 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:927
[task 2020-06-08T15:38:12.591Z] 15:38:12 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:918
[task 2020-06-08T15:38:12.591Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | popup should have moved approximately the same as the element (x) -
[task 2020-06-08T15:38:12.591Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | popup should have moved approximately the same as the element (y) -
[task 2020-06-08T15:38:12.595Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | initial 150 300 79.94999694824219 19 -
[task 2020-06-08T15:38:12.595Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | final 136.408694445312 301.15330981898296 179.32378548151246 42.61603569984436 -
[task 2020-06-08T15:38:12.596Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | initial popup 150 374 101.94999694824219 56 -
[task 2020-06-08T15:38:12.596Z] 15:38:12 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | final popup 136 375 179 56 -
[task 2020-06-08T15:38:13.046Z] 15:38:13 INFO - Leaving test bound
[task 2020-06-08T15:38:13.078Z] 15:38:13 INFO - GECKO(2023) | MEMORY STAT | vsize 7733MB | residentFast 337MB | heapAllocated 116MB
[task 2020-06-08T15:38:13.078Z] 15:38:13 INFO - TEST-OK | gfx/layers/apz/test/mochitest/browser_test_select_zoom.js | took 2937ms
Description
•