Closed Bug 1447152 Opened 7 years ago Closed 2 years ago

Intermittent toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Uncaught exception - Simplified document title should be updated with recovery title. - timed out after 50 tries.

Categories

(Toolkit :: Printing, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

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

Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=169022605&repo=autoland https://queue.taskcluster.net/v1/task/Bgcf4IpTQOiIoZVr7v5sdw/runs/0/artifacts/public/logs/live_backing.log 20:41:03 INFO - 17 INFO TEST-START | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js 20:41:03 INFO - GECKO(5308) | Waiting for browser load 20:41:03 INFO - GECKO(5308) | Saw state f0001 and status 0 20:41:03 INFO - GECKO(5308) | Saw state c0010 and status 0 20:41:03 INFO - GECKO(5308) | Browser loaded http://example.com/browser/toolkit/components/printing/tests/simplifyNonArticleSample.html 20:41:04 INFO - GECKO(5308) | JavaScript error: resource:///modules/ContentMetaHandler.jsm, line 155: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIMessageSender.sendAsyncMessage] 20:41:04 INFO - GECKO(5308) | JavaScript error: chrome://global/content/browser-content.js, line 665: TypeError: content.document.head is null 20:41:09 INFO - TEST-INFO | started process screenshot 20:41:09 INFO - TEST-INFO | screenshot: exit 0 20:41:09 INFO - Buffered messages logged at 20:41:03 20:41:09 INFO - 18 INFO Entering test bound set_simplify_and_reader_pref 20:41:09 INFO - 19 INFO Leaving test bound set_simplify_and_reader_pref 20:41:09 INFO - 20 INFO Entering test bound switch_print_preview_browsers 20:41:09 INFO - 21 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/printing/tests/simplifyNonArticleSample.html" line: 0}] 20:41:09 INFO - Buffered messages logged at 20:41:04 20:41:09 INFO - 22 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}] 20:41:09 INFO - 23 INFO TEST-PASS | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Should have initial content. - "Non article title" == "Non article title" - 20:41:09 INFO - 24 INFO Console message: [JavaScript Error: "TypeError: content.document.head is null" {file: "chrome://global/content/browser-content.js" line: 665}] 20:41:09 INFO - 25 INFO TEST-PASS | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Should have simplify page option checked - 20:41:10 INFO - Buffered messages finished 20:41:10 ERROR - 26 INFO TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Uncaught exception - Simplified document title should be updated with recovery title. - timed out after 50 tries. 20:41:10 INFO - 27 INFO Leaving test bound switch_print_preview_browsers 20:41:10 INFO - GECKO(5308) | MEMORY STAT | vsize 2098945MB | vsizeMaxContiguous 129794423MB | residentFast 255MB | heapAllocated 87MB 20:41:10 INFO - 28 INFO TEST-OK | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | took 6134ms 20:41:10 INFO - Not taking screenshot here: see the one that was previously logged 20:41:10 ERROR - 29 INFO TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Found an unexpected tab at the end of test run: about:printpreview - 20:41:10 INFO - Not taking screenshot here: see the one that was previously logged 20:41:10 ERROR - 30 INFO TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Found an unexpected tab at the end of test run: about:printpreview - 20:41:10 INFO - GECKO(5308) | ************************* 20:41:10 INFO - GECKO(5308) | A coding exception was thrown and uncaught in a Task. 20:41:10 INFO - GECKO(5308) | Full message: TypeError: this.selectedItem is null 20:41:10 INFO - GECKO(5308) | Full stack: _setPositionalAttributes@chrome://browser/content/tabbrowser.xml:328:1 20:41:10 INFO - GECKO(5308) | _endRemoveTab@chrome://browser/content/tabbrowser.js:2901:5 20:41:10 INFO - GECKO(5308) | removeTab@chrome://browser/content/tabbrowser.js:2657:7 20:41:10 INFO - GECKO(5308) | Tester_waitForWindowsState@chrome://mochikit/content/browser-test.js:548:9 20:41:10 INFO - GECKO(5308) | Tester.prototype.nextTest<@chrome://mochikit/content/browser-test.js:876:5 20:41:10 INFO - GECKO(5308) | testScope/test_finish/<@chrome://mochikit/content/browser-test.js:1375:11 20:41:10 INFO - GECKO(5308) | run@chrome://mochikit/content/browser-test.js:1312:9 20:41:10 INFO - GECKO(5308) | ************************* 20:41:10 INFO - GECKO(5308) | Unable to read VR Path Registry from C:\Users\GenericWorker\AppData\Local\openvr\openvrpaths.vrpath 20:41:10 INFO - GECKO(5308) | JavaScript error: chrome://browser/content/tabbrowser.xml, line 328: TypeError: this.selectedItem is null 20:41:10 INFO - 31 INFO Console message: [JavaScript Error: "TypeError: this.selectedItem is null" {file: "chrome://browser/content/tabbrowser.xml" line: 328}] 20:45:56 INFO - 32 INFO Console message: [JavaScript Error: "getScreenshot error: Win error 2 during operation open on file C:\Users\GenericWorker\AppData\Local\Temp\tmpuvosdg.mozrunner\thumbnails\7414eca030d802715e5079446f9d937e.png (The system cannot find the file specified. 20:45:56 INFO - )" {file: "resource://activity-stream/lib/Screenshots.jsm" line: 64}] 20:45:56 INFO - getScreenshotForURL@resource://activity-stream/lib/Screenshots.jsm:64:7 20:45:56 INFO - async*maybeCacheScreenshot@resource://activity-stream/lib/Screenshots.jsm:107:32 20:45:56 INFO - async*_fetchIcon@resource://activity-stream/lib/TopSitesFeed.jsm:185:13 20:45:56 INFO - async*getLinksWithDefaults@resource://activity-stream/lib/TopSitesFeed.jsm:134:9 20:45:56 INFO - async*refresh@resource://activity-stream/lib/TopSitesFeed.jsm:153:25 20:45:56 INFO - async*onAction@resource://activity-stream/lib/TopSitesFeed.jsm:311:9 20:45:56 INFO - _middleware/</<@resource://activity-stream/lib/Store.jsm:49:11 20:45:56 INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:28:55 20:45:56 INFO - init/this.intervalId<@resource://activity-stream/lib/SystemTickFeed.jsm:18:41 20:45:56 INFO - notify@resource://gre/modules/Timer.jsm:44:7 20:52:06 INFO - Buffered messages finished 20:52:06 WARNING - TEST-UNEXPECTED-TIMEOUT | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | application timed out after 370 seconds with no output 20:52:06 INFO - 33 ERROR Force-terminating active process(es). 20:52:06 INFO - Determining child pids from psutil... 20:52:06 INFO - [7888, 3336, 2444, 5092] 20:52:06 INFO - ==> process 5308 launched child process 2444 ("Z:\task_1521491815\build\application\firefox\firefox.exe" -contentproc --channel="5308.0.963410621\829501970" -childID 1 -isForBrowser -prefsHandle 2120 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521491815\build\application\firefox\omni.ja" -appomni "Z:\task_1521491815\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521491815\build\application\firefox\browser" 5308 "\\.\pipe\gecko-crash-server-pipe.5308" 2176 tab) 20:52:06 INFO - ==> process 5308 launched child process 3336 ("Z:\task_1521491815\build\application\firefox\firefox.exe" -contentproc --channel="5308.6.299148310\1111759118" -childID 2 -isForBrowser -prefsHandle 2512 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521491815\build\application\firefox\omni.ja" -appomni "Z:\task_1521491815\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521491815\build\application\firefox\browser" 5308 "\\.\pipe\gecko-crash-server-pipe.5308" 2536 tab) 20:52:06 INFO - ==> process 5308 launched child process 7888 ("Z:\task_1521491815\build\application\firefox\firefox.exe" -contentproc --channel="5308.12.440755785\908436341" -childID 3 -isForBrowser -prefsHandle 3492 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521491815\build\application\firefox\omni.ja" -appomni "Z:\task_1521491815\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521491815\build\application\firefox\browser" 5308 "\\.\pipe\gecko-crash-server-pipe.5308" 3500 tab) 20:52:06 INFO - ==> process 5308 launched child process 5092 ("Z:\task_1521491815\build\application\firefox\firefox.exe" -contentproc --channel="5308.18.422742983\2047768105" -childID 4 -isForBrowser -prefsHandle 3724 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521491815\build\application\firefox\omni.ja" -appomni "Z:\task_1521491815\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521491815\build\application\firefox\browser" 5308 "\\.\pipe\gecko-crash-server-pipe.5308" 3648 tab) 20:52:06 INFO - Found child pids: set([7888, 3336, 2444, 5092]) 20:52:06 INFO - Killing process: 7888 20:52:06 INFO - Not taking screenshot here: see the one that was previously logged 20:52:06 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 7888: error 5 20:52:06 INFO - Killing process: 3336 20:52:06 INFO - Not taking screenshot here: see the one that was previously logged 20:52:06 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 3336: error 5 20:52:06 INFO - Killing process: 2444 20:52:06 INFO - Not taking screenshot here: see the one that was previously logged 20:52:07 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 2444: error 5 20:52:07 INFO - Killing process: 5092 20:52:07 INFO - Not taking screenshot here: see the one that was previously logged 20:52:07 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 5092: error 5 20:52:07 INFO - psutil found pid 7888 dead 20:52:07 INFO - psutil found pid 5092 dead 20:52:07 INFO - psutil found pid 2444 dead 20:52:07 INFO - psutil found pid 3336 dead 20:52:07 INFO - Killing process: 5308 20:52:07 INFO - Not taking screenshot here: see the one that was previously logged 20:52:07 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 5308: error 5 20:52:07 INFO - psutil found pid 5308 dead 20:52:07 INFO - TEST-INFO | Main app process: exit 1 20:52:07 INFO - Buffered messages finished 20:52:07 ERROR - 34 ERROR TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | application terminated with exit code 1 20:52:07 INFO - runtests.py | Application ran for: 0:11:12.162000 20:52:07 INFO - zombiecheck | Reading PID log: c:\users\genericworker\appdata\local\temp\tmpevmqi5pidlog 20:52:07 INFO - ==> process 5308 launched child process 2444 ("Z:\task_1521491815\build\application\firefox\firefox.exe" -contentproc --channel="5308.0.963410621\829501970" -childID 1 -isForBrowser -prefsHandle 2120 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521491815\build\application\firefox\omni.ja" -appomni "Z:\task_1521491815\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521491815\build\application\firefox\browser" 5308 "\\.\pipe\gecko-crash-server-pipe.5308" 2176 tab) 20:52:07 INFO - ==> process 5308 launched child process 3336 ("Z:\task_1521491815\build\application\firefox\firefox.exe" -contentproc --channel="5308.6.299148310\1111759118" -childID 2 -isForBrowser -prefsHandle 2512 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521491815\build\application\firefox\omni.ja" -appomni "Z:\task_1521491815\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521491815\build\application\firefox\browser" 5308 "\\.\pipe\gecko-crash-server-pipe.5308" 2536 tab) 20:52:07 INFO - ==> process 5308 launched child process 7888 ("Z:\task_1521491815\build\application\firefox\firefox.exe" -contentproc --channel="5308.12.440755785\908436341" -childID 3 -isForBrowser -prefsHandle 3492 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521491815\build\application\firefox\omni.ja" -appomni "Z:\task_1521491815\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521491815\build\application\firefox\browser" 5308 "\\.\pipe\gecko-crash-server-pipe.5308" 3500 tab) 20:52:07 INFO - ==> process 5308 launched child process 5092 ("Z:\task_1521491815\build\application\firefox\firefox.exe" -contentproc --channel="5308.18.422742983\2047768105" -childID 4 -isForBrowser -prefsHandle 3724 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521491815\build\application\firefox\omni.ja" -appomni "Z:\task_1521491815\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521491815\build\application\firefox\browser" 5308 "\\.\pipe\gecko-crash-server-pipe.5308" 3648 tab) 20:52:07 INFO - zombiecheck | Checking for orphan process with PID: 3336 20:52:07 INFO - zombiecheck | Checking for orphan process with PID: 7888 20:52:07 INFO - zombiecheck | Checking for orphan process with PID: 2444 20:52:07 INFO - zombiecheck | Checking for orphan process with PID: 5092 20:52:07 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/Hg-bxS8kTfWpJHcmtVFaLg/artifacts/public/build/target.crashreporter-symbols.zip 20:52:17 INFO - mozcrash Copy/paste: Z:\task_1521491815\build\win32-minidump_stackwalk.exe c:\users\genericworker\appdata\local\temp\tmpuvosdg.mozrunner\minidumps\2d1c9f6a-8185-418e-8579-3be453ab4ae1.dmp c:\users\genericworker\appdata\local\temp\tmpreairg 20:52:21 INFO - mozcrash Saved minidump as Z:\task_1521491815\build\blobber_upload_dir\2d1c9f6a-8185-418e-8579-3be453ab4ae1.dmp 20:52:21 WARNING - PROCESS-CRASH | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | application crashed [None] 20:52:21 INFO - Crash dump filename: c:\users\genericworker\appdata\local\temp\tmpuvosdg.mozrunner\minidumps\2d1c9f6a-8185-418e-8579-3be453ab4ae1.dmp 20:52:21 INFO - Operating system: Windows NT 20:52:21 INFO - 10.0.15063 20:52:21 INFO - CPU: amd64 20:52:21 INFO - family 6 model 63 stepping 2 20:52:21 INFO - 8 CPUs 20:52:21 INFO - GPU: UNKNOWN 20:52:21 INFO - No crash 20:52:21 INFO - Process uptime: 669 seconds 20:52:21 INFO - Thread 0 20:52:21 INFO - 0 ntdll.dll!AslHashFree + 0x35028 20:52:21 INFO - rax = 0x000000d9317febf0 rdx = 0x0000000000000220 20:52:21 INFO - rcx = 0x000000d9317febf0 rbx = 0x0000000000000000 20:52:21 INFO - rsi = 0x0000000000000000 rdi = 0x0000000000000000 20:52:21 INFO - rbp = 0x000000d9317feb50 rsp = 0x000000d9317feaf8 20:52:21 INFO - r8 = 0x000000d9317ff390 r9 = 0x00007ff9c3061c58 20:52:21 INFO - r10 = 0x0000000000000000 r11 = 0x000000d9317ff320 20:52:21 INFO - r12 = 0x0000000000000000 r13 = 0x0000000000000000 20:52:21 INFO - r14 = 0x000002cac3d08370 r15 = 0x000002cac3d083a8 20:52:21 INFO - rip = 0x00007ff9eb018be4 20:52:21 INFO - Found by: given as instruction pointer in context 20:52:21 INFO - 1 0x2cac3d10701 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317feb60 20:52:21 INFO - rip = 0x000002cac3d10701 20:52:21 INFO - Found by: previous frame's frame pointer 20:52:21 INFO - 2 KERNELBASE.dll!AslpFileLargeEnsureLargeFileMapping + 0x3c 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317feb70 20:52:21 INFO - rip = 0x00007ff9e77fe988 20:52:21 INFO - Found by: stack scanning 20:52:21 INFO - 3 xul.dll!SingleNativeEventPump::OnProcessNextEvent(nsIThreadInternal *,bool) [nsAppShell.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 149 + 0x1a] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317febb0 20:52:21 INFO - rip = 0x00007ff9c10295a2 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 4 xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 999 + 0x19] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317fec20 20:52:21 INFO - rip = 0x00007ff9bf591d56 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 5 xul.dll!NS_ProcessNextEvent(nsIThread *,bool) [nsThreadUtils.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 517 + 0xd] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff360 20:52:21 INFO - rip = 0x00007ff9bf5994df 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 6 xul.dll!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [MessagePump.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 125 + 0xa] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff390 20:52:21 INFO - rip = 0x00007ff9bf8f0e35 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 7 xul.dll!mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate *) [MessagePump.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 301 + 0xb] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff3d0 20:52:21 INFO - rip = 0x00007ff9bf8f0f07 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 8 xul.dll!MessageLoop::RunHandler() [message_loop.cc:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 319 + 0xf] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff400 20:52:21 INFO - rip = 0x00007ff9bf8cff2f 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 9 xul.dll!MessageLoop::Run() [message_loop.cc:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 299 + 0x8] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff430 20:52:21 INFO - rip = 0x00007ff9bf8cfbba 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 10 xul.dll!nsBaseAppShell::Run() [nsBaseAppShell.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 157 + 0xd] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff480 20:52:21 INFO - rip = 0x00007ff9c0fdb8c3 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 11 xul.dll!nsAppShell::Run() [nsAppShell.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 401 + 0x8] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff4b0 20:52:21 INFO - rip = 0x00007ff9c102b4db 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 12 xul.dll!XRE_RunAppShell() [nsEmbedFunctions.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 893 + 0x6] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff4e0 20:52:21 INFO - rip = 0x00007ff9c1db1abb 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 13 xul.dll!mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate *) [MessagePump.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 269 + 0x5] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff510 20:52:21 INFO - rip = 0x00007ff9bf8f0ec5 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 14 xul.dll!MessageLoop::RunHandler() [message_loop.cc:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 319 + 0xf] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff540 20:52:21 INFO - rip = 0x00007ff9bf8cff2f 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 15 xul.dll!MessageLoop::Run() [message_loop.cc:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 299 + 0x8] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff570 20:52:21 INFO - rip = 0x00007ff9bf8cfbba 20:52:21 INFO - Found by: call frame info 20:52:21 INFO - 16 xul.dll!XRE_InitChildProcess(int,char * * const,XREChildData const *) [nsEmbedFunctions.cpp:d2c963c5022507cb99c74c4bcba9d2c596b4339e : 719 + 0x9] 20:52:21 INFO - rbp = 0x000000d9317fec60 rsp = 0x000000d9317ff5c0 20:52:21 INFO - rip = 0x00007ff9c1db185a 20:52:21 INFO - Found by: call frame info
We have 39 failures since this bug was created (10h ago). They occur on Linux x64 (asan, debug, opt, pgo), Windows 7 (opt, debug, pgo) and windows10-64 (opt, debug, pgo). Here is a recent log example: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=169111454&lineNumber=6562 and a relevant part of it: 03:44:12 ERROR - 24 INFO TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Uncaught exception - Simplified document title should be updated with recovery title. - timed out after 50 tries. 03:44:12 INFO - 25 INFO Leaving test bound switch_print_preview_browsers 03:44:12 INFO - GECKO(5020) | MEMORY STAT | vsize 746MB | vsizeMaxContiguous 784MB | residentFast 201MB | heapAllocated 78MB 03:44:12 INFO - 26 INFO TEST-OK | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | took 5948ms 03:44:12 INFO - Not taking screenshot here: see the one that was previously logged 03:44:12 ERROR - 27 INFO TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Found an unexpected tab at the end of test run: about:printpreview - 03:44:12 INFO - Not taking screenshot here: see the one that was previously logged 03:44:12 ERROR - 28 INFO TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Found an unexpected tab at the end of test run: about:printpreview -
Flags: needinfo?(mconley)
Whiteboard: [stockwell needswork]
Summary: Perma-failing tier2 toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Uncaught exception - Simplified document title should be updated with recovery title. - timed out after 50 tries. → Intermittent toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Uncaught exception - Simplified document title should be updated with recovery title. - timed out after 50 tries.

Apologies - declaring needinfo bankruptcy on needinfo's greater than 2 years old.

Flags: needinfo?(mconley)
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Recent failure: https://treeherder.mozilla.org/logviewer?job_id=349121581&repo=mozilla-central&lineNumber=8652

task 2021-08-21T10:53:14.224Z] 10:53:14     INFO - TEST-START | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js
[task 2021-08-21T10:53:14.259Z] 10:53:14     INFO - GECKO(5640) | Waiting for browser load
[task 2021-08-21T10:53:14.274Z] 10:53:14     INFO - GECKO(5640) | Waiting for browser state change
[task 2021-08-21T10:53:14.291Z] 10:53:14     INFO - GECKO(5640) | Saw state f0001 and status 0
[task 2021-08-21T10:53:14.337Z] 10:53:14     INFO - GECKO(5640) | Saw state c0010 and status 0
[task 2021-08-21T10:53:14.353Z] 10:53:14     INFO - GECKO(5640) | Browser got expected state change http://example.com/browser/toolkit/components/printing/tests/simplifyNonArticleSample.html
[task 2021-08-21T10:53:15.757Z] 10:53:15     INFO - GECKO(5640) | JavaScript error: resource://gre/actors/PrintingChild.jsm, line 239: TypeError: can't access property "innerHTML", document.head is null
[task 2021-08-21T10:53:21.791Z] 10:53:21     INFO - TEST-INFO | started process screenshot
[task 2021-08-21T10:53:21.991Z] 10:53:21     INFO - TEST-INFO | screenshot: exit 0
[task 2021-08-21T10:53:21.994Z] 10:53:21     INFO - Buffered messages logged at 10:53:14
[task 2021-08-21T10:53:21.994Z] 10:53:21     INFO - Entering test bound set_simplify_and_reader_pref
[task 2021-08-21T10:53:21.995Z] 10:53:21     INFO - Leaving test bound set_simplify_and_reader_pref
[task 2021-08-21T10:53:21.995Z] 10:53:21     INFO - Entering test bound switch_print_preview_browsers
[task 2021-08-21T10:53:21.996Z] 10:53:21     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/printing/tests/simplifyNonArticleSample.html" line: 0}]
[task 2021-08-21T10:53:21.997Z] 10:53:21     INFO - Buffered messages logged at 10:53:15
[task 2021-08-21T10:53:21.998Z] 10:53:21     INFO - TEST-PASS | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Should have initial content. - "Non article title" == "Non article title" - 
[task 2021-08-21T10:53:21.998Z] 10:53:21     INFO - Console message: [JavaScript Error: "TypeError: can't access property "innerHTML", document.head is null" {file: "resource://gre/actors/PrintingChild.jsm" line: 239}]
[task 2021-08-21T10:53:21.999Z] 10:53:21     INFO - Buffered messages logged at 10:53:16
[task 2021-08-21T10:53:21.999Z] 10:53:21     INFO - TEST-PASS | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Should have simplify page option checked - 
[task 2021-08-21T10:53:22.000Z] 10:53:21     INFO - Buffered messages finished
[task 2021-08-21T10:53:22.000Z] 10:53:22     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Uncaught exception - Simplified document title should be updated with recovery title. - timed out after 50 tries.
[task 2021-08-21T10:53:22.001Z] 10:53:22     INFO - Leaving test bound switch_print_preview_browsers
[task 2021-08-21T10:53:22.001Z] 10:53:22     INFO - GECKO(5640) | MEMORY STAT | vsize 19406284MB | vsizeMaxContiguous 66471623MB | residentFast 1191MB
[task 2021-08-21T10:53:22.002Z] 10:53:22     INFO - TEST-OK | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | took 7614ms
[task 2021-08-21T10:53:22.002Z] 10:53:22     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-08-21T10:53:22.003Z] 10:53:22     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Found an unexpected tab at the end of test run: about:printpreview - 
[task 2021-08-21T10:53:22.003Z] 10:53:22     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-08-21T10:53:22.004Z] 10:53:22     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js | Found an unexpected tab at the end of test run: about:printpreview - 
[task 2021-08-21T10:53:22.004Z] 10:53:22     INFO - GECKO(5640) | JavaScript error: chrome://browser/content/tabbrowser-tabs.js, line 1123: TypeError: can't access property "closing", selectedTab is null
[task 2021-08-21T10:53:22.004Z] 10:53:22     INFO - Console message: [JavaScript Error: "TypeError: can't access property "closing", selectedTab is null" {file: "chrome://browser/content/tabbrowser-tabs.js" line: 1123}]
[task 2021-08-21T10:53:36.314Z] 10:53:36     INFO - Console message: [JavaScript Warning: "telemetry.state_file_read_errors - Unknown scalar."]
[task 2021-08-21T10:53:36.321Z] 10:53:36     INFO - Console message: [JavaScript Warning: "telemetry.generated_new_client_id - Unknown scalar."]
[task 2021-08-21T10:58:55.858Z] 10:58:55     INFO - GECKO(5640) | 1629543535863	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates
[task 2021-08-21T10:58:55.867Z] 10:58:55     INFO - Console message: [JavaScript Error: "1629543535863	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates" {file: "resource://gre/modules/Log.jsm" line: 723}]
[task 2021-08-21T10:58:55.867Z] 10:58:55     INFO - append@resource://gre/modules/Log.jsm:723:12
[task 2021-08-21T10:58:55.867Z] 10:58:55     INFO - log@resource://gre/modules/Log.jsm:379:16
[task 2021-08-21T10:58:55.867Z] 10:58:55     INFO - error@resource://gre/modules/Log.jsm:387:10
[task 2021-08-21T10:58:55.867Z] 10:58:55     INFO - updateSystemAddons/res<@resource://gre/modules/addons/XPIInstall.jsm:4049:25
[task 2021-08-21T10:58:55.867Z] 10:58:55     INFO - 
[task 2021-08-21T11:05:05.894Z] 11:05:05     INFO - Buffered messages finished
[task 2021-08-21T11:05:05.896Z] 11:05:05    ERROR - TEST-UNEXPECTED-TIMEOUT | toolkit/components/printing/tests/browser_preview_print_simplify_non_article.js (finished) | application timed out after 370 seconds with no output
[task 2021-08-21T11:05:05.896Z] 11:05:05    ERROR - Force-terminating active process(es).
[task 2021-08-21T11:05:05.897Z] 11:05:05     INFO - Determining child pids from psutil...
[task 2021-08-21T11:05:05.900Z] 11:05:05     INFO - [2456]
[task 2021-08-21T11:05:05.901Z] 11:05:05     INFO - ==> process 2456 launched child process 5116 ("Z:\task_162953920034637\build\application\firefox\firefox.exe" -contentproc --channel="2456.0.1090209407\1477547787" -parentBuildID 20210821093516 -prefsHandle 2264 -prefMapHandle 2256 -prefsLen 1 -prefMapSize 251355 -appdir "Z:\task_162953920034637\build\application\firefox\browser" - 2456  gpu)
[task 2021-08-21T11:05:05.901Z] 11:05:05     INFO - ==> process 2456 launched child process 4936 ("Z:\task_162953920034637\build\application\firefox\firefox.exe" -contentproc --channel="2456.1.1438618888\983908792" -childID 1 -isForBrowser -prefsHandle 2840 -prefMapHandle 2836 -prefsLen 1790 -prefMapSize 251355 -jsInit 1384 283504 -parentBuildID 20210821093516 -appdir "Z:\task_162953920034637\build\application\firefox\browser" - 2456  tab)
[task 2021-08-21T11:05:05.902Z] 11:05:05     INFO - ==> process 2456 launched child process 8744 ("Z:\task_162953920034637\build\application\firefox\firefox.exe" -contentproc --channel="2456.3.2096305493\410690646" -childID 2 -isForBrowser -prefsHandle 3204 -prefMapHandle 3200 -prefsLen 1933 -prefMapSize 251355 -jsInit 1384 283504 -parentBuildID 20210821093516 -appdir "Z:\task_162953920034637\build\application\firefox\browser" - 2456  tab)
[task 2021-08-21T11:05:05.903Z] 11:05:05     INFO - ==> process 2456 launched child process 7372 ("Z:\task_162953920034637\build\application\firefox\firefox.exe" -contentproc --channel="2456.5.730772816\186143899" -childID 3 -isForBrowser -prefsHandle 3240 -prefMapHandle 3224 -prefsLen 1973 -prefMapSize 251355 -jsInit 1384 283504 -parentBuildID 20210821093516 -appdir "Z:\task_162953920034637\build\application\firefox\browser" - 2456  tab)
[task 2021-08-21T11:05:05.904Z] 11:05:05     INFO - ==> process 2456 launched child process 3472 ("Z:\task_162953920034637\build\application\firefox\firefox.exe" -contentproc --channel="2456.7.673922068\828350984" -childID 4 -isForBrowser -prefsHandle 4160 -prefMapHandle 4144 -prefsLen 8633 -prefMapSize 251355 -jsInit 1384 283504 -parentBuildID 20210821093516 -appdir "Z:\task_162953920034637\build\application\firefox\browser" - 2456  tab)
[task 2021-08-21T11:05:05.905Z] 11:05:05     INFO - ==> process 2456 launched child process 3152 ("Z:\task_162953920034637\build\application\firefox\firefox.exe" -contentproc --channel="2456.9.2005373326\2084570898" -childID 5 -isForBrowser -prefsHandle 4188 -prefMapHandle 4200 -prefsLen 9954 -prefMapSize 251355 -jsInit 1384 283504 -parentBuildID 20210821093516 -appdir "Z:\task_162953920034637\build\application\firefox\browser" - 2456  tab)
[task 2021-08-21T11:05:05.905Z] 11:05:05     INFO - ==> process 2456 launched child process 5488 ("Z:\task_162953920034637\build\application\firefox\firefox.exe" -contentproc --channel="2456.11.1108514152\1967533376" -childID 6 -isForBrowser -prefsHandle 3044 -prefMapHandle 4524 -prefsLen 10126 -prefMapSize 251355 -jsInit 1384 283504 -parentBuildID 20210821093516 -appdir "Z:\task_162953920034637\build\application\firefox\browser" - 2456  tab)
[task 2021-08-21T11:05:05.906Z] 11:05:05     INFO - Found child pids: {8744, 4936, 7372, 3472, 3152, 5488, 2456, 5116}
[task 2021-08-21T11:05:05.906Z] 11:05:05     INFO - Killing process: 8744
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.