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

Status: RESOLVED INCOMPLETE

(DevTools :: Debugger, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ccoroiu [at] mozilla.com

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

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

21:33:33     INFO -  71 INFO TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-browser-content-toolbox.js | Debugger context is available -
21:33:33     INFO -  72 INFO Create a breakpoint
21:33:33     INFO -  73 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xmlns." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  74 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xmlns." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  75 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xmlns." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  76 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xmlns." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  77 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xlink." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  78 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xlink." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  79 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xmlns." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  80 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xmlns." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  81 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xmlns." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  82 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xlink." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  83 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xlink." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  84 INFO Console message: [JavaScript Warning: "Removed unsafe attribute. Element: svg. Attribute: xmlns." {file: "resource://devtools/shared/base-loader.js -> resource://devtools/client/shared/vendor/react-dom.js" line: 11623}]
21:33:33     INFO -  Buffered messages logged at 21:27:22
21:33:33     INFO -  85 INFO Waiting for state change: selected source
21:33:33     INFO -  86 INFO Finished waiting for state change: selected source
21:33:33     INFO -  87 INFO Waiting for ADD_BREAKPOINT to dispatch 1 time(s)
21:33:33     INFO -  88 INFO ADD_BREAKPOINT dispatched 1 time(s)
21:33:33     INFO -  89 INFO Disable the breakpoint
21:33:33     INFO -  90 INFO Waiting for DISABLE_BREAKPOINT to dispatch 1 time(s)
21:33:33     INFO -  91 INFO DISABLE_BREAKPOINT dispatched 1 time(s)
21:33:33     INFO -  92 INFO TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-browser-content-toolbox.js | breakpoint is disabled -
21:33:33     INFO -  93 INFO Enable the breakpoint
21:33:33     INFO -  94 INFO Waiting for ENABLE_BREAKPOINT to dispatch 1 time(s)
21:33:33     INFO -  95 INFO ENABLE_BREAKPOINT dispatched 1 time(s)
21:33:33     INFO -  96 INFO TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-browser-content-toolbox.js | breakpoint is enabled -
21:33:33     INFO -  97 INFO Close the browser toolbox window
21:33:33     INFO -  Buffered messages logged at 21:27:23
21:33:33     INFO -  98 INFO Toolbox is destroyed
21:33:33     INFO -  99 INFO Leaving test bound
21:33:33     INFO -  Buffered messages finished
21:33:33  WARNING -  TEST-UNEXPECTED-TIMEOUT | devtools/client/debugger/new/test/mochitest/browser_dbg-browser-content-toolbox.js | application timed out after 370 seconds with no output
21:33:33     INFO -  100 ERROR Force-terminating active process(es).
21:33:33     INFO -  Determining child pids from psutil...
21:33:33     INFO -  [3092, 2880, 2748, 3388]
21:33:33     INFO -  ==> process 524 launched child process 2880 ("Z:\task_1521665654\build\application\firefox\firefox.exe" -contentproc --channel="524.0.1154829392\2028161189" -childID 1 -isForBrowser -prefsHandle 1688 -prefsLen 16587 -schedulerPrefs 0001,2 -greomni "Z:\task_1521665654\build\application\firefox\omni.ja" -appomni "Z:\task_1521665654\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521665654\build\application\firefox\browser"  524 "\\.\pipe\gecko-crash-server-pipe.524" 1888 tab)
21:33:33     INFO -  ==> process 524 launched child process 3092 ("Z:\task_1521665654\build\application\firefox\firefox.exe" -contentproc --channel="524.6.552304331\1331997468" -childID 2 -isForBrowser -prefsHandle 2184 -prefsLen 16587 -schedulerPrefs 0001,2 -greomni "Z:\task_1521665654\build\application\firefox\omni.ja" -appomni "Z:\task_1521665654\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521665654\build\application\firefox\browser"  524 "\\.\pipe\gecko-crash-server-pipe.524" 2196 tab)
21:33:33     INFO -  ==> process 524 launched child process 3388 ("Z:\task_1521665654\build\application\firefox\firefox.exe" -contentproc --channel="524.12.1755270398\710464660" -childID 3 -isForBrowser -prefsHandle 2360 -prefsLen 22249 -schedulerPrefs 0001,2 -greomni "Z:\task_1521665654\build\application\firefox\omni.ja" -appomni "Z:\task_1521665654\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521665654\build\application\firefox\browser"  524 "\\.\pipe\gecko-crash-server-pipe.524" 2872 tab)
21:33:33     INFO -  ==> process 524 launched child process 2748 ("Z:\task_1521665654\build\application\firefox\firefox.exe" -contentproc --channel="524.18.96977228\322488986" -childID 4 -isForBrowser -prefsHandle 3348 -prefsLen 22488 -schedulerPrefs 0001,2 -greomni "Z:\task_1521665654\build\application\firefox\omni.ja" -appomni "Z:\task_1521665654\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521665654\build\application\firefox\browser"  524 "\\.\pipe\gecko-crash-server-pipe.524" 3360 tab)
21:33:33     INFO -  Found child pids: set([2880, 2748, 3092, 3388])
21:33:33     INFO -  Killing process: 2880
21:33:33     INFO -  TEST-INFO | started process screenshot
21:33:33     INFO -  TEST-INFO | screenshot: exit 0
21:33:33     INFO -  mozcrash kill_pid(): wait failed (-1) terminating pid 2880: error 5
21:33:33     INFO -  Killing process: 2748
21:33:33     INFO -  Not taking screenshot here: see the one that was previously logged
21:33:33     INFO -  mozcrash kill_pid(): wait failed (-1) terminating pid 2748: error 5
21:33:33     INFO -  Killing process: 3092
21:33:33     INFO -  Not taking screenshot here: see the one that was previously logged
21:33:33     INFO -  mozcrash kill_pid(): wait failed (-1) terminating pid 3092: error 5
21:33:33     INFO -  Killing process: 3388
21:33:33     INFO -  Not taking screenshot here: see the one that was previously logged
21:33:33     INFO -  mozcrash kill_pid(): wait failed (-1) terminating pid 3388: error 5
21:33:33     INFO -  psutil found pid 2748 dead
21:33:33     INFO -  psutil found pid 3092 dead
21:33:33     INFO -  psutil found pid 3388 dead
21:33:33     INFO -  psutil found pid 2880 dead
21:33:33     INFO -  Killing process: 524
21:33:33     INFO -  Not taking screenshot here: see the one that was previously logged
21:33:33     INFO -  mozcrash kill_pid(): wait failed (-1) terminating pid 524: error 5
21:33:33     INFO -  psutil found pid 524 dead
21:33:33     INFO -  TEST-INFO | Main app process: exit 1
21:33:33     INFO -  Buffered messages finished
21:33:33    ERROR -  101 ERROR TEST-UNEXPECTED-FAIL | devtools/client/debugger/new/test/mochitest/browser_dbg-browser-content-toolbox.js | application terminated with exit code 1
21:33:33     INFO -  runtests.py | Application ran for: 0:07:11.874000
21:33:33     INFO -  zombiecheck | Reading PID log: c:\users\genericworker\appdata\local\temp\tmpzdjayqpidlog
21:33:33     INFO -  ==> process 524 launched child process 2880 ("Z:\task_1521665654\build\application\firefox\firefox.exe" -contentproc --channel="524.0.1154829392\2028161189" -childID 1 -isForBrowser -prefsHandle 1688 -prefsLen 16587 -schedulerPrefs 0001,2 -greomni "Z:\task_1521665654\build\application\firefox\omni.ja" -appomni "Z:\task_1521665654\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521665654\build\application\firefox\browser"  524 "\\.\pipe\gecko-crash-server-pipe.524" 1888 tab)
21:33:33     INFO -  ==> process 524 launched child process 3092 ("Z:\task_1521665654\build\application\firefox\firefox.exe" -contentproc --channel="524.6.552304331\1331997468" -childID 2 -isForBrowser -prefsHandle 2184 -prefsLen 16587 -schedulerPrefs 0001,2 -greomni "Z:\task_1521665654\build\application\firefox\omni.ja" -appomni "Z:\task_1521665654\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521665654\build\application\firefox\browser"  524 "\\.\pipe\gecko-crash-server-pipe.524" 2196 tab)
21:33:33     INFO -  ==> process 524 launched child process 3388 ("Z:\task_1521665654\build\application\firefox\firefox.exe" -contentproc --channel="524.12.1755270398\710464660" -childID 3 -isForBrowser -prefsHandle 2360 -prefsLen 22249 -schedulerPrefs 0001,2 -greomni "Z:\task_1521665654\build\application\firefox\omni.ja" -appomni "Z:\task_1521665654\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521665654\build\application\firefox\browser"  524 "\\.\pipe\gecko-crash-server-pipe.524" 2872 tab)
21:33:33     INFO -  ==> process 524 launched child process 2748 ("Z:\task_1521665654\build\application\firefox\firefox.exe" -contentproc --channel="524.18.96977228\322488986" -childID 4 -isForBrowser -prefsHandle 3348 -prefsLen 22488 -schedulerPrefs 0001,2 -greomni "Z:\task_1521665654\build\application\firefox\omni.ja" -appomni "Z:\task_1521665654\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1521665654\build\application\firefox\browser"  524 "\\.\pipe\gecko-crash-server-pipe.524" 3360 tab)
21:33:33     INFO -  zombiecheck | Checking for orphan process with PID: 2880
21:33:33     INFO -  zombiecheck | Checking for orphan process with PID: 3388
21:33:33     INFO -  zombiecheck | Checking for orphan process with PID: 2748
21:33:33     INFO -  zombiecheck | Checking for orphan process with PID: 3092
21:33:33     INFO -  mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/eo8aMEgNQz2XTkddSU9n_g/artifacts/public/build/target.crashreporter-symbols.zip
21:33:38     INFO -  mozcrash Copy/paste: Z:\task_1521665654\build\win32-minidump_stackwalk.exe c:\users\genericworker\appdata\local\temp\tmphtbtgq.mozrunner\minidumps\1788eca7-ffc6-470a-a3bb-44cf25ffb3e4.dmp c:\users\genericworker\appdata\local\temp\tmpj5cq86
21:33:45     INFO -  mozcrash Saved minidump as Z:\task_1521665654\build\blobber_upload_dir\1788eca7-ffc6-470a-a3bb-44cf25ffb3e4.dmp
21:33:45  WARNING -  PROCESS-CRASH | devtools/client/debugger/new/test/mochitest/browser_dbg-browser-content-toolbox.js | application crashed [None]
21:33:45     INFO -  Crash dump filename: c:\users\genericworker\appdata\local\temp\tmphtbtgq.mozrunner\minidumps\1788eca7-ffc6-470a-a3bb-44cf25ffb3e4.dmp
21:33:45     INFO -  Operating system: Windows NT
21:33:45     INFO -                    6.1.7601 Service Pack 1
21:33:45     INFO -  CPU: x86
21:33:45     INFO -       GenuineIntel family 6 model 63 stepping 2
21:33:45     INFO -       8 CPUs
21:33:45     INFO -  GPU: UNKNOWN
21:33:45     INFO -  No crash
21:33:45     INFO -  Process uptime: 427 seconds
21:33:45     INFO -  Thread 0
21:33:45     INFO -   0  ntdll.dll!KiFastSystemCallRet + 0x0
21:33:45     INFO -      eip = 0x775f70b4   esp = 0x0016f268   ebp = 0x0016f2b0   ebx = 0x0016f2b8
21:33:45     INFO -      esi = 0x00000000   edi = 0x00000000   eax = 0x0b4e1000   ecx = 0x0d1151f8
21:33:45     INFO -      edx = 0x0000001c   efl = 0x00000247
21:33:45     INFO -      Found by: given as instruction pointer in context

Comment 1

[Intermittent Failures Robot]

19 failures in 822 pushes (0.023 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 10
* mozilla-central: 5
* mozilla-inbound: 3
* try: 1

Platform breakdown:
* windows7-32: 14
* windows10-64: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1447846&startday=2018-03-20&endday=2018-03-26&tree=trunk

Comment 2

[Intermittent Failures Robot]

11 failures in 718 pushes (0.015 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 7
* mozilla-inbound: 4

Platform breakdown:
* windows10-64: 6
* windows7-32: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1447846&startday=2018-03-26&endday=2018-04-01&tree=trunk

Comment 4

[Firefox Bug Husbandry Bot]

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