Add diagnostic information to help track down why the Purify layout tests...

tools/purify/common.py

 #!/bin/env python
 # Copyright (c) 2006-2008 The Chromium Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
 # common.py
 
 """ Common code used by purify_test.py and quantify_test.py in order to automate
 running of Rational Purify and Quantify in a consistent manner.
 """
@@ skipping 65 matching lines @@
   else:
     # For non-detached processes, manually read and print out stdout and stderr.
     # By default, the subprocess is supposed to inherit these from its parent,
     # however when run under buildbot, it seems unable to read data from a
     # grandchild process, so we have to read the child and print the data as if
     # it came from us for buildbot to read it.  We're not sure why this is
     # necessary.
     # TODO(erikkay): should we buffer stderr and stdout separately?
     p = subprocess.Popen(proc, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
 
+  logging.info("started subprocess")
+
   # How long to wait (in seconds) before printing progress log messages.
   progress_delay = 300
   progress_delay_time = time.time() + progress_delay
   did_timeout = False
   if timeout > 0:
     wait_until = time.time() + timeout
   while p.poll() is None and not did_timeout:
     if not detach:
       line = p.stdout.readline()
       while line:
         _print_line(line)
         line = p.stdout.readline()
     else:
       # When we detach, blocking on reading stdout doesn't work, so we sleep
       # a short time and poll.
       time.sleep(0.5)
       if time.time() >= progress_delay_time:
         # Force output on a periodic basis to avoid getting killed off by the
         # buildbot.
         # TODO(erikkay): I'd prefer a less obtrusive 'print ".",' with a flush
         # but because of how we're doing subprocesses, this doesn't appear to
         # work reliably.
         logging.info("%s still running..." % os.path.basename(proc[0]))
         progress_delay_time = time.time() + progress_delay
     if timeout > 0:
       did_timeout = time.time() > wait_until
 
   if did_timeout:
+    logging.info("process timed out")
+  else:
+    logging.info("process ended, did not time out")
+
+  if did_timeout:
     subprocess.call(["taskkill", "/T", "/F", "/PID", str(p.pid)])
     logging.error("KILLED %d" % p.pid)
     # Give the process a chance to actually die before continuing
     # so that cleanup can happen safely.
     time.sleep(1.0)
     logging.error("TIMEOUT waiting for %s" % proc[0])
     raise TimeoutError(proc[0])
   elif not detach:
     for line in p.stdout.readlines():
       _print_line(line, False)
+    logging.info("flushing stdout")
     p.stdout.flush()
 
+  logging.info("collecting result code")
   result = p.poll()
   if result:
     logging.error("%s exited with non-zero result code %d" % (proc[0], result))
   return result
 
 
 def FixPath(path):
   """We pass computed paths to Rational as arguments, so these paths must be
   valid windows paths.  When running in cygwin's python, computed paths
   wind up looking like /cygdrive/c/..., so we need to call out to cygpath
@@ skipping 182 matching lines @@
           file = os.path.join(self._cache_dir, cfile);
           if os.path.isfile(file):
             try:
               os.remove(file)
             except:
               logging.warning("unable to delete file %s: %s" % (file, 
                               sys.exc_info()[0]))