Closed Bug 1455126 Opened 8 years ago Closed 8 years ago

Intermittent test-oop-extensions/browser_ext_connect_and_move_tabs.js | application crashed [None] after application timed out & application terminated with exit code 1

Categories

(WebExtensions :: General, defect, P5)

Product:
WebExtensions
Component:
General
Type:
defect

Tracking

(Not tracked)

Status:
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=174305154&repo=mozilla-central https://queue.taskcluster.net/v1/task/PZdT4gSWRqWajOAkOasfsA/runs/0/artifacts/public/logs/live_backing.log 12:21:11 INFO - 307 INFO TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_commands_update.js 12:21:12 INFO - GECKO(5788) | 1524054072121 addons.xpi ERROR Attempted to load bootstrap scope from missing directory C:\Users\task_1524053591\AppData\Local\Temp\tmpfygm9d.mozrunner\extensions\commands@mochi.test.xpi 12:21:12 INFO - GECKO(5788) | 1524054072122 addons.xpi WARN Add-on commands@mochi.test is missing bootstrap method shutdown 12:21:12 INFO - GECKO(5788) | 1524054072123 addons.xpi WARN Add-on commands@mochi.test is missing bootstrap method uninstall 12:21:12 INFO - GECKO(5788) | 1524054072124 addons.xpi WARN Attempted to remove commands@mochi.test from app-profile but it was already gone 12:21:12 INFO - GECKO(5788) | MEMORY STAT | vsize 2099060MB | vsizeMaxContiguous 129458165MB | residentFast 352MB | heapAllocated 146MB 12:21:12 INFO - 308 INFO TEST-OK | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_commands_update.js | took 1125ms 12:21:12 INFO - 309 INFO checking window state 12:21:12 INFO - 310 INFO TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js 12:21:32 INFO - GECKO(5788) | [NPAPI 3496, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 12:21:32 INFO - GECKO(5788) | [NPAPI 3496, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 12:27:42 INFO - Buffered messages logged at 12:21:12 12:27:42 INFO - 311 INFO Entering test bound contentscript_connect_and_move_tabs 12:27:42 INFO - 312 INFO Extension loaded 12:27:42 INFO - 313 INFO Console message: Warning: attempting to write 4881 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes. 12:27:42 INFO - 314 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_script, Actual: connect_from_script - 12:27:42 INFO - Buffered messages logged at 12:21:13 12:27:42 INFO - 315 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: ping, Actual: ping - 12:27:42 INFO - 316 INFO Console message: [JavaScript Error: "Promise rejected after context unloaded: Message manager disconnected 12:27:42 INFO - " {file: "moz-extension://e281d2b3-a5f7-44a3-8dc4-a4f18bf751f9/script.js" line: 8}] 12:27:42 INFO - @moz-extension://e281d2b3-a5f7-44a3-8dc4-a4f18bf751f9/script.js:8:13 12:27:42 INFO - 317 INFO Leaving test bound contentscript_connect_and_move_tabs 12:27:42 INFO - 318 INFO Entering test bound extension_tab_connect_and_move_tabs 12:27:42 INFO - 319 INFO Extension loaded 12:27:42 INFO - 320 INFO Console message: Warning: attempting to write 4961 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes. 12:27:42 INFO - 321 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: open_extension_tab, Actual: open_extension_tab - 12:27:42 INFO - Buffered messages logged at 12:21:14 12:27:42 INFO - 322 INFO TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | expected message - Expected: connect_from_script, Actual: connect_from_script - 12:27:42 INFO - Buffered messages finished 12:27:42 WARNING - TEST-UNEXPECTED-TIMEOUT | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | application timed out after 370 seconds with no output 12:27:42 INFO - 323 ERROR Force-terminating active process(es). 12:27:42 INFO - Determining child pids from psutil... 12:27:42 INFO - [8116, 4704, 7708, 3364, 5836, 4496, 3496] 12:27:42 INFO - ==> process 5788 launched child process 7708 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.0.1606581417\679298930" -childID 1 -isForBrowser -prefsHandle 1404 -prefsLen 16424 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 2152 tab) 12:27:42 INFO - ==> process 5788 launched child process 4496 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.6.14870237\1930878756" -childID 2 -isForBrowser -prefsHandle 2508 -prefsLen 16424 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 2492 tab) 12:27:42 INFO - ==> process 5788 launched child process 3364 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.12.479596105\1971724909" -childID 3 -isForBrowser -prefsHandle 2464 -prefsLen 22112 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 3464 tab) 12:27:42 INFO - ==> process 5788 launched child process 4704 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.18.248878640\736610055" -childID 4 -isForBrowser -prefsHandle 3796 -prefsLen 22113 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 3740 tab) 12:27:42 INFO - ==> process 5788 launched child process 8116 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.24.2029215873\949692157" -childID 5 -isForBrowser -prefsHandle 4080 -prefsLen 22167 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 4052 tab) 12:27:42 INFO - ==> process 5788 launched child process 3496 ("Z:\task_1524053591\build\application\firefox\plugin-container.exe" --channel="5788.30.1205369669\175560176" "C:\Users\task_1524053591\AppData\Local\Temp\tmpfygm9d.mozrunner\plugins\nptest.dll" -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 4800 plugin) 12:27:42 INFO - ==> process 5788 launched child process 5836 ("Z:\task_1524053591\build\application\firefox\plugin-container.exe" --channel="5788.34.1466036295\334664687" "C:\Users\task_1524053591\AppData\Local\Temp\tmpfygm9d.mozrunner\plugins\npswftest.dll" -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 5064 plugin) 12:27:42 INFO - Found child pids: set([4704, 3364, 3496, 5836, 4496, 8116, 7708]) 12:27:42 INFO - Killing process: 4704 12:27:42 INFO - TEST-INFO | started process screenshot 12:27:42 INFO - TEST-INFO | screenshot: exit 0 12:27:42 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 4704: error 5 12:27:42 INFO - Killing process: 3364 12:27:42 INFO - Not taking screenshot here: see the one that was previously logged 12:27:42 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 3364: error 5 12:27:42 INFO - Killing process: 3496 12:27:42 INFO - Not taking screenshot here: see the one that was previously logged 12:27:42 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 3496: error 5 12:27:42 INFO - Killing process: 5836 12:27:42 INFO - Not taking screenshot here: see the one that was previously logged 12:27:42 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 5836: error 5 12:27:42 INFO - Killing process: 4496 12:27:42 INFO - Not taking screenshot here: see the one that was previously logged 12:27:42 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 4496: error 5 12:27:42 INFO - Killing process: 8116 12:27:42 INFO - Not taking screenshot here: see the one that was previously logged 12:27:43 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 8116: error 5 12:27:43 INFO - Killing process: 7708 12:27:43 INFO - Not taking screenshot here: see the one that was previously logged 12:27:43 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 7708: error 5 12:27:43 INFO - psutil found pid 3496 dead 12:27:43 INFO - psutil found pid 8116 dead 12:27:43 INFO - psutil found pid 3364 dead 12:27:43 INFO - psutil found pid 5836 dead 12:27:43 INFO - psutil found pid 4704 dead 12:27:43 INFO - psutil found pid 7708 dead 12:27:43 INFO - psutil found pid 4496 dead 12:27:43 INFO - Killing process: 5788 12:27:43 INFO - Not taking screenshot here: see the one that was previously logged 12:27:43 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 5788: error 5 12:27:43 INFO - psutil found pid 5788 dead 12:27:43 INFO - TEST-INFO | Main app process: exit 1 12:27:43 INFO - Buffered messages finished 12:27:43 ERROR - 324 ERROR TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | application terminated with exit code 1 12:27:43 INFO - runtests.py | Application ran for: 0:07:14.838000 12:27:43 INFO - zombiecheck | Reading PID log: c:\users\task_1524053591\appdata\local\temp\tmp3qx56dpidlog 12:27:43 INFO - ==> process 5788 launched child process 7708 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.0.1606581417\679298930" -childID 1 -isForBrowser -prefsHandle 1404 -prefsLen 16424 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 2152 tab) 12:27:43 INFO - ==> process 5788 launched child process 4496 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.6.14870237\1930878756" -childID 2 -isForBrowser -prefsHandle 2508 -prefsLen 16424 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 2492 tab) 12:27:43 INFO - ==> process 5788 launched child process 3364 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.12.479596105\1971724909" -childID 3 -isForBrowser -prefsHandle 2464 -prefsLen 22112 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 3464 tab) 12:27:43 INFO - ==> process 5788 launched child process 4704 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.18.248878640\736610055" -childID 4 -isForBrowser -prefsHandle 3796 -prefsLen 22113 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 3740 tab) 12:27:43 INFO - ==> process 5788 launched child process 8116 ("Z:\task_1524053591\build\application\firefox\firefox.exe" -contentproc --channel="5788.24.2029215873\949692157" -childID 5 -isForBrowser -prefsHandle 4080 -prefsLen 22167 -schedulerPrefs 0001,2 -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 4052 tab) 12:27:43 INFO - ==> process 5788 launched child process 3496 ("Z:\task_1524053591\build\application\firefox\plugin-container.exe" --channel="5788.30.1205369669\175560176" "C:\Users\task_1524053591\AppData\Local\Temp\tmpfygm9d.mozrunner\plugins\nptest.dll" -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 4800 plugin) 12:27:43 INFO - ==> process 5788 launched child process 5836 ("Z:\task_1524053591\build\application\firefox\plugin-container.exe" --channel="5788.34.1466036295\334664687" "C:\Users\task_1524053591\AppData\Local\Temp\tmpfygm9d.mozrunner\plugins\npswftest.dll" -greomni "Z:\task_1524053591\build\application\firefox\omni.ja" -appomni "Z:\task_1524053591\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1524053591\build\application\firefox\browser" - 5788 "\\.\pipe\gecko-crash-server-pipe.5788" 5064 plugin) 12:27:43 INFO - zombiecheck | Checking for orphan process with PID: 4704 12:27:43 INFO - zombiecheck | Checking for orphan process with PID: 3364 12:27:43 INFO - zombiecheck | Checking for orphan process with PID: 3496 12:27:43 INFO - zombiecheck | Checking for orphan process with PID: 5836 12:27:43 INFO - zombiecheck | Checking for orphan process with PID: 4496 12:27:43 INFO - zombiecheck | Checking for orphan process with PID: 8116 12:27:43 INFO - zombiecheck | Checking for orphan process with PID: 7708 12:27:43 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/Jl6XyMmgQy2FTxg6sXC3mg/artifacts/public/build/target.crashreporter-symbols.zip 12:27:47 INFO - mozcrash Copy/paste: Z:\task_1524053591\build\win32-minidump_stackwalk.exe c:\users\task_1524053591\appdata\local\temp\tmpfygm9d.mozrunner\minidumps\50bbbd97-8cf5-402b-aff9-c22154f7e8b8.dmp c:\users\task_1524053591\appdata\local\temp\tmptvaxcr 12:27:52 INFO - mozcrash Saved minidump as Z:\task_1524053591\build\blobber_upload_dir\50bbbd97-8cf5-402b-aff9-c22154f7e8b8.dmp 12:27:52 WARNING - PROCESS-CRASH | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_connect_and_move_tabs.js | application crashed [None] 12:27:52 INFO - Crash dump filename: c:\users\task_1524053591\appdata\local\temp\tmpfygm9d.mozrunner\minidumps\50bbbd97-8cf5-402b-aff9-c22154f7e8b8.dmp 12:27:52 INFO - Operating system: Windows NT 12:27:52 INFO - 10.0.15063 12:27:52 INFO - CPU: amd64 12:27:52 INFO - family 6 model 63 stepping 2 12:27:52 INFO - 8 CPUs 12:27:52 INFO - GPU: UNKNOWN 12:27:52 INFO - No crash 12:27:52 INFO - Process uptime: 430 seconds 12:27:52 INFO - Thread 0 12:27:52 INFO - 0 ntdll.dll!NtWaitForAlertByThreadId + 0x14 12:27:52 INFO - rax = 0x000000000000000a rdx = 0x00000228afbbd960 12:27:52 INFO - rcx = 0x00000228afbbd960 rbx = 0x0000000000000000 12:27:52 INFO - rsi = 0x0000000000000000 rdi = 0x0000000000000000 12:27:52 INFO - rbp = 0x0000003a713ff130 rsp = 0x0000003a713ff0d8 12:27:52 INFO - r8 = 0x00000228ac498488 r9 = 0x00000228ac498480 12:27:52 INFO - r10 = 0x0000000000000000 r11 = 0x0000003a713ff100 12:27:52 INFO - r12 = 0x0000000000000000 r13 = 0x0000003a713ff970 12:27:52 INFO - r14 = 0x00000228a7409370 r15 = 0x00000228a74093a8 12:27:52 INFO - rip = 0x00007fffa4af8be4 12:27:52 INFO - Found by: given as instruction pointer in context 12:27:52 INFO - 1 ntdll.dll!RtlSleepConditionVariableCS + 0xc9 12:27:52 INFO - rbx = 0x0000000000000000 rbp = 0x0000003a713ff130 12:27:52 INFO - rsp = 0x0000003a713ff0e0 r12 = 0x0000000000000000 12:27:52 INFO - r13 = 0x0000003a713ff970 r14 = 0x00000228a7409370 12:27:52 INFO - r15 = 0x00000228a74093a8 rip = 0x00007fffa4ac01b9 12:27:52 INFO - Found by: call frame info 12:27:52 INFO - 2 KERNELBASE.dll!Normalization__LoadTables + 0xfc 12:27:52 INFO - rbx = 0x0000000000000000 rbp = 0x0000003a713ff130 12:27:52 INFO - rsp = 0x0000003a713ff150 r12 = 0x0000000000000000 12:27:52 INFO - r13 = 0x0000003a713ff970 r14 = 0x00000228a7409370 12:27:52 INFO - r15 = 0x00000228a74093a8 rip = 0x00007fffa147e988 12:27:52 INFO - Found by: call frame info 12:27:52 INFO - 3 mozglue.dll!mozilla::detail::ConditionVariableImpl::wait(mozilla::detail::MutexImpl &) [ConditionVariable_windows.cpp:4af4ae0aee552a99a995ce4b32198b98294a95f7 : 58 + 0x10] 12:27:52 INFO - rbx = 0x0000000000000000 rbp = 0x0000003a713ff130 12:27:52 INFO - rsp = 0x0000003a713ff180 r12 = 0x0000000000000000 12:27:52 INFO - r13 = 0x0000003a713ff970 r14 = 0x00000228a7409370 12:27:52 INFO - r15 = 0x00000228a74093a8 rip = 0x00007fff8eadedf1 12:27:52 INFO - Found by: call frame info 12:27:52 INFO - 4 xul.dll!mozilla::ThreadEventQueue<mozilla::PrioritizedEventQueue<mozilla::LabeledEventQueue> >::GetEvent(bool,mozilla::EventPriority *) [ThreadEventQueue.cpp:4af4ae0aee552a99a995ce4b32198b98294a95f7 : 155 + 0x13] 12:27:52 INFO - rbx = 0x0000000000000000 rbp = 0x0000003a713ff130 12:27:52 INFO - rsp = 0x0000003a713ff1b0 r12 = 0x0000000000000000 12:27:52 INFO - r13 = 0x0000003a713ff970 r14 = 0x00000228a7409370 12:27:52 INFO - r15 = 0x00000228a74093a8 rip = 0x00007fff7c026260 12:27:52 INFO - Found by: call frame info 12:27:52 INFO - 5 xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:4af4ae0aee552a99a995ce4b32198b98294a95f7 : 999 + 0x12] 12:27:52 INFO - rbx = 0x0000000000000000 rbp = 0x0000003a713ff130 12:27:52 INFO - rsp = 0x0000003a713ff200 r12 = 0x0000000000000000 12:27:52 INFO - r13 = 0x0000003a713ff970 r14 = 0x00000228a7409370 12:27:52 INFO - r15 = 0x00000228a74093a8 rip = 0x00007fff7c028c1f 12:27:52 INFO - Found by: call frame info
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → INCOMPLETE
Product: Toolkit → WebExtensions
You need to log in before you can comment on or make changes to this bug.