Improve logging and ease debugging.

tests/gclient_test.py

 #!/usr/bin/env python
 # 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.
 
 """Unit tests for gclient.py.
 
 See gclient_smoketest.py for integration tests.
 """
 
 from __future__ import with_statement
 import Queue
 import logging
 import os
 import sys
 import unittest
 
 BASE_DIR = os.path.dirname(os.path.abspath(__file__))
 sys.path.insert(0, os.path.dirname(BASE_DIR))
 
 import gclient
+import gclient_utils
 from tests import trial_dir
 
 
 def write(filename, content):
   """Writes the content of a file and create the directories as needed."""
   filename = os.path.abspath(filename)
   dirname = os.path.dirname(filename)
   if not os.path.isdir(dirname):
     os.makedirs(dirname)
   with open(filename, 'w') as f:
@@ skipping 123 matching lines @@
     actual.remove('svn://example.com/bar_empty')
     self.assertEquals(
         [
           'svn://example.com/foo/dir1',
           'svn://example.com/foo/dir1/dir2/dir3',
           'svn://example.com/foo/dir1/dir2/dir3/dir4',
           # TODO(maruel): This is probably wrong.
           'svn://example.com/foo/dir1/dir2/dir3/dir4/dir1/another',
         ],
         actual)
+
     self._check_requirements(
         obj.dependencies[0],
         {
           'foo/dir1': ['foo'],
           'foo/dir1/dir2/dir3': ['foo', 'foo/dir1', 'foo/dir1/dir2'],
           'foo/dir1/dir2/dir3/dir4':
               ['foo', 'foo/dir1', 'foo/dir1/dir2', 'foo/dir1/dir2/dir3'],
           'foo/dir1/dir2/dir5/dir6':
               ['foo', 'foo/dir1', 'foo/dir1/dir2', 'foo/dir1/dir2/dir3/dir4'],
         })
@@ skipping 10 matching lines @@
           'bar/empty': ['bar'],
         })
 
   def _check_requirements(self, solution, expected):
     for dependency in solution.dependencies:
       self.assertEquals(
           expected.pop(dependency.name), sorted(dependency.requirements))
     self.assertEquals({}, expected)
 
   def _get_processed(self):
+    """Retrieves the item in the order they were processed."""
     items = []
     try:
       while True:
         items.append(self.processed.get_nowait())
     except Queue.Empty:
       pass
     return items
 
   def testAutofix(self):
     # Invalid urls causes pain when specifying requirements. Make sure it's
@@ skipping 27 matching lines @@
     obj.dependencies[0]._dependencies.append(
         gclient.Dependency(
           obj.dependencies[0], 'foo/dir3',
           gclient.GClientKeywords.FileImpl('url'), None, None, None, None,
           'DEPS', True))
     obj.dependencies[0]._file_list.append('foo')
     self.assertEquals(434, len(str(obj)), '%d\n%s' % (len(str(obj)), str(obj)))
 
 
 if __name__ == '__main__':
+  sys.stdout = gclient_utils.MakeFileAutoFlush(sys.stdout)
+  sys.stdout = gclient_utils.MakeFileAnnotated(sys.stdout, include_zero=True)
+  sys.stderr = gclient_utils.MakeFileAutoFlush(sys.stderr)
+  sys.stderr = gclient_utils.MakeFileAnnotated(sys.stderr, include_zero=True)
   logging.basicConfig(
       level=[logging.ERROR, logging.WARNING, logging.INFO, logging.DEBUG][
         min(sys.argv.count('-v'), 3)],
-      format='%(asctime).19s %(levelname)s %(filename)s:'
-              '%(lineno)s %(message)s')
+      format='%(relativeCreated)4d %(levelname)5s %(module)13s('
+              '%(lineno)d) %(message)s')
   unittest.main()