bug 501034 - add hang detection + breakpad triggering to automation.py. r=Waldo

--HG--
extra : rebase_source : 088eeeb0c3135d1048dca08f3639642a90b2eab2

build/automation-build.mk

@@ -68,6 +68,12 @@ else
 AUTOMATION_PPARGS += -DIS_DEBUG_BUILD=0
 endif
 
+ifdef MOZ_CRASHREPORTER
+AUTOMATION_PPARGS += -DCRASHREPORTER=1
+else
+AUTOMATION_PPARGS += -DCRASHREPORTER=0
+endif
+
 $(CURDIR)/automationutils.py: $(MOZILLA_DIR)/build/automationutils.py
 	$(INSTALL) $< .
 

build/automation.py.in

@@ -43,6 +43,7 @@ import itertools
 import logging
 import os
 import re
+import select
 import shutil
 import signal
 import subprocess
@@ -72,8 +73,12 @@ __all__ = [
            "environment",
            "IS_TEST_BUILD",
            "IS_DEBUG_BUILD",
+           "DEFAULT_TIMEOUT",
           ]
 
+# timeout, in seconds
+DEFAULT_TIMEOUT = 60.0
+
 # These are generated in mozilla/build/Makefile.in
 #expand DIST_BIN = __XPC_BIN_PATH__
 #expand IS_WIN32 = len("__WIN32__") != 0
@@ -94,6 +99,7 @@ UNIXISH = not IS_WIN32 and not IS_MAC
 #expand CERTS_SRC_DIR = __CERTS_SRC_DIR__
 #expand IS_TEST_BUILD = __IS_TEST_BUILD__
 #expand IS_DEBUG_BUILD = __IS_DEBUG_BUILD__
+#expand CRASHREPORTER = __CRASHREPORTER__ == 1
 
 ###########
 # LOGGING #
@@ -434,6 +440,40 @@ def environment(env = None, xrePath = DIST_BIN, crashreporter = True):
   env['GNOME_DISABLE_CRASH_DIALOG'] = "1"
   return env
 
+if IS_WIN32:
+  import ctypes, time, msvcrt
+  PeekNamedPipe = ctypes.windll.kernel32.PeekNamedPipe
+  GetLastError = ctypes.windll.kernel32.GetLastError
+  def readWithTimeout(f, timeout):
+    """Try to read a line of output from the file object |f|.
+    |f| must be a  pipe, like the |stdout| member of a subprocess.Popen
+    object created with stdout=PIPE. If no output
+    is received within |timeout| seconds, return a blank line.
+    Returns a tuple (line, did_timeout), where |did_timeout| is True
+    if the read timed out, and False otherwise."""
+    x = msvcrt.get_osfhandle(f.fileno())
+    l = ctypes.c_long()
+    buf = ctypes.create_string_buffer('', 1024)
+    done = time.time() + timeout
+    while time.time() < done:
+        if PeekNamedPipe(x, buf, len(buf), None, ctypes.byref(l), None) == 0:
+            err = GetLastError()
+            if err == 38 or err == 109: # ERROR_HANDLE_EOF || ERROR_BROKEN_PIPE
+                return ('', False)
+        if (l > 0 and '\n' in buf.value):
+            return (f.readline(), False)
+        time.sleep(0.1)
+    return ('', True)
+else:
+  def readWithTimeout(f, timeout):
+    """Try to read a line of output from the file object |f|. If no output
+    is received within |timeout| seconds, return a blank line.
+    Returns a tuple (line, did_timeout), where |did_timeout| is True
+    if the read timed out, and False otherwise."""
+    (r, w, e) = select.select([f], [], [], timeout)
+    if len(r) == 0:
+      return ('', True)
+    return (f.readline(), False)
 
 ###############
 # RUN THE APP #
@@ -442,7 +482,8 @@ def environment(env = None, xrePath = DIST_BIN, crashreporter = True):
 def runApp(testURL, env, app, profileDir, extraArgs,
            runSSLTunnel = False, utilityPath = DIST_BIN,
            xrePath = DIST_BIN, certPath = CERTS_SRC_DIR,
-           debuggerInfo = None, symbolsPath = None):
+           debuggerInfo = None, symbolsPath = None,
+           timeout = DEFAULT_TIMEOUT):
   "Run the app, log the duration it took to execute, return the status code."
 
   # copy env so we don't munge the caller's environment
@@ -506,6 +547,7 @@ def runApp(testURL, env, app, profileDir, extraArgs,
   log.info("INFO | automation.py | Application pid: %d", proc.pid)
 
   stackFixerProcess = None
+  didTimeout = False
   if outputPipe is None:
     log.info("TEST-INFO: Not logging stdout or stderr due to debugger connection")
   else:
@@ -520,17 +562,27 @@ def runApp(testURL, env, app, profileDir, extraArgs,
         stackFixerProcess = Process([PERL, os.path.join(utilityPath, stackFixerCommand)], stdin=logsource, stdout=subprocess.PIPE)
         logsource = stackFixerProcess.stdout
 
-    line = logsource.readline()
+    (line, didTimeout) = readWithTimeout(logsource, timeout)
-    while line != "":
+    while line != "" and not didTimeout:
       log.info(line.rstrip())
-      line = logsource.readline()
+      (line, didTimeout) = readWithTimeout(logsource, timeout)
+    if didTimeout:
+      log.info("TEST-UNEXPECTED-FAIL | automation.py | application timed out after %d seconds with no output", int(timeout))
+      if CRASHREPORTER:
+        if UNIXISH:
+          os.kill(proc.pid, signal.SIGSEGV)
+        else:
+          #TODO: kill the process such that it triggers Breakpad
+          proc.kill()
+      else:
+        proc.kill()
 
   status = proc.wait()
-  if status != 0:
+  if status != 0 and not didTimeout:
     log.info("TEST-UNEXPECTED-FAIL | automation.py | Exited with code %d during test run", status)
   if stackFixerProcess is not None:
     status = stackFixerProcess.wait()
-    if status != 0:
+    if status != 0 and not didTimeout:
       log.info("TEST-UNEXPECTED-FAIL | automation.py | Stack fixer process exited with code %d during test run", status)
   log.info("INFO | automation.py | Application ran for: %s", str(datetime.now() - startTime))
 

build/pgo/profileserver.py.in

@@ -68,5 +68,8 @@ if __name__ == '__main__':
 
   url = "http://localhost:%d/index.html" % PORT
   appPath = os.path.join(SCRIPT_DIR, automation.DEFAULT_APP)
-  status = automation.runApp(url, browserEnv, appPath, PROFILE_DIRECTORY, {})
+  status = automation.runApp(url, browserEnv, appPath, PROFILE_DIRECTORY, {},
+                             # the profiling HTML doesn't output anything,
+                             # so let's just ignore this for now.
+                             timeout = None)
   sys.exit(status)

layout/tools/reftest/runreftest.py

@@ -173,7 +173,10 @@ Are you executing $objdir/_tests/reftest/runreftest.py?""" \
                                utilityPath = options.utilityPath,
                                xrePath=options.xrePath,
                                debuggerInfo=debuggerInfo,
-                               symbolsPath=options.symbolsPath)
+                               symbolsPath=options.symbolsPath,
+                               # give the JS harness 30 seconds to deal
+                               # with its own timeouts
+                               timeout=options.timeout + 30.0)
     processLeakLog(leakLogFile, options.leakThreshold)
     automation.log.info("\nREFTEST INFO | runreftest.py | Running tests: end.")
   finally:

testing/mochitest/runtests.py.in

@@ -455,7 +455,11 @@ Are you executing $objdir/_tests/testing/mochitest/runtests.py?"""
   if os.path.exists(LEAK_REPORT_FILE):
     os.remove(LEAK_REPORT_FILE)
 
-  # then again to actually run reftest
+  # then again to actually run mochitest
+  # don't use a timeout if we're not auto-running
+  #XXX: use the value from --timeout when bug 521130 lands, for now
+  # use the Mochitest JS harness's timeout + 30 seconds
+  timeout = options.autorun and 330.0 or None
   automation.log.info("INFO | runtests.py | Running tests: start.\n")
   status = automation.runApp(testURL, browserEnv, options.app,
                              PROFILE_DIRECTORY, options.browserArgs,
@@ -464,7 +468,8 @@ Are you executing $objdir/_tests/testing/mochitest/runtests.py?"""
                              xrePath = options.xrePath,
                              certPath=options.certPath,
                              debuggerInfo=debuggerInfo,
-                             symbolsPath=options.symbolsPath)
+                             symbolsPath=options.symbolsPath,
+                             timeout = timeout)
 
   # Server's no longer needed, and perhaps more importantly, anything it might
   # spew to console shouldn't disrupt the leak information table we print next.