Closed Bug 1447142 Opened 6 years ago Closed 6 years ago

Intermittent toolkit/components/reader/test/browser_readerMode_readingTime.js | Test timed out -

Categories

(Toolkit :: Reader Mode, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: btara [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=168947866&repo=mozilla-inbound

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

[task 2018-03-19T15:39:11.533Z] 15:39:11     INFO - Entering test bound 
[task 2018-03-19T15:39:11.535Z] 15:39:11     INFO - Console message: [JavaScript Error: "Not a string"]
[task 2018-03-19T15:39:11.539Z] 15:39:11     INFO - Console message: [JavaScript Error: "NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIMessageSender.sendAsyncMessage]" {file: "resource:///modules/ContentMetaHandler.jsm" line: 155}]
[task 2018-03-19T15:39:11.541Z] 15:39:11     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://example.com/browser/toolkit/components/reader/test/readerModeArticleShort.html" line: 0}]
[task 2018-03-19T15:39:11.543Z] 15:39:11     INFO - Console message: [JavaScript Error: "NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIMessageSender.sendAsyncMessage]" {file: "resource:///modules/ContentMetaHandler.jsm" line: 155}]
[task 2018-03-19T15:39:11.546Z] 15:39:11     INFO - Buffered messages logged at 15:38:27
[task 2018-03-19T15:39:11.548Z] 15:39:11     INFO - Console message: [JavaScript Error: "Error requesting favicon URL for about:reader content: favicon not found for uri" {file: "resource:///modules/ReaderParent.jsm" line: 33}]
[task 2018-03-19T15:39:11.549Z] 15:39:11     INFO - onRejection@resource:///modules/ReaderParent.jsm:33:13
[task 2018-03-19T15:39:11.550Z] 15:39:11     INFO - promise callback*receiveMessage@resource:///modules/ReaderParent.jsm:26:11
[task 2018-03-19T15:39:11.551Z] 15:39:11     INFO - receiveMessage@jar:file:///builds/worker/workspace/build/application/firefox/browser/omni.ja!/components/nsBrowserGlue.js:247:15
[task 2018-03-19T15:39:11.554Z] 15:39:11     INFO - 
[task 2018-03-19T15:39:11.556Z] 15:39:11     INFO - Console message: [JavaScript Error: "Not a string"]
[task 2018-03-19T15:39:11.557Z] 15:39:11     INFO - Console message: [JavaScript Error: "Not a string"]
[task 2018-03-19T15:39:11.559Z] 15:39:11     INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_readingTime.js | Reading time element should be in document - {} == true - 
[task 2018-03-19T15:39:11.560Z] 15:39:11     INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_readingTime.js | Reading time should be '1 minute' - "1 minute" == "1 minute" - 
[task 2018-03-19T15:39:11.562Z] 15:39:11     INFO - Leaving test bound 
[task 2018-03-19T15:39:11.563Z] 15:39:11     INFO - Entering test bound 
[task 2018-03-19T15:39:11.565Z] 15:39:11     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at self (“default-src”). Source: 
[task 2018-03-19T15:39:11.566Z] 15:39:11     INFO -             @keyframes grow {
[task 2018-03-19T15:39:11.567Z] 15:39:11     INFO -          ...." {file: "about:reader?url=http%3A%2F%2Fexample.com%2Fbrowser%2Ftoolkit%2Fcomponents%2Freader%2Ftest%2FreaderModeArticleShort.html" line: 1 column: 0 source: "
[task 2018-03-19T15:39:11.573Z] 15:39:11     INFO -             @keyframes grow {
[task 2018-03-19T15:39:11.575Z] 15:39:11     INFO -          ..."}]
[task 2018-03-19T15:39:11.576Z] 15:39:11     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://example.com/browser/toolkit/components/reader/test/readerModeArticleMedium.html" line: 0}]
[task 2018-03-19T15:39:11.578Z] 15:39:11     INFO - Console message: [JavaScript Error: "remote browser crashed while on http://example.com/browser/toolkit/components/reader/test/readerModeArticleMedium.html
[task 2018-03-19T15:39:11.579Z] 15:39:11     INFO - " {file: "chrome://mochikit/content/mochitest-e10s-utils.js" line: 8}]
[task 2018-03-19T15:39:11.580Z] 15:39:11     INFO - e10s_init/<@chrome://mochikit/content/mochitest-e10s-utils.js:8:5
[task 2018-03-19T15:39:11.582Z] 15:39:11     INFO - EventListener.handleEvent*e10s_init@chrome://mochikit/content/mochitest-e10s-utils.js:6:3
[task 2018-03-19T15:39:11.583Z] 15:39:11     INFO - testInit@chrome://mochikit/content/browser-test.js:102:5
[task 2018-03-19T15:39:11.584Z] 15:39:11     INFO - setTimeout handler*@chrome://mochikit/content/browser-test.js:26:3
[task 2018-03-19T15:39:11.585Z] 15:39:11     INFO - 
[task 2018-03-19T15:39:11.588Z] 15:39:11     INFO - Console message: [JavaScript Error: "NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIMessageSender.sendAsyncMessage]" {file: "resource:///modules/ContentMetaHandler.jsm" line: 155}]
[task 2018-03-19T15:39:11.589Z] 15:39:11     INFO - Buffered messages finished
[task 2018-03-19T15:39:11.591Z] 15:39:11     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/reader/test/browser_readerMode_readingTime.js | Test timed out - 
[task 2018-03-19T15:39:11.593Z] 15:39:11     INFO - GECKO(5911) | MEMORY STAT | vsize 2169MB | residentFast 286MB | heapAllocated 97MB
[task 2018-03-19T15:39:11.594Z] 15:39:11     INFO - TEST-OK | toolkit/components/reader/test/browser_readerMode_readingTime.js | took 45066ms
[task 2018-03-19T15:39:11.596Z] 15:39:11     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-03-19T15:39:11.601Z] 15:39:11     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/reader/test/browser_readerMode_readingTime.js | Found a tab after previous test timed out: http://example.com/browser/toolkit/components/reader/test/readerModeArticleMedium.html - 
[task 2018-03-19T15:39:11.602Z] 15:39:11     INFO - checking window state
[task 2018-03-19T15:39:11.605Z] 15:39:11     INFO - TEST-START | toolkit/components/reader/test/browser_readerMode_with_anchor.js
[task 2018-03-19T15:39:12.292Z] 15:39:12     INFO - GECKO(5911) | JavaScript error: resource:///modules/ContentMetaHandler.jsm, line 155: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIMessageSender.sendAsyncMessage]
[task 2018-03-19T15:39:12.723Z] 15:39:12     INFO - GECKO(5911) | MEMORY STAT | vsize 2175MB | residentFast 280MB | heapAllocated 91MB
[task 2018-03-19T15:39:12.723Z] 15:39:12     INFO - TEST-OK | toolkit/components/reader/test/browser_readerMode_with_anchor.js | took 1682ms
[task 2018-03-19T15:39:12.759Z] 15:39:12     INFO - checking window state
[task 2018-03-19T15:39:13.162Z] 15:39:13     INFO - GECKO(5911) | JavaScript error: resource:///modules/ContentMetaHandler.jsm, line 155: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIMessageSender.sendAsyncMessage]
[task 2018-03-19T15:39:13.564Z] 15:39:13     INFO - Console message: [JavaScript Error: "NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIMessageSender.sendAsyncMessage]" {file: "resource:///modules/ContentMetaHandler.jsm" line: 155}]
[task 2018-03-19T15:39:14.408Z] 15:39:14     INFO - GECKO(5911) | Completed ShutdownLeaks collections in process 5963
[task 2018-03-19T15:39:14.409Z] 15:39:14     INFO - GECKO(5911) | Completed ShutdownLeaks collections in process 6097
[task 2018-03-19T15:39:14.469Z] 15:39:14     INFO - GECKO(5911) | Completed ShutdownLeaks collections in process 6036
[task 2018-03-19T15:39:14.470Z] 15:39:14     INFO - GECKO(5911) | Completed ShutdownLeaks collections in process 6010
[task 2018-03-19T15:39:14.732Z] 15:39:14     INFO - GECKO(5911) | Completed ShutdownLeaks collections in process 5911
[task 2018-03-19T15:39:14.732Z] 15:39:14     INFO - TEST-START | Shutdown
[task 2018-03-19T15:39:14.733Z] 15:39:14     INFO - Browser Chrome Test Summary
[task 2018-03-19T15:39:14.734Z] 15:39:14     INFO - Passed:  52
[task 2018-03-19T15:39:14.736Z] 15:39:14     INFO - Failed:  2
[task 2018-03-19T15:39:14.739Z] 15:39:14     INFO - Todo:    0
[task 2018-03-19T15:39:14.740Z] 15:39:14     INFO - Mode:    e10s
[task 2018-03-19T15:39:14.742Z] 15:39:14     INFO - *** End BrowserChrome Test Results ***
[task 2018-03-19T15:39:15.071Z] 15:39:15     INFO - GECKO(5911) | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
[task 2018-03-19T15:39:15.108Z] 15:39:15     INFO - GECKO(5911) | 1521473955099	Marionette	DEBUG	Received observer notification xpcom-will-shutdown
[task 2018-03-19T15:39:15.108Z] 15:39:15     INFO - GECKO(5911) | 1521473955099	Marionette	DEBUG	New connections will no longer be accepted
[task 2018-03-19T15:39:15.432Z] 15:39:15     INFO - TEST-INFO | Main app process: exit 0
[task 2018-03-19T15:39:15.433Z] 15:39:15     INFO - runtests.py | Application ran for: 0:00:58.437468
[task 2018-03-19T15:39:15.434Z] 15:39:15     INFO - zombiecheck | Reading PID log: /tmp/tmpcLBdK3pidlog
[task 2018-03-19T15:39:15.435Z] 15:39:15     INFO - ==> process 5911 launched child process 5934
[task 2018-03-19T15:39:15.436Z] 15:39:15     INFO - ==> process 5911 launched child process 5963
[task 2018-03-19T15:39:15.437Z] 15:39:15     INFO - ==> process 5911 launched child process 6010
[task 2018-03-19T15:39:15.438Z] 15:39:15     INFO - ==> process 5911 launched child process 6036
[task 2018-03-19T15:39:15.439Z] 15:39:15     INFO - ==> process 5911 launched child process 6063
[task 2018-03-19T15:39:15.450Z] 15:39:15     INFO - ==> process 5911 launched child process 6093
[task 2018-03-19T15:39:15.451Z] 15:39:15     INFO - ==> process 5911 launched child process 6097
[task 2018-03-19T15:39:15.452Z] 15:39:15     INFO - zombiecheck | Checking for orphan process with PID: 5963
[task 2018-03-19T15:39:15.452Z] 15:39:15     INFO - zombiecheck | Checking for orphan process with PID: 6093
[task 2018-03-19T15:39:15.453Z] 15:39:15     INFO - zombiecheck | Checking for orphan process with PID: 5934
[task 2018-03-19T15:39:15.454Z] 15:39:15     INFO - zombiecheck | Checking for orphan process with PID: 6063
[task 2018-03-19T15:39:15.455Z] 15:39:15     INFO - zombiecheck | Checking for orphan process with PID: 6097
[task 2018-03-19T15:39:15.456Z] 15:39:15     INFO - zombiecheck | Checking for orphan process with PID: 6036
[task 2018-03-19T15:39:15.456Z] 15:39:15     INFO - zombiecheck | Checking for orphan process with PID: 6010
[task 2018-03-19T15:39:15.457Z] 15:39:15     INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/dtzqWGPcTPO4oxPzkvKtaQ/artifacts/public/build/target.crashreporter-symbols.zip
[task 2018-03-19T15:39:22.072Z] 15:39:22     INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpwp3wr9.mozrunner/minidumps/7ea95a61-b6d5-1923-0a48-9f3ce4050560.dmp /tmp/tmprsOreC
[task 2018-03-19T15:39:30.098Z] 15:39:30     INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/7ea95a61-b6d5-1923-0a48-9f3ce4050560.dmp
[task 2018-03-19T15:39:30.099Z] 15:39:30     INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/7ea95a61-b6d5-1923-0a48-9f3ce4050560.extra
[task 2018-03-19T15:39:30.170Z] 15:39:30     INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ 0x3d80ab384570]
[task 2018-03-19T15:39:30.171Z] 15:39:30     INFO - Crash dump filename: /tmp/tmpwp3wr9.mozrunner/minidumps/7ea95a61-b6d5-1923-0a48-9f3ce4050560.dmp
[task 2018-03-19T15:39:30.171Z] 15:39:30     INFO - Operating system: Linux
[task 2018-03-19T15:39:30.171Z] 15:39:30     INFO -                   0.0.0 Linux 4.4.0-1014-aws #14taskcluster-Ubuntu SMP Mon Feb 19 11:31:26 UTC 2018 x86_64
[task 2018-03-19T15:39:30.171Z] 15:39:30     INFO - CPU: amd64
[task 2018-03-19T15:39:30.171Z] 15:39:30     INFO -      family 6 model 62 stepping 4
[task 2018-03-19T15:39:30.172Z] 15:39:30     INFO -      2 CPUs
[task 2018-03-19T15:39:30.172Z] 15:39:30     INFO - 
[task 2018-03-19T15:39:30.173Z] 15:39:30     INFO - GPU: UNKNOWN
[task 2018-03-19T15:39:30.173Z] 15:39:30     INFO - 
[task 2018-03-19T15:39:30.173Z] 15:39:30     INFO - Crash reason:  SIGSEGV
[task 2018-03-19T15:39:30.174Z] 15:39:30     INFO - Crash address: 0x3d80ab384570
[task 2018-03-19T15:39:30.174Z] 15:39:30     INFO - Process uptime: not available
[task 2018-03-19T15:39:30.174Z] 15:39:30     INFO - 
[task 2018-03-19T15:39:30.175Z] 15:39:30     INFO - Thread 19 (crashed)
[task 2018-03-19T15:39:30.176Z] 15:39:30     INFO -  0  0x3d80ab384570
[task 2018-03-19T15:39:30.176Z] 15:39:30     INFO -     rax = 0x00003d80ab384570   rdx = 0x0000000000002842
[task 2018-03-19T15:39:30.177Z] 15:39:30     INFO -     rcx = 0x0000000000000002   rbx = 0xfffe7f1f32d10880
[task 2018-03-19T15:39:30.178Z] 15:39:30     INFO -     rsi = 0x00007f1f331fa218   rdi = 0x00007f1f31b911e0
[task 2018-03-19T15:39:30.178Z] 15:39:30     INFO -     rbp = 0x00007f1f331fa1d8   rsp = 0x00007f1f331fa1a0
[task 2018-03-19T15:39:30.179Z] 15:39:30     INFO -      r8 = 0x00007f1f33a9b000    r9 = 0x00007f1f33a4d800
[task 2018-03-19T15:39:30.179Z] 15:39:30     INFO -     r10 = 0x0000000000000000   r11 = 0x0000000000005821
[task 2018-03-19T15:39:30.180Z] 15:39:30     INFO -     r12 = 0x0000000000000008   r13 = 0x00007f1f331fab98
[task 2018-03-19T15:39:30.180Z] 15:39:30     INFO -     r14 = 0x0000000000000002   r15 = 0x00007f1f331faac0
[task 2018-03-19T15:39:30.181Z] 15:39:30     INFO -     rip = 0x00003d80ab384570
[task 2018-03-19T15:39:30.181Z] 15:39:30     INFO -     Found by: given as instruction pointer in context
[task 2018-03-19T15:39:30.182Z] 15:39:30     INFO -  1  0x7f1f31b911e0
[task 2018-03-19T15:39:30.182Z] 15:39:30     INFO -     rbp = 0x00007f1f331fa248   rsp = 0x00007f1f331fa1e8
[task 2018-03-19T15:39:30.182Z] 15:39:30     INFO -     rip = 0x00007f1f31b911e0
[task 2018-03-19T15:39:30.183Z] 15:39:30     INFO -     Found by: previous frame's frame pointer
[task 2018-03-19T15:39:30.183Z] 15:39:30     INFO -  2  0x3d80ab3706f1
[task 2018-03-19T15:39:30.183Z] 15:39:30     INFO -     rbp = 0x00007f1f331fa280   rsp = 0x00007f1f331fa258
[task 2018-03-19T15:39:30.183Z] 15:39:30     INFO -     rip = 0x00003d80ab3706f1
[task 2018-03-19T15:39:30.184Z] 15:39:30     INFO -     Found by: previous frame's frame pointer
[task 2018-03-19T15:39:30.184Z] 15:39:30     INFO -  3  0x7f1f31b922d8
[task 2018-03-19T15:39:30.184Z] 15:39:30     INFO -     rbp = 0x00007f1f331fa2f8   rsp = 0x00007f1f331fa290
[task 2018-03-19T15:39:30.185Z] 15:39:30     INFO -     rip = 0x00007f1f31b922d8
[task 2018-03-19T15:39:30.185Z] 15:39:30     INFO -     Found by: previous frame's frame pointer
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.