Improve logging and ease debugging.

gclient_utils.py

 # Copyright (c) 2011 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.
 
 """Generic utils."""
 
 import errno
 import logging
 import os
 import Queue
@@ skipping 229 matching lines @@
         new_fileobj.last_flushed_at = time.time()
     finally:
       new_fileobj.lock.release()
     if should_flush:
       new_fileobj.flush()
 
   new_fileobj.write = auto_flush_write
   return new_fileobj
 
 
-def MakeFileAnnotated(fileobj):
+def MakeFileAnnotated(fileobj, include_zero=False):
   """Creates a file object clone to automatically prepends every line in worker
   threads with a NN> prefix."""
   if hasattr(fileobj, 'output_buffers'):
     # Already patched.
     return fileobj
 
   # Attribute 'XXX' defined outside __init__
   # pylint: disable=W0201
   new_fileobj = SoftClone(fileobj)
   if not hasattr(new_fileobj, 'lock'):
     new_fileobj.lock = threading.Lock()
   new_fileobj.output_buffers = {}
   new_fileobj.old_annotated_write = new_fileobj.write
 
   def annotated_write(out):
     index = getattr(threading.currentThread(), 'index', None)
     if index is None:
-      # Undexed threads aren't buffered.
-      new_fileobj.old_annotated_write(out)
-      return
+      if not include_zero:
+        # Unindexed threads aren't buffered.
+        new_fileobj.old_annotated_write(out)
+        return
+      index = 0
 
     new_fileobj.lock.acquire()
     try:
       # Use a dummy array to hold the string so the code can be lockless.
       # Strings are immutable, requiring to keep a lock for the whole dictionary
       # otherwise. Using an array is faster than using a dummy object.
       if not index in new_fileobj.output_buffers:
         obj = new_fileobj.output_buffers[index] = ['']
       else:
         obj = new_fileobj.output_buffers[index]
@@ skipping 269 matching lines @@
     try:
       while True:
         # Check for task to run first, then wait.
         while True:
           if not self.exceptions.empty():
             # Systematically flush the queue when an exception logged.
             self.queued = []
           self._flush_terminated_threads()
           if (not self.queued and not self.running or
               self.jobs == len(self.running)):
-            # No more worker threads or can't queue anything.
+            logging.debug('No more worker threads or can\'t queue anything.')
             break
 
           # Check for new tasks to start.
           for i in xrange(len(self.queued)):
             # Verify its requirements.
             for r in self.queued[i].requirements:
               if not r in self.ran:
                 # Requirement not met.
                 break
             else:
@@ skipping 66 matching lines @@
       # exception.
       task_item.run(*args, **kwargs)
       self.ran.append(task_item.name)
       if self.progress:
         self.progress.update(1, ', '.join(t.item.name for t in self.running))
 
   class _Worker(threading.Thread):
     """One thread to execute one WorkItem."""
     def __init__(self, item, index, args, kwargs):
       threading.Thread.__init__(self, name=item.name or 'Worker')
-      logging.info(item.name)
+      logging.info('_Worker(%s) reqs:%s' % (item.name, item.requirements))
       self.item = item
       self.index = index
       self.args = args
       self.kwargs = kwargs
 
     def run(self):
       """Runs in its own thread."""
-      logging.debug('running(%s)' % self.item.name)
+      logging.debug('_Worker.run(%s)' % self.item.name)
       work_queue = self.kwargs['work_queue']
       try:
         self.item.run(*self.args, **self.kwargs)
       except Exception:
         # Catch exception location.
         logging.info('Caught exception in thread %s' % self.item.name)
         logging.info(str(sys.exc_info()))
         work_queue.exceptions.put(sys.exc_info())
-      logging.info('Task %s done' % self.item.name)
+      logging.info('_Worker.run(%s) done' % self.item.name)
 
       work_queue.ready_cond.acquire()
       try:
         work_queue.ready_cond.notifyAll()
       finally:
         work_queue.ready_cond.release()