1494097 - Intermittent toolkit/components/thumbnails/test/browser_thumbnails_storage.js | Test timed out -

Status: RESOLVED INCOMPLETE

(Firefox :: New Tab Page, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=201474113&repo=autoland

https://queue.taskcluster.net/v1/task/HajXyb8IT_GtmxDCb-tHeg/runs/0/artifacts/public/logs/live_backing.log

[task 2018-09-25T18:19:57.431Z] 18:19:57     INFO - TEST-START | toolkit/components/thumbnails/test/browser_thumbnails_redirect.js
[task 2018-09-25T18:19:57.777Z] 18:19:57     INFO - GECKO(10055) | MEMORY STAT | vsize 1800MB | residentFast 299MB | heapAllocated 117MB
[task 2018-09-25T18:19:57.779Z] 18:19:57     INFO - TEST-OK | toolkit/components/thumbnails/test/browser_thumbnails_redirect.js | took 343ms
[task 2018-09-25T18:19:57.800Z] 18:19:57     INFO - checking window state
[task 2018-09-25T18:19:57.818Z] 18:19:57     INFO - TEST-START | toolkit/components/thumbnails/test/browser_thumbnails_storage.js
[task 2018-09-25T18:20:42.815Z] 18:20:42     INFO - TEST-INFO | started process screentopng
[task 2018-09-25T18:20:43.218Z] 18:20:43     INFO - TEST-INFO | screentopng: exit 0
[task 2018-09-25T18:20:43.218Z] 18:20:43     INFO - Buffered messages logged at 18:19:57
[task 2018-09-25T18:20:43.218Z] 18:20:43     INFO - Console message: [JavaScript Error: "TelemetryStopwatch: requesting elapsed time for nonexisting stopwatch. Histogram: "FX_TAB_SWITCH_COMPOSITE_E10S_MS", key: "null"" {file: "resource://gre/modules/TelemetryStopwatch.jsm" line: 372}]
[task 2018-09-25T18:20:43.219Z] 18:20:43     INFO - timeElapsed@resource://gre/modules/TelemetryStopwatch.jsm:372:9
[task 2018-09-25T18:20:43.220Z] 18:20:43     INFO - timeElapsed@resource://gre/modules/TelemetryStopwatch.jsm:195:12
[task 2018-09-25T18:20:43.221Z] 18:20:43     INFO - onPaint@resource:///modules/AsyncTabSwitcher.jsm:744:18
[task 2018-09-25T18:20:43.221Z] 18:20:43     INFO - handleEvent@resource:///modules/AsyncTabSwitcher.jsm:1044:9
[task 2018-09-25T18:20:43.222Z] 18:20:43     INFO - EventListener.handleEvent*AsyncTabSwitcher@resource:///modules/AsyncTabSwitcher.jsm:140:5
[task 2018-09-25T18:20:43.223Z] 18:20:43     INFO - _getSwitcher@chrome://browser/content/tabbrowser.js:4037:24
[task 2018-09-25T18:20:43.223Z] 18:20:43     INFO - warmupTab@chrome://browser/content/tabbrowser.js:4044:7
[task 2018-09-25T18:20:43.224Z] 18:20:43     INFO - _mouseenter@chrome://browser/content/tabbrowser.xml:1980:11
[task 2018-09-25T18:20:43.225Z] 18:20:43     INFO - _setPositionalAttributes@chrome://browser/content/tabbrowser.xml:322:13
[task 2018-09-25T18:20:43.225Z] 18:20:43     INFO - addTab@chrome://browser/content/tabbrowser.js:2400:7
[task 2018-09-25T18:20:43.226Z] 18:20:43     INFO - addTab@resource://testing-common/BrowserTestUtils.jsm:1769:12
[task 2018-09-25T18:20:43.227Z] 18:20:43     INFO - addTab@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:98:36
[task 2018-09-25T18:20:43.227Z] 18:20:43     INFO - runTests@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/browser_thumbnails_redirect.js:17:9
[task 2018-09-25T18:20:43.228Z] 18:20:43     INFO - next@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:66:15
[task 2018-09-25T18:20:43.229Z] 18:20:43     INFO - run/<@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:53:9
[task 2018-09-25T18:20:43.229Z] 18:20:43     INFO - promise callback*run@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:50:5
[task 2018-09-25T18:20:43.230Z] 18:20:43     INFO - test@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:37:3
[task 2018-09-25T18:20:43.231Z] 18:20:43     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1133:9
[task 2018-09-25T18:20:43.231Z] 18:20:43     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:995:9
[task 2018-09-25T18:20:43.232Z] 18:20:43     INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
[task 2018-09-25T18:20:43.233Z] 18:20:43     INFO - 
[task 2018-09-25T18:20:43.234Z] 18:20:43     INFO - Buffered messages finished
[task 2018-09-25T18:20:43.235Z] 18:20:43     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/thumbnails/test/browser_thumbnails_storage.js | Test timed out - 
[task 2018-09-25T18:20:43.236Z] 18:20:43     INFO - GECKO(10055) | MEMORY STAT | vsize 1816MB | residentFast 293MB | heapAllocated 96MB
[task 2018-09-25T18:20:43.236Z] 18:20:43     INFO - TEST-OK | toolkit/components/thumbnails/test/browser_thumbnails_storage.js | took 45090ms
[task 2018-09-25T18:20:43.237Z] 18:20:43     INFO - checking window state
[task 2018-09-25T18:20:43.238Z] 18:20:43    ERROR - GECKO(10055) | TEST-UNEXPECTED-FAIL | unknown test url | uncaught exception - ReferenceError: PageThumbsStorageService is not defined at thumbnailFile@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:181:3
[task 2018-09-25T18:20:43.239Z] 18:20:43     INFO - GECKO(10055) | thumbnailExists@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:189:14
[task 2018-09-25T18:20:43.240Z] 18:20:43     INFO - GECKO(10055) | whenFileExists@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:225:8
[task 2018-09-25T18:20:43.241Z] 18:20:43     INFO - GECKO(10055) | callback@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:226:22
[task 2018-09-25T18:20:43.242Z] 18:20:43     INFO - GECKO(10055) | setTimeout handler*SimpleTest_setTimeoutShim@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:676:12
[task 2018-09-25T18:20:43.242Z] 18:20:43     INFO - GECKO(10055) | whenFileExists@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:229:3
[task 2018-09-25T18:20:43.243Z] 18:20:43     INFO - GECKO(10055) | callback@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:226:22
[task 2018-09-25T18:20:43.244Z] 18:20:43     INFO - GECKO(10055) | setTimeout handler*SimpleTest_setTimeoutShim@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:676:12
[task 2018-09-25T18:20:43.245Z] 18:20:43     INFO - GECKO(10055) | whenFileExists@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:229:3
[task 2018-09-25T18:20:43.246Z] 18:20:43     INFO - GECKO(10055) | callback@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:226:22
[task 2018-09-25T18:20:43.247Z] 18:20:43     INFO - GECKO(10055) | ensureDOMPromiseRejectionsProcessed@resource://testing-common/PromiseTestUtils.jsm:110:5
[task 2018-09-25T18:20:43.248Z] 18:20:43     INFO - GECKO(10055) | nextTest@chrome://mochikit/content/browser-test.js:743:7
[task 2018-09-25T18:20:43.249Z] 18:20:43     INFO - GECKO(10055) | async*timeoutFn@chrome://mochikit/content/browser-test.js:1199:9
[task 2018-09-25T18:20:43.250Z] 18:20:43     INFO - GECKO(10055) | setTimeout handler*Tester_execTest@chrome://mochikit/content/browser-test.js:1161:9
[task 2018-09-25T18:20:43.251Z] 18:20:43     INFO - GECKO(10055) | nextTest/<@chrome://mochikit/content/browser-test.js:995:9
[task 2018-09-25T18:20:43.251Z] 18:20:43     INFO - GECKO(10055) | SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
[task 2018-09-25T18:20:43.252Z] 18:20:43     INFO - GECKO(10055) | JavaScript error: chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js, line 181: ReferenceError: PageThumbsStorageService is not defined

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2018-09-24&endday=2018-09-30&tree=all

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:
* try: 1
* autoland: 1

Platform breakdown:
* linux32: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2018-10-22&endday=2018-10-28&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2018-11-19&endday=2018-11-25&tree=all

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2018-12-24&endday=2018-12-30&tree=all

Comment 5

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 6

[Dorel Luca [:dluca]]

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=225030630&repo=autoland&lineNumber=6220

INFO - TEST-START | toolkit/components/thumbnails/test/browser_thumbnails_storage.js
[task 2019-01-30T19:49:04.971Z] 19:49:04 INFO - TEST-INFO | started process screentopng
[task 2019-01-30T19:49:05.544Z] 19:49:05 INFO - TEST-INFO | screentopng: exit 0
[task 2019-01-30T19:49:05.545Z] 19:49:05 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/thumbnails/test/browser_thumbnails_storage.js | Test timed out -
[task 2019-01-30T19:49:05.550Z] 19:49:05 INFO - GECKO(10805) | MEMORY STAT | vsize 1832MB | residentFast 289MB | heapAllocated 90MB
[task 2019-01-30T19:49:05.550Z] 19:49:05 INFO - TEST-OK | toolkit/components/thumbnails/test/browser_thumbnails_storage.js | took 45066ms
[task 2019-01-30T19:49:05.550Z] 19:49:05 INFO - checking window state
[task 2019-01-30T19:49:05.551Z] 19:49:05 ERROR - GECKO(10805) | TEST-UNEXPECTED-FAIL | unknown test url | uncaught exception - ReferenceError: PageThumbsStorageService is not defined at thumbnailFile@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:181:3
[task 2019-01-30T19:49:05.551Z] 19:49:05 INFO - GECKO(10805) | thumbnailExists@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:189:14
[task 2019-01-30T19:49:05.554Z] 19:49:05 INFO - GECKO(10805) | whenFileExists@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:225:8
[task 2019-01-30T19:49:05.555Z] 19:49:05 INFO - GECKO(10805) | callback@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:226:22
[task 2019-01-30T19:49:05.555Z] 19:49:05 INFO - GECKO(10805) | setTimeout handlerSimpleTest_setTimeoutShim@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:684:12
[task 2019-01-30T19:49:05.556Z] 19:49:05 INFO - GECKO(10805) | whenFileExists@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:229:3
[task 2019-01-30T19:49:05.557Z] 19:49:05 INFO - GECKO(10805) | callback@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:226:22
[task 2019-01-30T19:49:05.557Z] 19:49:05 INFO - GECKO(10805) | setTimeout handlerSimpleTest_setTimeoutShim@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:684:12
[task 2019-01-30T19:49:05.559Z] 19:49:05 INFO - GECKO(10805) | whenFileExists@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:229:3
[task 2019-01-30T19:49:05.560Z] 19:49:05 INFO - GECKO(10805) | callback@chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js:226:22
[task 2019-01-30T19:49:05.560Z] 19:49:05 INFO - GECKO(10805) | ensureDOMPromiseRejectionsProcessed@resource://testing-common/PromiseTestUtils.jsm:110:5
[task 2019-01-30T19:49:05.561Z] 19:49:05 INFO - GECKO(10805) | nextTest@chrome://mochikit/content/browser-test.js:744:7
[task 2019-01-30T19:49:05.561Z] 19:49:05 INFO - GECKO(10805) | asynctimeoutFn@chrome://mochikit/content/browser-test.js:1202:9
[task 2019-01-30T19:49:05.562Z] 19:49:05 INFO - GECKO(10805) | setTimeout handlerTester_execTest@chrome://mochikit/content/browser-test.js:1164:9
[task 2019-01-30T19:49:05.563Z] 19:49:05 INFO - GECKO(10805) | nextTest/<@chrome://mochikit/content/browser-test.js:995:9
[task 2019-01-30T19:49:05.566Z] 19:49:05 INFO - GECKO(10805) | SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
[task 2019-01-30T19:49:05.567Z] 19:49:05 INFO - GECKO(10805) | JavaScript error: chrome://mochitests/content/browser/toolkit/components/thumbnails/test/head.js, line 181: ReferenceError: PageThumbsStorageService is not defined
[task 2019-01-30T19:49:05.568Z] 19:49:05 INFO - TEST-START | toolkit/components/thumbnails/test/browser_thumbnails_storage_migrate3.js
[task 2019-01-30T19:49:05.569Z] 19:49:05 INFO - GECKO(10805) | MEMORY STAT | vsize 1834MB | residentFast 293MB | heapAllocated 92MB
[task 2019-01-30T19:49:05.573Z] 19:49:05 INFO - TEST-OK | toolkit/components/thumbnails/test/browser_thumbnails_storage_migrate3.js | took 133ms
[task 2019-01-30T19:49:05.574Z] 19:49:05 INFO - checking window state
[task 2019-01-30T19:49:05.579Z] 19:49:05 INFO - TEST-START | toolkit/components/thumbnails/test/browser_thumbnails_update.js
[task 2019-01-30T19:49:06.565Z] 19:49:06 INFO - GECKO(10805) | MEMORY STAT | vsize 1836MB | residentFast 309MB | heapAllocated 109MB
[task 2019-01-30T19:49:06.566Z] 19:49:06 INFO - TEST-OK | toolkit/components/thumbnails/test/browser_thumbnails_update.js | took 1260ms
[task 2019-01-30T19:49:06.586Z] 19:49:06 INFO - checking window state
[task 2019-01-30T19:49:08.095Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 11174
[task 2019-01-30T19:49:08.136Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 11197
[task 2019-01-30T19:49:08.137Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 11058
[task 2019-01-30T19:49:08.159Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 11080
[task 2019-01-30T19:49:08.175Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 11147
[task 2019-01-30T19:49:08.176Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 11103
[task 2019-01-30T19:49:08.196Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 10965
[task 2019-01-30T19:49:08.206Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 10914
[task 2019-01-30T19:49:08.207Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 10896
[task 2019-01-30T19:49:08.248Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 11000
[task 2019-01-30T19:49:08.535Z] 19:49:08 INFO - GECKO(10805) | Completed ShutdownLeaks collections in process 10805
[task 2019-01-30T19:49:08.540Z] 19:49:08 INFO - TEST-START | Shutdown
[task 2019-01-30T19:49:08.542Z] 19:49:08 INFO - Browser Chrome Test Summary
[task 2019-01-30T19:49:08.544Z] 19:49:08 INFO - Passed: 164
[task 2019-01-30T19:49:08.546Z] 19:49:08 INFO - Failed: 1
[task 2019-01-30T19:49:08.547Z] 19:49:08 INFO - Todo: 0
[task 2019-01-30T19:49:08.549Z] 19:49:08 INFO - Mode: e10s
[task 2019-01-30T19:49:08.551Z] 19:49:08 INFO - *** End BrowserChrome Test Results ***
[task 2019-01-30T19:49:08.804Z] 19:49:08 INFO - GECKO(10805) | [Parent 10805, Gecko_IOThread] WARNING: pipe error (78): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 357
[task 2019-01-30T19:49:09.043Z] 19:49:09 INFO - GECKO(10805) | 1548877749030 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2019-01-30T19:49:09.052Z] 19:49:09 INFO - GECKO(10805) | 1548877749030 Marionette INFO Stopped listening on port 2828
[task 2019-01-30T19:49:09.054Z] 19:49:09 INFO - GECKO(10805) | 1548877749031 Marionette DEBUG Remote service is inactive
[task 2019-01-30T19:49:09.415Z] 19:49:09 INFO - TEST-INFO | Main app process: exit 0
[task 2019-01-30T19:49:09.415Z] 19:49:09 INFO - runtests.py | Application ran for: 0:02:35.656925
[task 2019-01-30T19:49:09.415Z] 19:49:09 INFO - zombiecheck | Reading PID log: /tmp/tmpEOl7iSpidlog
[task 2019-01-30T19:49:09.416Z] 19:49:09 INFO - ==> process 10805 launched child process 10830
[task 2019-01-30T19:49:09.418Z] 19:49:09 INFO - ==> process 10805 launched child process 10896
[task 2019-01-30T19:49:09.419Z] 19:49:09 INFO - ==> process 10805 launched child process 10914
[task 2019-01-30T19:49:09.420Z] 19:49:09 INFO - ==> process 10805 launched child process 10965
[task 2019-01-30T19:49:09.421Z] 19:49:09 INFO - ==> process 10805 launched child process 11000
[task 2019-01-30T19:49:09.422Z] 19:49:09 INFO - ==> process 10805 launched child process 11015
[task 2019-01-30T19:49:09.426Z] 19:49:09 INFO - ==> process 10805 launched child process 11058
[task 2019-01-30T19:49:09.426Z] 19:49:09 INFO - ==> process 10805 launched child process 11080
[task 2019-01-30T19:49:09.426Z] 19:49:09 INFO - ==> process 10805 launched child process 11103
[task 2019-01-30T19:49:09.426Z] 19:49:09 INFO - ==> process 10805 launched child process 11124
[task 2019-01-30T19:49:09.427Z] 19:49:09 INFO - ==> process 10805 launched child process 11145
[task 2019-01-30T19:49:09.427Z] 19:49:09 INFO - ==> process 10805 launched child process 11147
[task 2019-01-30T19:49:09.427Z] 19:49:09 INFO - ==> process 10805 launched child process 11174
[task 2019-01-30T19:49:09.427Z] 19:49:09 INFO - ==> process 10805 launched child process 11195
[task 2019-01-30T19:49:09.429Z] 19:49:09 INFO - ==> process 10805 launched child process 11197
[task 2019-01-30T19:49:09.431Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 10914
[task 2019-01-30T19:49:09.432Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11174
[task 2019-01-30T19:49:09.438Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11015
[task 2019-01-30T19:49:09.438Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11080
[task 2019-01-30T19:49:09.438Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11145
[task 2019-01-30T19:49:09.438Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11147
[task 2019-01-30T19:49:09.440Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 10830
[task 2019-01-30T19:49:09.441Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 10896
[task 2019-01-30T19:49:09.442Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11058
[task 2019-01-30T19:49:09.443Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11124
[task 2019-01-30T19:49:09.445Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 10965
[task 2019-01-30T19:49:09.446Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11000
[task 2019-01-30T19:49:09.447Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11195
[task 2019-01-30T19:49:09.447Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11197
[task 2019-01-30T19:49:09.448Z] 19:49:09 INFO - zombiecheck | Checking for orphan process with PID: 11103
[task 2019-01-30T19:49:09.448Z] 19:49:09 INFO - Stopping web server
[task 2019-01-30T19:49:09.449Z] 19:49:09 INFO - Stopping web socket server
[task 2019-01-30T19:49:09.456Z] 19:49:09 INFO - Stopping ssltunnel
[task 2019-01-30T19:49:09.493Z] 19:49:09 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2019-01-30T19:49:09.494Z] 19:49:09 INFO - runtests.py | Running tests: end.
[task 2019-01-30T19:49:09.720Z] 19:49:09 INFO - Buffered messages finished
[task 2019-01-30T19:49:09.722Z] 19:49:09 INFO - Running manifest: toolkit/components/windowcreator/test/browser.ini
[task 2019-01-30T19:49:09.723Z] 19:49:09 INFO - The following extra prefs will be set:
[task 2019-01-30T19:49:09.724Z] 19:49:09 INFO - dom.animations-api.core.enabled=true
[task 2019-01-30T19:49:09.724Z] 19:49:09 INFO - dom.animations-api.timelines.enabled=true
[task 2019-01-30T19:49:09.761Z] 19:49:09 INFO - Setting pipeline to PAUSED ...
[task 2019-01-30T19:49:09.762Z] 19:49:09 INFO - Pipeline is PREROLLING ...
[task 2019-01-30T19:49:09.762Z] 19:49:09 INFO - Pipeline is PREROLLED ...
[task 2019-01-30T19:49:09.763Z] 19:49:09 INFO - Setting pipeline to PLAYING ...
[task 2019-01-30T19:49:09.768Z] 19:49:09 INFO - New clock: GstSystemClock
[task 2019-01-30T19:49:09.793Z] 19:49:09 INFO - Got EOS from element "pipeline0".
[task 2019-01-30T19:49:09.795Z] 19:49:09 INFO - Execution ended after 0:00:00.033106738
[task 2019-01-30T19:49:09.798Z] 19:49:09 INFO - Setting pipeline to PAUSED ...
[task 2019-01-30T19:49:09.800Z] 19:49:09 INFO - Setting pipeline to READY ...
[task 2019-01-30T19:49:09.803Z] 19:49:09 INFO - (gst-launch-1.0:11283): GStreamer-CRITICAL *: gst_object_unref: assertion '((GObject ) object)->ref_count > 0' failed
[task 2019-01-30T19:49:09.805Z] 19:49:09 INFO - Setting pipeline to NULL ...
[task 2019-01-30T19:49:09.807Z] 19:49:09 INFO - Freeing pipeline ...
[task 2019-01-30T19:49:09.934Z] 19:49:09 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2019-01-30T19:49:10.125Z] 19:49:10 INFO - MochitestServer : launching [u'/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpHf9OlN.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2019-01-30T19:49:10.126Z] 19:49:10 INFO - runtests.py | Server pid: 11305
[task 2019-01-30T19:49:10.147Z] 19:49:10 INFO - runtests.py | Websocket server pid: 11308
[task 2019-01-30T19:49:10.171Z] 19:49:10 INFO - runtests.py | SSL tunnel pid: 11311
[task 2019-01-30T19:49:10.325Z] 19:49:10 INFO - runtests.py | Running with scheme: http
[task 2019-01-30T19:49:10.327Z] 19:49:10 INFO - runtests.py | Running with e10s: True
[task 2019-01-30T19:49:10.327Z] 19:49:10 INFO - runtests.py | Running with serviceworker_e10s: False
[task 2019-01-30T19:49:10.327Z] 19:49:10 INFO - runtests.py | Running tests: start.
[task 2019-01-30T19:49:10.327Z] 19:49:10 INFO -
[task 2019-01-30T19:49:10.350Z] 19:49:10 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpHf9OlN.mozrunner
[task 2019-01-30T19:49:10.368Z] 19:49:10 INFO - runtests.py | Application pid: 11332
[task 2019-01-30T19:49:10.368Z] 19:49:10 INFO - TEST-INFO | started process GECKO(11332)
[task 2019-01-30T19:49:11.136Z] 19:49:11 INFO - GECKO(11332) | 1548877751123 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: mozillaAddons
[task 2019-01-30T19:49:11.136Z] 19:49:11 INFO - GECKO(11332) | 1548877751124 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2019-01-30T19:49:11.137Z] 19:49:11 INFO - GECKO(11332) | 1548877751124 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: about:reader
[task 2019-01-30T19:49:11.314Z] 19:49:11 INFO - GECKO(11332) | 1548877751311 Marionette TRACE Received observer notification profile-after-change
[task 2019-01-30T19:49:11.371Z] 19:49:11 INFO - GECKO(11332) | 1548877751363 Marionette TRACE Received observer notification command-line-startup
[task 2019-01-30T19:49:11.377Z] 19:49:11 INFO - GECKO(11332) | 1548877751363 Marionette TRACE Received observer notification nsPref:changed
[task 2019-01-30T19:49:11.384Z] 19:49:11 INFO - GECKO(11332) | 1548877751363 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false)
[task 2019-01-30T19:49:14.653Z] 19:49:14 INFO - GECKO(11332) | 1548877754647 Marionette TRACE Received observer notification toplevel-window-ready
[task 2019-01-30T19:49:16.773Z] 19:49:16 INFO - GECKO(11332) | 1548877756765 Marionette TRACE Received observer notification sessionstore-windows-restored
[task 2019-01-30T19:49:16.775Z] 19:49:16 INFO - GECKO(11332) | 1548877756765 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2019-01-30T19:49:17.115Z] 19:49:17 INFO - GECKO(11332) | 1548877757109 Marionette TRACE All scripts recorded.
[task 2019-01-30T19:49:17.236Z] 19:49:17 INFO - GECKO(11332) | 1548877757207 Marionette INFO Listening on port 2828
[task 2019-01-30T19:49:17.236Z] 19:49:17 INFO - GECKO(11332) | 1548877757208 Marionette DEBUG Remote service is active
[task 2019-01-30T19:49:17.306Z] 19:49:17 INFO - GECKO(11332) | 1548877757298 Marionette DEBUG Accepted connection 0 from 127.0.0.1:39864
[task 2019-01-30T19:49:17.306Z] 19:49:17 INFO - GECKO(11332) | 1548877757301 Marionette DEBUG Closed connection 0
[task 2019-01-30T19:49:17.307Z] 19:49:17 INFO - GECKO(11332) | 1548877757301 Marionette DEBUG Accepted connection 1 from 127.0.0.1:39866
[task 2019-01-30T19:49:17.315Z] 19:49:17 INFO - GECKO(11332) | 1548877757309 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2019-01-30T19:49:17.414Z] 19:49:17 INFO - GECKO(11332) | 1548877757410 Marionette TRACE [4294967297] Frame script loaded
[task 2019-01-30T19:49:17.431Z] 19:49:17 INFO - GECKO(11332) | 1548877757421 Marionette TRACE [4294967297] Frame script registered
[task 2019-01-30T19:49:17.447Z] 19:49:17 INFO - GECKO(11332) | 1548877757441 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"465f6e11-00ec-4123-b789-65430b4779af","capabilities":{"browserName":"firefox","browserVersion":"67.0a ... mp/tmpHf9OlN.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2019-01-30T19:49:17.509Z] 19:49:17 INFO - GECKO(11332) | 1548877757501 Marionette DEBUG 1 -> [0,2,"Addon:Install",{"path":"/tmp/tmpQ1BUW_.zip","temporary":false}]
[task 2019-01-30T19:49:17.680Z] 19:49:17 INFO - GECKO(11332) | 1548877757672 Marionette DEBUG 1 <- [1,2,null,{"value":"[e-mail]"}]
[task 2019-01-30T19:49:17.723Z] 19:49:17 INFO - GECKO(11332) | 1548877757720 Marionette DEBUG 1 -> [0,3,"Addon:Install",{"path":"/tmp/tmp2t43ML.zip","temporary":false}]
[task 2019-01-30T19:49:17.789Z] 19:49:17 INFO - GECKO(11332) | 1548877757785 Marionette DEBUG 1 <- [1,3,null,{"value":"[e-mail]"}]
[task 2019-01-30T19:49:17.796Z] 19:49:17 INFO - GECKO(11332) | 1548877757790 Marionette DEBUG 1 -> [0,4,"Marionette:GetContext",{}]
[task 2019-01-30T19:49:17.802Z] 19:49:17 INFO - GECKO(11332) | 1548877757790 Marionette DEBUG 1 <- [1,4,null,{"value":"content"}]
[task 2019-01-30T19:49:17.807Z] 19:49:17 INFO - GECKO(11332) | 1548877757794 Marionette DEBUG 1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-01-30T19:49:17.813Z] 19:49:17 INFO - GECKO(11332) | 1548877757796 Marionette DEBUG 1 <- [1,5,null,{"value":null}]
[task 2019-01-30T19:49:17.819Z] 19:49:17 INFO - GECKO(11332) | 1548877757801 Marionette DEBUG 1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/ This Source Code Form is subject to the terms of the Mozilla Public\n * License, ... testUrl":"about:blank","flavor":"browser-chrome"}],"filename":"tests/mochitest/runtests.py","sandbox":"default","line":1712}]
[task 2019-01-30T19:49:17.839Z] 19:49:17 INFO - GECKO(11332) | 1548877757832 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2019-01-30T19:49:17.880Z] 19:49:17 INFO - GECKO(11332) | 1548877757875 Marionette DEBUG 1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2019-01-30T19:49:17.886Z] 19:49:17 INFO - GECKO(11332) | 1548877757876 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2019-01-30T19:49:17.890Z] 19:49:17 INFO - GECKO(11332) | 1548877757884 Marionette DEBUG 1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2019-01-30T19:49:17.898Z] 19:49:17 INFO - runtests.py | Waiting for browser...
[task 2019-01-30T19:49:17.899Z] 19:49:17 INFO - GECKO(11332) | 1548877757887 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2019-01-30T19:49:17.902Z] 19:49:17 INFO - GECKO(11332) | 1548877757898 Marionette DEBUG Closed connection 1
[task 2019-01-30T19:49:18.004Z] 19:49:18 INFO - *** Start BrowserChrome Test Results ***
[task 2019-01-30T19:49:18.040Z] 19:49:18 INFO - checking window state
[task 2019-01-30T19:49:18.166Z] 19:49:18 INFO - TEST-START | toolkit/components/windowcreator/test/browser_bug1204626.js
[task 2019-01-30T19:49:22.448Z] 19:49:22 INFO - GECKO(11332) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2019-01-30T19:49:22.449Z] 19:49:22 INFO - GECKO(11332) | MEMORY STAT | vsize 1785MB | residentFast 347MB | heapAllocated 130MB
[task 2019-01-30T19:49:22.451Z] 19:49:22 INFO - TEST-OK | toolkit/components/windowcreator/test/browser_bug1204626.js | took 4283ms

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2019-01-28&endday=2019-02-03&tree=all

Comment 8

[Noemi Erli[:noemi_erli]]

Recent log failure: https://treeherder.mozilla.org/logviewer.html#?job_id=226301335&repo=autoland

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2019-02-04&endday=2019-02-10&tree=all

Comment 10

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2019-02-11&endday=2019-02-17&tree=all

Comment 11

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 12

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-release: 1

Platform breakdown:

• linux32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2019-03-11&endday=2019-03-17&tree=all

Comment 13

[Narcis Beleuzu [:NarcisB]]

Fail reappeared on autoland.
Log link: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=245125115&repo=autoland&lineNumber=18568

Comment 14

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2019-05-06&endday=2019-05-12&tree=all

Comment 15

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 16

[Cosmin Sabou [:CosminS]]

https://treeherder.mozilla.org/logviewer.html#?job_id=250264433&repo=autoland

Comment 17

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1494097&startday=2019-06-03&endday=2019-06-09&tree=all

Comment 18

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup