Closed Bug 1427930 Opened 7 years ago Closed 7 years ago

Intermittent talos timeout on startup, "command timed out: 3600 seconds without output, attempting to kill", "timed out after 3600 seconds of no output": g2 timeout on startup

Categories

(Testing :: Talos, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1453007

People

(Reporter: CosminS, Unassigned)

Details

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

+++ This bug was initially created as a clone of Bug #934310 +++ You'll probably find a fair few of these in bug 920161, since we tend to assume without looking that a 3600 second timeout in talos is a clone timeout. https://tbpl.mozilla.org/php/getParsedLog.php?id=30054331&tree=Fx-Team Rev4 MacOSX Lion 10.7 fx-team talos svgr on 2013-11-03 14:47:10 PST for push 1478a4c6fe96 slave: talos-r4-lion-002 14:49:30 INFO - Running test tsvgx: 14:49:30 INFO - Started Sun, 03 Nov 2013 14:49:30 14:49:30 INFO - DEBUG : operating with platform_type : mac_ 14:49:30 INFO - DEBUG : created profile 14:49:30 INFO - DEBUG : command line: /builds/slave/talos-slave/test/build/application/FirefoxNightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/kl/22tr3t1d4f35n34w5z9p3xvr00000w/T/tmpSOgV8Z/profile http://localhost/getInfo.html 14:49:40 INFO - DEBUG : initialized firefox 14:49:40 INFO - DEBUG : command line: /builds/slave/talos-slave/test/build/application/FirefoxNightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/kl/22tr3t1d4f35n34w5z9p3xvr00000w/T/tmpSOgV8Z/profile -tp file:/builds/slave/talos-slave/test/build/venv/lib/python2.7/site-packages/talos/page_load_test/svgx/svgx.manifest -tpchrome -tpnoisy -tpcycles 1 -tppagecycles 25 command timed out: 3600 seconds without output, attempting to kill process killed by signal 9 program finished with exit code -1 elapsedTime=3743.149791 Cloned this since the old bug is marked as fixed and the fails started reappearing in the last few days. New log and treeherder link: https://treeherder.mozilla.org/logviewer.html#?job_id=153983651&repo=mozilla-inbound&lineNumber=1620 https://treeherder.mozilla.org/logviewer.html#?job_id=153983651&repo=mozilla-inbound&lineNumber=1620
No longer blocks: 934967, 1153838
No longer depends on: 934310, 1154434, 1378816
The h1 failures here are bug 1422863. Bug there are 2 g2 timeouts on startup: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=153983651 https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=154503408 17:22:54 INFO - Running cycle 1/5 for damp test... 17:22:54 INFO - Using env: {'ALLUSERSPROFILE': 'C:\\ProgramData', 17:22:54 INFO - 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 17:22:54 INFO - 'COMMONPROGRAMFILES': 'C:\\Program Files (x86)\\Common Files', 17:22:54 INFO - 'COMMONPROGRAMFILES(X86)': 'C:\\Program Files (x86)\\Common Files', 17:22:54 INFO - 'COMMONPROGRAMW6432': 'C:\\Program Files\\Common Files', 17:22:54 INFO - 'COMPUTERNAME': 'T-W1064-IX-151', 17:22:54 INFO - 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 17:22:54 INFO - 'HOMEDRIVE': 'C:', 17:22:54 INFO - 'HOMEPATH': '\\Users\\cltbld', 17:22:54 INFO - 'JSGC_DISABLE_POISONING': '1', 17:22:54 INFO - 'KTS_HOME': 'C:\\Program Files\\KTS', 17:22:54 INFO - 'KTS_VERSION': '1.19c', 17:22:54 INFO - 'LD_LIBRARY_PATH': 'C:\\slave\\test\\build\\application\\firefox', 17:22:54 INFO - 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 17:22:54 INFO - 'LOGONSERVER': '\\\\T-W1064-IX-151', 17:22:54 INFO - 'MINIDUMP_SAVE_PATH': 'C:\\slave\\test\\build\\blobber_upload_dir', 17:22:54 INFO - 'MINIDUMP_STACKWALK': 'C:\\slave\\test\\build\\win32-minidump_stackwalk.exe', 17:22:54 INFO - 'MONDIR': 'C:\\Monitor_config\\', 17:22:54 INFO - 'MOZBUILDDIR': 'C:\\mozilla-build\\', 17:22:54 INFO - 'MOZ_CRASHREPORTER': '1', 17:22:54 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 17:22:54 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 17:22:54 INFO - 'MOZ_NO_REMOTE': '1', 17:22:54 INFO - 'MOZ_UPLOAD_DIR': 'C:\\slave\\test\\build\\blobber_upload_dir', 17:22:54 INFO - 'NO_EM_RESTART': '1', 17:22:54 INFO - 'NUMBER_OF_PROCESSORS': '8', 17:22:54 INFO - 'ONEDRIVE': 'C:\\Users\\cltbld\\OneDrive', 17:22:54 INFO - 'OS': 'Windows_NT', 17:22:54 INFO - 'OURDRIVE': 'C:', 17:22:54 INFO - 'PATH': 'C:\\slave\\test\\build\\venv\\Scripts;C:\\windows\\system32;C:\\windows;C:\\windows\\System32\\Wbem;C:\\windows\\System32\\WindowsPowerShell\\v1.0\\;C:\\Users\\root\\AppData\\Local\\Microsoft\\WindowsApps;;C:\\mozilla-build;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\vim\\vim72;C:\\mozilla-build\\wget;C:\\mozilla-build\\info-zip;C:\\CoreUtils\\bin;C:\\mozilla-build\\buildbotve\\scripts;C:\\Users\\cltbld\\AppData\\Local\\Microsoft\\WindowsApps', 17:22:54 INFO - 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 17:22:54 INFO - 'PROCESSOR_ARCHITECTURE': 'x86', 17:22:54 INFO - 'PROCESSOR_ARCHITEW6432': 'AMD64', 17:22:54 INFO - 'PROCESSOR_IDENTIFIER': 'Intel64 Family 6 Model 30 Stepping 5, GenuineIntel', 17:22:54 INFO - 'PROCESSOR_LEVEL': '6', 17:22:54 INFO - 'PROCESSOR_REVISION': '1e05', 17:22:54 INFO - 'PROGRAMDATA': 'C:\\ProgramData', 17:22:54 INFO - 'PROGRAMFILES': 'C:\\Program Files (x86)', 17:22:54 INFO - 'PROGRAMFILES(X86)': 'C:\\Program Files (x86)', 17:22:54 INFO - 'PROGRAMW6432': 'C:\\Program Files', 17:22:54 INFO - 'PROMPT': '$P$G', 17:22:54 INFO - 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 17:22:54 INFO - 'PSMODULEPATH': '%ProgramFiles%\\WindowsPowerShell\\Modules;C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules', 17:22:54 INFO - 'PUBLIC': 'C:\\Users\\Public', 17:22:54 INFO - 'PWD': 'C:\\slave\\test', 17:22:54 INFO - 'PYTHONPATH': 'C:\\slave\\test\\build\\tests\\talos', 17:22:54 INFO - 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 17:22:54 INFO - 'RUST_BACKTRACE': 'full', 17:22:54 INFO - 'SCRIPTSPATH': 'C:\\slave\\test\\scripts', 17:22:54 INFO - 'SLAVEDIR': 'C:\\slave\\', 17:22:54 INFO - 'SYSTEMDRIVE': 'C:', 17:22:54 INFO - 'SYSTEMROOT': 'C:\\windows', 17:22:54 INFO - 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 17:22:54 INFO - 'TEST1': 'testie', 17:22:54 INFO - 'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 17:22:54 INFO - 'USERDOMAIN': 'T-W1064-IX-151', 17:22:54 INFO - 'USERDOMAIN_ROAMINGPROFILE': 'T-W1064-IX-151', 17:22:54 INFO - 'USERNAME': 'cltbld', 17:22:54 INFO - 'USERPROFILE': 'C:\\Users\\cltbld', 17:22:54 INFO - 'WINDIR': 'C:\\windows', 17:22:54 INFO - 'XPCOM_DEBUG_BREAK': 'warn'} 17:22:54 INFO - TEST-INFO | started process 2848 (C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmplcjhzs\profile) command timed out: 3600 seconds without output, attempting to kill 18:22:54 INFO - Timeout waiting for test completion; killing browser... 18:22:54 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 2848: error 5 Let's use the bug for these.
Summary: Intermittent talos timeout on startup, "command timed out: 3600 seconds without output, attempting to kill", "timed out after 3600 seconds of no output" → Intermittent talos timeout on startup, "command timed out: 3600 seconds without output, attempting to kill", "timed out after 3600 seconds of no output": g2 timeout on startup
There are 38 failures in the past 7 days, all on macosx64-nightly opt. Recent log failure: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=173137745&lineNumber=4101 Relevant part of the log: 11:06:20 INFO - TEST-INFO | started process 1380 (/Users/cltbld/tasks/task_1523468941/build/application/Firefox Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/nk/lkwxjm4s2zbgych5wk8fk3m000000w/T/tmp3i6QvM/profile) 11:06:20 INFO - PID 1380 | Unable to read VR Path Registry from /Users/cltbld/Library/Application Support/OpenVR/.openvr/openvrpaths.vrpath 11:06:21 INFO - PID 1380 | Unable to read VR Path Registry from /Users/cltbld/Library/Application Support/OpenVR/.openvr/openvrpaths.vrpath 11:06:21 INFO - PID 1380 | Unable to read VR Path Registry from /Users/cltbld/Library/Application Support/OpenVR/.openvr/openvrpaths.vrpath 11:06:22 INFO - PID 1380 | 2018-04-11 11:06:22.179 plugin-container[1381:23529] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9743, name = 'com.apple.tsm.portname' 11:06:22 INFO - PID 1380 | See /usr/include/servers/bootstrap_defs.h for the error codes. 11:06:22 INFO - PID 1380 | 2018-04-11 11:06:22.430 plugin-container[1382:23544] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x984b, name = 'com.apple.tsm.portname' 11:06:22 INFO - PID 1380 | See /usr/include/servers/bootstrap_defs.h for the error codes. 11:06:23 INFO - PID 1380 | Unable to read VR Path Registry from /Users/cltbld/Library/Application Support/OpenVR/.openvr/openvrpaths.vrpath 11:06:23 INFO - PID 1380 | 2018-04-11 11:06:23.905 plugin-container[1383:23646] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x932f, name = 'com.apple.tsm.portname' 11:06:23 INFO - PID 1380 | See /usr/include/servers/bootstrap_defs.h for the error codes. 11:06:36 INFO - PID 1380 | 2018-04-11 11:06:36.665 firefox[1380:23460] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.nightly.savedState/window_1.data: No such file or directory (2) 12:06:36 INFO - Automation Error: mozprocess timed out after 3600 seconds running ['/Users/cltbld/tasks/task_1523468941/build/venv/bin/python', '/Users/cltbld/tasks/task_1523468941/build/tests/talos/talos/run_tests.py', '--suite', 'g2-e10s', '--executablePath', '/Users/cltbld/tasks/task_1523468941/build/application/Firefox Nightly.app/Contents/MacOS/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/TGY3178nTCq1Hp98a6eOrQ/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 't-yosemite-r7-278', '--geckoProfile', '--webServer', 'localhost', '--webServer', 'localhost', '--webServer', 'localhost', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/Users/cltbld/tasks/task_1523468941/build/blobber_upload_dir/g2-e10s_errorsummary.log', '--log-raw=/Users/cltbld/tasks/task_1523468941/build/blobber_upload_dir/g2-e10s_raw.log'] 12:06:36 ERROR - timed out after 3600 seconds of no output 12:06:36 ERROR - Return code: -15 12:06:36 WARNING - setting return code to -15 12:06:36 ERROR - # TBPL FAILURE # 12:06:36 WARNING - setting return code to 2 :rwood Can you please take a look here?
Flags: needinfo?(rwood)
Whiteboard: [stockwell unknown] → [stockwell needswork]
Status: NEW → RESOLVED
Closed: 7 years ago
Flags: needinfo?(rwood)
Resolution: --- → DUPLICATE
Whiteboard: [stockwell needswork] → [stockwell disabled]
You need to log in before you can comment on or make changes to this bug.