Try to read the stdout pipe to the Valgrind process differently

tools/valgrind/common.py

 # Copyright (c) 2012 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.
 
 import logging
 import platform
 import os
 import signal
 import subprocess
 import sys
@@ skipping 17 matching lines @@
 def RunSubprocess(proc, timeout=0):
   """ Runs a subprocess, until it finishes or |timeout| is exceeded and the
   process is killed with taskkill.  A |timeout| <= 0  means no timeout.
 
   Args:
     proc: list of process components (exe + args)
     timeout: how long to wait before killing, <= 0 means wait forever
   """
 
   logging.info("running %s, timeout %d sec" % (" ".join(proc), timeout))
+  sys.stdout.flush()
+  sys.stderr.flush()
+
   # 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, universal_newlines=True,
-                       bufsize=1,  # line buffered
+                       bufsize=0,  # unbuffered
                        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:
-    for line in p.stdout:
+    line = p.stdout.readline()
+    while line and not did_timeout:

[Nico, 2013/07/15 17:16:35]

Since this makes a difference and is very non-obvious, having a comment that
explains why this is a while and not a for-in loop might be a good idea.

[Timur Iskhodzhanov, 2013/07/15 18:18:43]

That was done in r202841 when I actually became sure WTH is going on.

       sys.stdout.write(line)
       sys.stdout.flush()
+      line = p.stdout.readline()
       if timeout > 0:
         did_timeout = time.time() > wait_until
-      if did_timeout:
-        break
 
   if did_timeout:
     logging.info("process timed out")
   else:
     logging.info("process ended, did not time out")
 
   if did_timeout:
     if IsWindows():
       subprocess.call(["taskkill", "/T", "/F", "/PID", str(p.pid)])
     else:
       # Does this kill all children, too?
       os.kill(p.pid, signal.SIGINT)
     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])
   else:
     for line in p.stdout:
       sys.stdout.write(line)
     if not IsMac():   # stdout flush fails on Mac
       logging.info("flushing stdout")
-      p.stdout.flush()
+      sys.stdout.flush()

[Reid Kleckner, 2013/05/28 13:00:27]

Aha.  :)  Is that it?

[Reid Kleckner, 2013/05/28 13:01:34]

Er, no, it shouldn't be.

[Timur Iskhodzhanov, 2013/05/28 13:01:57]

Nope, I don't think so - the hangs happen when python is around line 62 [old
line 58].

 
   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 IsLinux():
   return sys.platform.startswith('linux')
@@ skipping 142 matching lines @@
     return False
 
   print "-----------------------------------------------------"
   print "Suppressions used:"
   print "  count name"
   for (name, count) in sorted(suppcounts.items(), key=lambda (k,v): (v,k)):
     print "%7d %s" % (count, name)
   print "-----------------------------------------------------"
   sys.stdout.flush()
   return True