Closed Bug 1446622 Opened 8 years ago Closed 7 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | devtools/client/debugger/new/test/mochitest/browser_dbg-call-stack.js | application timed out after 370 seconds with no output

Categories

(DevTools :: Debugger, defect, P5)

Product:
DevTools
Component:
Debugger
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=168666458&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/cN5K6zEsRRChHLsr_epxdQ/runs/0/artifacts/public/logs/live_backing.log 04:32:00 INFO - GECKO(1476) | [ACTION] ADD_SOURCES - {"type":"ADD_SOURCES","sources":[{"url":"webpack:///webpack/bootstrap c097356c0822da643365","id":"server1.conn10.content-process1/source171/originalSource-128fbce10ef7c9cf326cd514d2045aa3","isPrettyPrinted":false,"isWasm":false,"isBlackBoxed":false,"loadedState":"unloaded"},{"url":"webpack:///fixtures/webpack-standalone/input.js","id":"server1.conn10.content-process1/source171/originalSource-1108c80d32bffefd248c5a24210375e9","isPrettyPrinted":false,"isWasm":false,"isBlackBoxed":false,"loadedState":"unloaded"},{"url":"webpack:///fixtures/webpack-standalone/src/mod1.js","id":"server1.conn10.content-process1/source171/originalSource-311798e685eda63d68c6c8be7645b25a","isPrettyPrinted":false,"isWasm":false,"isBlackBoxed":false,"loadedState":"unloaded"}]} 04:32:00 INFO - GECKO(1476) | [ACTION] ENABLE_BREAKPOINT [done] - {"type":"ENABLE_BREAKPOINT","breakpoint":{"id":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/simple2.js:3:","disabled":true,"hidden":false,"loading":false,"condition":null,"location":{"sourceId":"server1.conn10.content-process1/source181","line":3,"sourceUrl":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/simple2.js"},"astLocation":{"name":"bar","offset":{"line":1}},"generatedLocation":{"sourceId":"server1.conn10.content-process1/source181","line":3,"sourceUrl":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/simple2.js"}},"seqId":"3","status":"done","value":{"breakpoint":{"id":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/simple2.js:3:","disabled":false,"hidden":false,"loading":false,"condition":null,"location":{"sourceId":"server1.conn10.content-process1/source181","line":3,"sourceUrl":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/simple2.js"},"astLocation":{"name":"bar","offset":{"line":1}},"generatedLocation":{"sourceId":"server1.conn10.content-process1/source181","line":3,"sourceUrl":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/simple2.js"}},"previousLocation":null}} 04:32:00 INFO - GECKO(1476) | [ACTION] UPDATE_SOURCE - {"type":"UPDATE_SOURCE","source":{"url":"webpack:///webpack/bootstrap ffb963fac42d81060378","id":"server1.conn10.content-process1/source158/originalSource-69f77c4131865b2f8dd46ccdd94eb5ef","isPrettyPrinted":false,"isWasm":false,"isBlackBoxed":false,"loadedState":"unloaded","sourceMapURL":""}} 04:32:00 INFO - GECKO(1476) | MEMORY STAT | vsize 905MB | vsizeMaxContiguous 600MB | residentFast 401MB | heapAllocated 185MB 04:32:00 INFO - 33 INFO TEST-OK | devtools/client/debugger/new/test/mochitest/browser_dbg-browser-content-toolbox.js | took 4492ms 04:32:00 INFO - 34 INFO checking window state 04:32:01 INFO - 35 INFO TEST-START | devtools/client/debugger/new/test/mochitest/browser_dbg-call-stack.js 04:38:11 INFO - Buffered messages logged at 04:32:01 04:38:11 INFO - 36 INFO Entering test bound 04:38:11 INFO - 37 INFO Adding a new tab with URL: http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/doc-script-switching.html 04:38:11 INFO - Buffered messages finished 04:38:11 WARNING - TEST-UNEXPECTED-TIMEOUT | devtools/client/debugger/new/test/mochitest/browser_dbg-call-stack.js | application timed out after 370 seconds with no output 04:38:11 INFO - 38 ERROR Force-terminating active process(es). 04:38:11 INFO - Determining child pids from psutil... 04:38:11 INFO - [1316, 1460, 1620, 3560] 04:38:11 INFO - ==> process 1476 launched child process 1460 ("Z:\task_1521258805\build\application\firefox\firefox.exe" -contentproc --channel="1476.0.751449889\1253284591" -childID 1 -isForBrowser -prefsHandle 1736 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521258805\build\application\firefox\omni.ja" -appomni "Z:\task_1521258805\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521258805\build\application\firefox\browser" 1476 "\\.\pipe\gecko-crash-server-pipe.1476" 1908 tab) 04:38:11 INFO - ==> process 1476 launched child process 1316 ("Z:\task_1521258805\build\application\firefox\firefox.exe" -contentproc --channel="1476.6.1350933237\1386165526" -childID 2 -isForBrowser -prefsHandle 2184 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521258805\build\application\firefox\omni.ja" -appomni "Z:\task_1521258805\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521258805\build\application\firefox\browser" 1476 "\\.\pipe\gecko-crash-server-pipe.1476" 2196 tab) 04:38:11 INFO - ==> process 1476 launched child process 1620 ("Z:\task_1521258805\build\application\firefox\firefox.exe" -contentproc --channel="1476.12.960934851\118141452" -childID 3 -isForBrowser -prefsHandle 2480 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521258805\build\application\firefox\omni.ja" -appomni "Z:\task_1521258805\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521258805\build\application\firefox\browser" 1476 "\\.\pipe\gecko-crash-server-pipe.1476" 2884 tab) 04:38:11 INFO - ==> process 1476 launched child process 3560 ("Z:\task_1521258805\build\application\firefox\firefox.exe" -contentproc --channel="1476.18.2051360808\686449741" -childID 4 -isForBrowser -prefsHandle 3156 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521258805\build\application\firefox\omni.ja" -appomni "Z:\task_1521258805\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521258805\build\application\firefox\browser" 1476 "\\.\pipe\gecko-crash-server-pipe.1476" 3148 tab) 04:38:11 INFO - Found child pids: set([1620, 1460, 1316, 3560]) 04:38:11 INFO - Killing process: 1620 04:38:11 INFO - TEST-INFO | started process screenshot 04:38:11 INFO - TEST-INFO | screenshot: exit 0 04:38:11 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 1620: error 5 04:38:11 INFO - Killing process: 1460 04:38:11 INFO - Not taking screenshot here: see the one that was previously logged 04:38:11 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 1460: error 5 04:38:11 INFO - Killing process: 1316 04:38:11 INFO - Not taking screenshot here: see the one that was previously logged 04:38:11 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 1316: error 5 04:38:11 INFO - Killing process: 3560 04:38:11 INFO - Not taking screenshot here: see the one that was previously logged 04:38:11 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 3560: error 5 04:38:11 INFO - psutil found pid 1620 dead 04:38:11 INFO - psutil found pid 3560 dead 04:38:11 INFO - psutil found pid 1460 dead 04:38:11 INFO - psutil found pid 1316 dead 04:38:11 INFO - Killing process: 1476 04:38:11 INFO - Not taking screenshot here: see the one that was previously logged 04:38:11 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 1476: error 5 04:38:11 INFO - psutil found pid 1476 dead 04:38:11 INFO - TEST-INFO | Main app process: exit 1 04:38:11 INFO - Buffered messages finished 04:38:11 ERROR - 39 ERROR TEST-UNEXPECTED-FAIL | devtools/client/debugger/new/test/mochitest/browser_dbg-call-stack.js | application terminated with exit code 1 04:38:11 INFO - runtests.py | Application ran for: 0:07:12.830000 04:38:11 INFO - zombiecheck | Reading PID log: c:\users\genericworker\appdata\local\temp\tmptoqwaspidlog 04:38:11 INFO - ==> process 1476 launched child process 1460 ("Z:\task_1521258805\build\application\firefox\firefox.exe" -contentproc --channel="1476.0.751449889\1253284591" -childID 1 -isForBrowser -prefsHandle 1736 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521258805\build\application\firefox\omni.ja" -appomni "Z:\task_1521258805\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521258805\build\application\firefox\browser" 1476 "\\.\pipe\gecko-crash-server-pipe.1476" 1908 tab) 04:38:11 INFO - ==> process 1476 launched child process 1316 ("Z:\task_1521258805\build\application\firefox\firefox.exe" -contentproc --channel="1476.6.1350933237\1386165526" -childID 2 -isForBrowser -prefsHandle 2184 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521258805\build\application\firefox\omni.ja" -appomni "Z:\task_1521258805\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521258805\build\application\firefox\browser" 1476 "\\.\pipe\gecko-crash-server-pipe.1476" 2196 tab) 04:38:11 INFO - ==> process 1476 launched child process 1620 ("Z:\task_1521258805\build\application\firefox\firefox.exe" -contentproc --channel="1476.12.960934851\118141452" -childID 3 -isForBrowser -prefsHandle 2480 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521258805\build\application\firefox\omni.ja" -appomni "Z:\task_1521258805\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521258805\build\application\firefox\browser" 1476 "\\.\pipe\gecko-crash-server-pipe.1476" 2884 tab) 04:38:11 INFO - ==> process 1476 launched child process 3560 ("Z:\task_1521258805\build\application\firefox\firefox.exe" -contentproc --channel="1476.18.2051360808\686449741" -childID 4 -isForBrowser -prefsHandle 3156 -prefsLen 212 -schedulerPrefs 0001,2 -greomni "Z:\task_1521258805\build\application\firefox\omni.ja" -appomni "Z:\task_1521258805\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521258805\build\application\firefox\browser" 1476 "\\.\pipe\gecko-crash-server-pipe.1476" 3148 tab) 04:38:11 INFO - zombiecheck | Checking for orphan process with PID: 1620 04:38:11 INFO - zombiecheck | Checking for orphan process with PID: 1316 04:38:11 INFO - zombiecheck | Checking for orphan process with PID: 1460 04:38:11 INFO - zombiecheck | Checking for orphan process with PID: 3560 04:38:11 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/E-JJyjuOTju9e61zHxOq0w/artifacts/public/build/target.crashreporter-symbols.zip 04:38:15 INFO - mozcrash Copy/paste: Z:\task_1521258805\build\win32-minidump_stackwalk.exe c:\users\genericworker\appdata\local\temp\tmphtwwuw.mozrunner\minidumps\1025d5b5-30b0-420a-b054-999ca793e820.dmp c:\users\genericworker\appdata\local\temp\tmpz9aqab 04:38:28 INFO - mozcrash Saved minidump as Z:\task_1521258805\build\blobber_upload_dir\1025d5b5-30b0-420a-b054-999ca793e820.dmp 04:38:28 WARNING - PROCESS-CRASH | devtools/client/debugger/new/test/mochitest/browser_dbg-call-stack.js | application crashed [None] 04:38:28 INFO - Crash dump filename: c:\users\genericworker\appdata\local\temp\tmphtwwuw.mozrunner\minidumps\1025d5b5-30b0-420a-b054-999ca793e820.dmp 04:38:28 INFO - Operating system: Windows NT 04:38:28 INFO - 6.1.7601 Service Pack 1 04:38:28 INFO - CPU: x86 04:38:28 INFO - GenuineIntel family 6 model 63 stepping 2 04:38:28 INFO - 8 CPUs 04:38:28 INFO - GPU: UNKNOWN 04:38:28 INFO - No crash 04:38:28 INFO - Process uptime: 430 seconds 04:38:28 INFO - Thread 0 04:38:28 INFO - 0 ntdll.dll!KiFastSystemCallRet + 0x0 04:38:28 INFO - eip = 0x776b70b4 esp = 0x0030f388 ebp = 0x0030f3d0 ebx = 0x0030f3e0 04:38:28 INFO - esi = 0x00000000 edi = 0x00000000 eax = 0x06825000 ecx = 0x0c2d1c98 04:38:28 INFO - edx = 0x0000001c efl = 0x00000247 04:38:28 INFO - Found by: given as instruction pointer in context 04:38:28 INFO - 1 ntdll.dll!ZwWaitForKeyedEvent + 0xc 04:38:28 INFO - eip = 0x776b69f4 esp = 0x0030f38c ebp = 0x0030f3d0 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 2 ntdll.dll!RtlSleepConditionVariableCS + 0xac 04:38:28 INFO - eip = 0x7767669b esp = 0x0030f390 ebp = 0x0030f3d0 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 3 kernel32.dll!SleepConditionVariableCS + 0x21 04:38:28 INFO - eip = 0x765b18df esp = 0x0030f3d8 ebp = 0x0030f400 04:38:28 INFO - Found by: previous frame's frame pointer 04:38:28 INFO - 4 mozglue.dll!mozilla::detail::ConditionVariableImpl::wait(mozilla::detail::MutexImpl &) [ConditionVariable_windows.cpp:3ab4dce21458246a48ebd65839d1563781427a1c : 58 + 0xa] 04:38:28 INFO - eip = 0x6733a998 esp = 0x0030f408 ebp = 0x0030f418 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 5 xul.dll!mozilla::CondVar::Wait(unsigned int) [CondVar.h:3ab4dce21458246a48ebd65839d1563781427a1c : 68 + 0xb] 04:38:28 INFO - eip = 0x5c781d4d esp = 0x0030f420 ebp = 0x0030f434 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 6 xul.dll!mozilla::ThreadEventQueue<mozilla::PrioritizedEventQueue<mozilla::LabeledEventQueue> >::GetEvent(bool,mozilla::EventPriority *) [ThreadEventQueue.cpp:3ab4dce21458246a48ebd65839d1563781427a1c : 155 + 0xa] 04:38:28 INFO - eip = 0x5c787032 esp = 0x0030f43c ebp = 0x0030f454 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 7 xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:3ab4dce21458246a48ebd65839d1563781427a1c : 999 + 0x1b] 04:38:28 INFO - eip = 0x5c788dc4 esp = 0x0030f45c ebp = 0x0030fa70 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 8 KERNELBASE.dll!GetLongPathNameW + 0x384 04:38:28 INFO - eip = 0x7585a0f7 esp = 0x0030f480 ebp = 0x0030fc28 04:38:28 INFO - Found by: stack scanning 04:38:28 INFO - 9 0x3 04:38:28 INFO - eip = 0x00000003 esp = 0x0030fc30 ebp = 0x5ed2337c 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 10 dbghelp.dll!GenExecuteIncludeThreadCallback(_MINIDUMP_STATE *,unsigned long,unsigned long *) + 0x67 04:38:28 INFO - eip = 0x68435f6f esp = 0x0030fc90 ebp = 0x5ed2337c 04:38:28 INFO - Found by: stack scanning 04:38:28 INFO - 11 mozglue.dll!static void arena_dalloc(void *, unsigned int, struct arena_t *) [mozjemalloc.cpp:3ab4dce21458246a48ebd65839d1563781427a1c : 3509 + 0x7] 04:38:28 INFO - eip = 0x67338863 esp = 0x0030fce4 ebp = 0x5ed2337c 04:38:28 INFO - Found by: stack scanning 04:38:28 INFO - 12 xul.dll!mozilla::BootstrapImpl::XRE_InitChildProcess(int,char * * const,XREChildData const *) [Bootstrap.cpp:3ab4dce21458246a48ebd65839d1563781427a1c : 69 + 0xe] 04:38:28 INFO - eip = 0x5e7269a4 esp = 0x0030fcf8 ebp = 0x0030fd04 04:38:28 INFO - Found by: stack scanning 04:38:28 INFO - 13 firefox.exe!content_process_main(mozilla::Bootstrap *,int,char * * const) [plugin-container.cpp:3ab4dce21458246a48ebd65839d1563781427a1c : 50 + 0x4] 04:38:28 INFO - eip = 0x008515ca esp = 0x0030fd0c ebp = 0x0030fd30 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 14 firefox.exe!NS_internal_main(int,char * *,char * *) [nsBrowserApp.cpp:3ab4dce21458246a48ebd65839d1563781427a1c : 280 + 0xf] 04:38:28 INFO - eip = 0x00851347 esp = 0x0030fd38 ebp = 0x0030fd6c 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 15 firefox.exe!wmain [nsWindowsWMain.cpp:3ab4dce21458246a48ebd65839d1563781427a1c : 129 + 0xf] 04:38:28 INFO - eip = 0x00851ad8 esp = 0x0030fd74 ebp = 0x0030fdac 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 16 firefox.exe!static int __scrt_common_main_seh() [exe_common.inl : 283 + 0x1c] 04:38:28 INFO - eip = 0x008705ab esp = 0x0030fdb4 ebp = 0x0030fdf4 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 17 kernel32.dll!BaseThreadInitThunk + 0x12 04:38:28 INFO - eip = 0x765d3c45 esp = 0x0030fdfc ebp = 0x0030fe00 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 18 ntdll.dll!__RtlUserThreadStart + 0x27 04:38:28 INFO - eip = 0x776d37f5 esp = 0x0030fe08 ebp = 0x0030fe40 04:38:28 INFO - Found by: call frame info 04:38:28 INFO - 19 ntdll.dll!_RtlUserThreadStart + 0x1b 04:38:28 INFO - eip = 0x776d37c8 esp = 0x0030fe48 ebp = 0x0030fe58 04:38:28 INFO - Found by: call frame info
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Product: Firefox → DevTools

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

Status: REOPENED → RESOLVED
Closed: 7 years ago → 7 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.