Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=150887909&repo=mozilla-central https://queue.taskcluster.net/v1/task/I2TbiMC2Taiqc0ZmCfI7bA/runs/0/artifacts/public/logs/live_backing.log 21:35:54 INFO - TEST-START | /streams/readable-streams/tee.dedicatedworker.html 21:35:54 INFO - Setting pref javascript.options.streams (true) 21:35:54 INFO - PID 3896 | ++DOCSHELL 1D587400 == 7 [pid = 3896] [id = {810c2f74-34b5-4c0f-b254-5c3b839c8351}] 21:35:54 INFO - PID 3896 | ++DOMWINDOW == 18 (19242A60) [pid = 3896] [serial = 18] [outer = 00000000] 21:35:54 INFO - PID 3896 | ++DOMWINDOW == 19 (1D588800) [pid = 3896] [serial = 19] [outer = 19242A60] 21:35:54 INFO - PID 3896 | ++DOMWINDOW == 20 (1E62F800) [pid = 3896] [serial = 20] [outer = 19242A60] 21:35:54 INFO - PID 3896 | ++DOCSHELL 1E9E9000 == 8 [pid = 3896] [id = {2847eade-960d-414c-b897-1f6ea556c6ba}] 21:35:54 INFO - PID 3896 | ++DOMWINDOW == 21 (19242CA0) [pid = 3896] [serial = 21] [outer = 00000000] 21:35:54 INFO - PID 3896 | ++DOMWINDOW == 22 (1E9EB000) [pid = 3896] [serial = 22] [outer = 19242CA0] 21:35:54 INFO - PID 3896 | ++DOMWINDOW == 23 (1D57BC00) [pid = 3896] [serial = 23] [outer = 19242CA0] 21:35:54 INFO - PID 3896 | [3896, Main Thread] WARNING: attempt to modify an immutable nsStandardURL: file z:/build/build/src/netwerk/base/nsStandardURL.cpp, line 1698 21:35:54 INFO - PID 3896 | Assertion failure: stream->readable(), at z:/build/build/src/js/src/builtin/Stream.cpp:2932 21:36:34 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/ZBVWz5exR4quU56lkLVkpw/artifacts/public/build/target.crashreporter-symbols.zip 21:36:43 INFO - mozcrash Copy/paste: Z:\task_1512766457\build\win32-minidump_stackwalk.exe c:\users\genericworker\appdata\local\temp\tmp9r4xfa.mozrunner\minidumps\e30a2ec6-f606-4e57-b839-c0c8c76dffe5.dmp c:\users\genericworker\appdata\local\temp\tmpdniqih 21:36:43 ERROR - Traceback (most recent call last): 21:36:43 ERROR - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 353, in run 21:36:43 ERROR - new_state = self.wait_event() 21:36:43 ERROR - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 427, in wait_event 21:36:43 ERROR - return f(*data) 21:36:43 ERROR - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 562, in test_ended 21:36:43 ERROR - if self.browser.check_for_crashes(): 21:36:43 ERROR - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 228, in check_for_crashes 21:36:43 ERROR - self.browser.check_for_crashes() 21:36:43 ERROR - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\browsers\firefox.py", line 330, in check_for_crashes 21:36:43 ERROR - quiet=True)) 21:36:43 ERROR - File "Z:\task_1512766457\build\venv\lib\site-packages\mozcrash\mozcrash.py", line 97, in check_for_crashes 21:36:43 ERROR - for info in crash_info: 21:36:43 ERROR - File "Z:\task_1512766457\build\venv\lib\site-packages\mozcrash\mozcrash.py", line 214, in __iter__ 21:36:43 ERROR - rv = self._process_dump_file(path, extra) 21:36:43 ERROR - File "Z:\task_1512766457\build\venv\lib\site-packages\mozcrash\mozcrash.py", line 294, in _process_dump_file 21:36:43 ERROR - self._save_dump_file(path, extra) 21:36:43 ERROR - File "Z:\task_1512766457\build\venv\lib\site-packages\mozcrash\mozcrash.py", line 318, in _save_dump_file 21:36:43 ERROR - shutil.move(path, self.dump_save_path) 21:36:43 ERROR - File "c:\mozilla-build\python\Lib\shutil.py", line 302, in move 21:36:43 ERROR - copy2(src, real_dst) 21:36:43 ERROR - File "c:\mozilla-build\python\Lib\shutil.py", line 130, in copy2 21:36:43 ERROR - copyfile(src, dst) 21:36:43 ERROR - File "c:\mozilla-build\python\Lib\shutil.py", line 82, in copyfile 21:36:43 ERROR - with open(src, 'rb') as fsrc: 21:36:43 ERROR - IOError: [Errno 13] Permission denied: 'c:\\users\\genericworker\\appdata\\local\\temp\\tmp9r4xfa.mozrunner\\minidumps\\e30a2ec6-f606-4e57-b839-c0c8c76dffe5.dmp' 21:36:43 ERROR - 21:36:43 INFO - Browser exited with return code 572 21:36:43 WARNING - u'runner_teardown' () 21:36:43 INFO - STDERR: Exception in thread Thread-TestrunnerManager-1: 21:36:43 INFO - Traceback (most recent call last): 21:36:43 INFO - File "c:\mozilla-build\python\Lib\threading.py", line 801, in __bootstrap_inner 21:36:43 INFO - self.run() 21:36:43 INFO - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 353, in run 21:36:43 INFO - new_state = self.wait_event() 21:36:43 INFO - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 427, in wait_event 21:36:43 INFO - return f(*data) 21:36:43 INFO - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 562, in test_ended 21:36:43 INFO - if self.browser.check_for_crashes(): 21:36:43 INFO - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\testrunner.py", line 228, in check_for_crashes 21:36:43 INFO - self.browser.check_for_crashes() 21:36:43 INFO - File "Z:\task_1512766457\build\tests\web-platform\tests\tools\wptrunner\wptrunner\browsers\firefox.py", line 330, in check_for_crashes 21:36:43 INFO - quiet=True)) 21:36:43 INFO - File "Z:\task_1512766457\build\venv\lib\site-packages\mozcrash\mozcrash.py", line 97, in check_for_crashes 21:36:43 INFO - for info in crash_info: 21:36:43 INFO - File "Z:\task_1512766457\build\venv\lib\site-packages\mozcrash\mozcrash.py", line 214, in __iter__ 21:36:43 INFO - rv = self._process_dump_file(path, extra) 21:36:43 INFO - File "Z:\task_1512766457\build\venv\lib\site-packages\mozcrash\mozcrash.py", line 294, in _process_dump_file 21:36:43 INFO - self._save_dump_file(path, extra) 21:36:43 INFO - File "Z:\task_1512766457\build\venv\lib\site-packages\mozcrash\mozcrash.py", line 318, in _save_dump_file 21:36:43 INFO - shutil.move(path, self.dump_save_path) 21:36:43 INFO - File "c:\mozilla-build\python\Lib\shutil.py", line 302, in move 21:36:43 INFO - copy2(src, real_dst) 21:36:43 INFO - File "c:\mozilla-build\python\Lib\shutil.py", line 130, in copy2 21:36:43 INFO - copyfile(src, dst) 21:36:43 INFO - File "c:\mozilla-build\python\Lib\shutil.py", line 82, in copyfile 21:36:43 INFO - with open(src, 'rb') as fsrc: 21:36:43 INFO - IOError: [Errno 13] Permission denied: 'c:\\users\\genericworker\\appdata\\local\\temp\\tmp9r4xfa.mozrunner\\minidumps\\e30a2ec6-f606-4e57-b839-c0c8c76dffe5.dmp' 21:36:43 INFO - Got 0 unexpected results 21:36:43 INFO - SUITE-END | took 1803s 21:36:43 INFO - Closing logging queue 21:36:43 INFO - queue closed 21:36:43 CRITICAL - Test harness output was not a valid structured log message: 21:36:43 CRITICAL - Traceback (most recent call last): 21:36:43 CRITICAL - Test harness output was not a valid structured log message: 21:36:43 CRITICAL - File "c:\mozilla-build\python\Lib\multiprocessing\queues.py", line 264, in _feed 21:36:43 CRITICAL - Test harness output was not a valid structured log message: 21:36:43 CRITICAL - send(obj) 21:36:43 CRITICAL - Test harness output was not a valid structured log message: 21:36:43 CRITICAL - IOError: [Errno 232] The pipe is being closed 21:36:44 INFO - Return code: 0 21:36:44 CRITICAL - # TBPL FAILURE # 21:36:44 WARNING - setting return code to 2 21:36:44 INFO - Running post-action listener: _package_coverage_data 21:36:44 INFO - Running post-action listener: _resource_record_post_action 21:36:44 INFO - [mozharness: 2017-12-08 21:36:44.815000Z] Finished run-tests step (success) 21:36:44 INFO - Running post-run listener: _resource_record_post_run 21:36:45 INFO - Total resource usage - Wall time: 1820s; CPU: 9.0%; Read bytes: 73790976; Write bytes: 2610150912; Read time: 314250; Write time: 5261330 21:36:45 INFO - TinderboxPrint: CPU usage<br/>9.5% 21:36:45 INFO - TinderboxPrint: I/O read bytes / time<br/>73,790,976 / 314,250 21:36:45 INFO - TinderboxPrint: I/O write bytes / time<br/>2,610,150,912 / 5,261,330 21:36:45 INFO - TinderboxPrint: CPU idle<br/>13,185.0 (90.5%) 21:36:45 INFO - TinderboxPrint: CPU system<br/>176.9 (1.2%) 21:36:45 INFO - TinderboxPrint: CPU user<br/>1,202.0 (8.3%) 21:36:45 INFO - pull - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 21:36:45 INFO - install - Wall time: 3s; CPU: 9.0%; Read bytes: 0; Write bytes: 184049664; Read time: 0; Write time: 97150 21:36:45 INFO - run-tests - Wall time: 1817s; CPU: 9.0%; Read bytes: 73790976; Write bytes: 2414353408; Read time: 314250; Write time: 5158630 21:36:45 INFO - Running post-run listener: _upload_blobber_files 21:36:45 WARNING - Blob upload gear skipped. Missing cmdline options. 21:36:45 INFO - Running post-run listener: copy_logs_to_upload_dir 21:36:45 INFO - Copying logs to upload dir... 21:36:45 INFO - mkdir: Z:\task_1512766457\build\upload\logs 21:36:45 INFO - Copying logs to upload dir... 21:36:45 INFO - Using _rmtree_windows ... 21:36:45 INFO - Running command: del /F /Q "Z:\task_1512766457\build\upload\logs\localconfig.json" 21:36:45 INFO - Return code: 0 21:36:45 INFO - Using _rmtree_windows ... 21:36:45 INFO - Running command: del /F /Q "Z:\task_1512766457\build\upload\logs\log_info.log" 21:36:45 INFO - Return code: 0 21:36:45 INFO - Using _rmtree_windows ... 21:36:45 INFO - Running command: del /F /Q "Z:\task_1512766457\build\upload\logs\log_raw.log" 21:36:45 INFO - Return code: 0 21:36:45 INFO - Using _rmtree_windows ... 21:36:45 INFO - Running command: del /F /Q "Z:\task_1512766457\build\upload\logs\log_warning.log" 21:36:45 INFO - Return code: 0 21:36:45 INFO - Using _rmtree_windows ... 21:36:45 INFO - Running command: del /F /Q "Z:\task_1512766457\build\upload\logs\log_critical.log" 21:36:45 INFO - Return code: 0 21:36:45 INFO - Using _rmtree_windows ... 21:36:45 INFO - Running command: del /F /Q "Z:\task_1512766457\build\upload\logs\log_error.log" 21:36:45 INFO - Return code: 0 21:36:45 INFO - Using _rmtree_windows ... 21:36:45 INFO - Running command: del /F /Q "Z:\task_1512766457\build\upload\logs\log_fatal.log" 21:36:45 INFO - Return code: 0 21:36:45 WARNING - returning nonzero exit status 2 [taskcluster 2017-12-08T21:36:45.776Z] Exit Code: 2 [taskcluster 2017-12-08T21:36:45.777Z] User Time: 0s [taskcluster 2017-12-08T21:36:45.777Z] Kernel Time: 0s [taskcluster 2017-12-08T21:36:45.777Z] Wall Time: 35m49.693s [taskcluster 2017-12-08T21:36:45.777Z] Peak Memory: 2273280 [taskcluster 2017-12-08T21:36:45.777Z] Result: FAILED [taskcluster 2017-12-08T21:36:45.777Z] === Task Finished === [taskcluster 2017-12-08T21:36:45.777Z] Task Duration: 35m49.706s

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=193410581&repo=mozilla-inbound&lineNumber=22588 21:39:53 INFO - TEST-START | /streams/readable-streams/tee.sharedworker.html 21:39:53 INFO - Setting pref javascript.options.streams (true) 21:39:53 INFO - PID 2642 | ++DOCSHELL 0x1185a9800 == 2 [pid = 2645] [id = {2cbd7441-464d-034f-a3b6-895ab1e41423}] 21:39:53 INFO - PID 2642 | ++DOMWINDOW == 5 (0x118507c00) [pid = 2645] [serial = 5] [outer = 0x0] 21:39:53 INFO - PID 2642 | ++DOMWINDOW == 6 (0x117bec000) [pid = 2645] [serial = 6] [outer = 0x118507c00] 21:39:53 INFO - PID 2642 | 1533962393862 Marionette DEBUG [2147483653] Frame script loaded 21:39:53 INFO - PID 2642 | 1533962393885 Marionette DEBUG [2147483653] Frame script registered 21:39:53 INFO - PID 2642 | ++DOMWINDOW == 7 (0x1185e3400) [pid = 2645] [serial = 7] [outer = 0x118507c00] 21:39:54 INFO - PID 2642 | ++DOCSHELL 0x11980c800 == 3 [pid = 2645] [id = {2fe61950-82a5-5543-a35c-bff53b70aaca}] 21:39:54 INFO - PID 2642 | ++DOMWINDOW == 8 (0x118509c00) [pid = 2645] [serial = 8] [outer = 0x0] 21:39:54 INFO - PID 2642 | ++DOMWINDOW == 9 (0x1185e5c00) [pid = 2645] [serial = 9] [outer = 0x118509c00] 21:39:54 INFO - PID 2642 | 1533962394026 Marionette DEBUG [2147483656] Frame script loaded 21:39:54 INFO - PID 2642 | 1533962394047 Marionette DEBUG [2147483656] Frame script registered 21:39:54 INFO - PID 2642 | ++DOMWINDOW == 10 (0x1185e9000) [pid = 2645] [serial = 10] [outer = 0x118509c00] 21:39:54 INFO - PID 2642 | [Child 2645, Main Thread] WARNING: NS_ENSURE_TRUE(!(err)) failed: file /builds/worker/workspace/build/src/toolkit/xre/nsXREDirProvider.cpp, line 1394 21:39:54 INFO - PID 2642 | [Child 2645, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/worker/workspace/build/src/toolkit/xre/nsXREDirProvider.cpp, line 1529 21:39:55 INFO - PID 2642 | Assertion failure: stream->readable(), at /builds/worker/workspace/build/src/js/src/builtin/Stream.cpp:2929 21:39:55 INFO - PID 2642 | ###!!! [Parent][MessageChannel] Error: (msgtype=0x17007C,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 21:39:55 INFO - PID 2642 | ###!!! [Parent][MessageChannel] Error: (msgtype=0x17007C,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 21:39:55 INFO - PID 2642 | ###!!! [Parent][MessageChannel] Error: (msgtype=0x17007C,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 21:39:55 INFO - PID 2642 | ++DOCSHELL 0x12ad54800 == 6 [pid = 2642] [id = {1bb6665b-b871-3b4e-8de7-cc079f5855ea}] 21:39:55 INFO - PID 2642 | ++DOMWINDOW == 13 (0x12a17c600) [pid = 2642] [serial = 13] [outer = 0x0] 21:39:55 INFO - PID 2642 | ++DOMWINDOW == 14 (0x12b5e3000) [pid = 2642] [serial = 14] [outer = 0x12a17c600] 21:39:55 INFO - PID 2642 | ++DOCSHELL 0x12b83f800 == 7 [pid = 2642] [id = {6b639759-c08c-8045-91d2-6dd7f914617b}] 21:39:55 INFO - PID 2642 | ++DOMWINDOW == 15 (0x131709200) [pid = 2642] [serial = 15] [outer = 0x0] 21:39:55 INFO - PID 2642 | ++DOMWINDOW == 16 (0x131726000) [pid = 2642] [serial = 16] [outer = 0x131709200] 21:39:55 INFO - PID 2642 | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down 21:39:55 INFO - PID 2642 | ++DOMWINDOW == 17 (0x12ba10c00) [pid = 2642] [serial = 17] [outer = 0x12a17c600] 21:39:55 INFO - PID 2642 | ++DOMWINDOW == 18 (0x11e021400) [pid = 2642] [serial = 18] [outer = 0x131709200] 21:39:55 INFO - PID 2642 | [Child 2646, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/workspace/build/src/widget/cocoa/nsAppShell.mm, line 758 21:39:55 INFO - PID 2642 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost 21:39:55 INFO - PID 2642 | [Child 2646, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp, line 934 21:39:55 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/bapN1Ga3Rm-dKEytDIIIHw/artifacts/public/build/target.crashreporter-symbols.zip

Bug 1385890 seems to have fixed this. Hasn't happened in the past month.