From d22ef0fea968c4f700bc1db81b6553bf597f8f7e Mon Sep 17 00:00:00 2001
From: "anodelman@mozilla.com" <anodelman@mozilla.com>
Date: Wed, 14 Nov 2007 18:49:30 -0800
Subject: [PATCH] bug 403102 - talos needs to recognize browser crash. logging
 of start/stop time off all talos tests for better monitoring. a=anodelman
 r=rcampbell

---
 testing/performance/talos/run_tests.py |  7 +++++--
 testing/performance/talos/ttest.py     | 15 ++++++++++-----
 testing/performance/talos/utils.py     | 10 +++++++++-
 3 files changed, 24 insertions(+), 8 deletions(-)

diff --git a/testing/performance/talos/run_tests.py b/testing/performance/talos/run_tests.py
index cd089d230f9d..27927c112eb9 100755
--- a/testing/performance/talos/run_tests.py
+++ b/testing/performance/talos/run_tests.py
@@ -297,14 +297,17 @@ def test_file(filename):
   utils.debug("using testdate: %d" % date)
   utils.debug("actual date: %d" % int(time.time()))
 
+  utils.stamped_msg(title, "Started")
   for test in tests:
-    print "Running test: " + test
+    utils.stamped_msg("Running test " + test, "Started")
     res, browser_dump, counter_dump = ttest.runTest(browser_config, tests[test])
     if not res:
+      utils.stamped_msg("Failed " + test, "Stopped")
       print 'FAIL: failure to complete test: ' + test
       sys.exit(0)
     results[test] = [browser_dump, counter_dump]
-    print "Completed test: " + test
+    utils.stamped_msg("Completed test " + test, "Stopped")
+  utils.stamped_msg(title, "Stopped")
 
   #process the results
   if (results_server != '') and (results_link != ''):
diff --git a/testing/performance/talos/ttest.py b/testing/performance/talos/ttest.py
index 45a9a4a3a007..4b01e7a78ce1 100644
--- a/testing/performance/talos/ttest.py
+++ b/testing/performance/talos/ttest.py
@@ -153,7 +153,8 @@ def runTest(browser_config, test_config):
     counter_results = {}
     for counter in counters:
       counter_results[counter] = []
-    
+   
+    busted = False 
     while total_time < timeout:
       # Sleep for [resolution] seconds
       time.sleep(resolution)
@@ -192,12 +193,16 @@ def runTest(browser_config, test_config):
 
       #ensure that the browser is still running
       #check at intervals of 60 - this is just to cut down on load 
+      #use the busted check to ensure that we aren't catching a bad time slice where the browser has
+      # completed the test and closed but we haven't picked up the result yet
+      if busted:
+        ffprocess.TerminateAllProcesses("firefox")
+        ffprocess.TerminateAllProcesses("crashreporter")
+        print "FAIL: browser crash"
+        break
       if (total_time % 60 == 0): 
         if ffprocess.ProcessesWithNameExist("crashreporter") or not ffprocess.ProcessesWithNameExist("firefox"):
-          ffprocess.TerminateAllProcesses("firefox")
-          ffprocess.TerminateAllProcesses("crashreporter")
-          print "FAIL: browser crash"
-          break
+          busted = True
 
     if total_time > timeout:
       print "FAIL: timeout from test"
diff --git a/testing/performance/talos/utils.py b/testing/performance/talos/utils.py
index 13b9d7cad4d4..90ed474bd31f 100755
--- a/testing/performance/talos/utils.py
+++ b/testing/performance/talos/utils.py
@@ -37,6 +37,7 @@
 """Utility functions"""
 
 import os
+import time
 DEBUG = 0
 NOISY = 0
 saved_environment = {}
@@ -61,10 +62,17 @@ def debug(message):
      debug switch is controlled through command line switch (-d or --debug)
      Args:
        message: string containing a debugging statement
-     """
+  """
   if DEBUG == 1:
     print "DEBUG: " + message
 
+def stamped_msg(msg_title, msg_action):
+  """Prints a message to the console with a time stamp
+  """
+  time_format = "%a, %d %b %Y %H:%M:%S"
+  msg_format = "%s: \n\t\t%s %s"
+  print msg_format % (msg_title, msg_action, time.strftime(time_format, time.localtime()))
+
 def setEnvironmentVars(newVars): 
    """Sets environment variables as specified by env, an array of variables 
    from sample.config"""