Improve logging and ease debugging.

gclient.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.
 
 """Meta checkout manager supporting both Subversion and GIT.
 
 Files
   .gclient      : Current client configuration, written by 'config' command.
                   Format is a Python script defining 'solutions', a list whose
@@ skipping 296 matching lines @@
 
     if not self.name and self.parent:
       raise gclient_utils.Error('Dependency without name')
 
   def LateOverride(self, url):
     """Resolves the parsed url from url.
 
     Manages From() keyword accordingly. Do not touch self.parsed_url nor
     self.url because it may called with other urls due to From()."""
     assert self.parsed_url == None or not self.should_process, self.parsed_url
-    overriden_url = self.get_custom_deps(self.name, url)
-    if overriden_url != url:
-      logging.info('%s, %s was overriden to %s' % (self.name, url,
-          overriden_url))
-      return overriden_url
-    elif isinstance(url, self.FromImpl):
+    parsed_url = self.get_custom_deps(self.name, url)
+    if parsed_url != url:
+      logging.info('LateOverride(%s, %s) -> %s' % (self.name, url, parsed_url))
+      return parsed_url
+
+    if isinstance(url, self.FromImpl):
       ref = [
           dep for dep in self.root.subtree(True) if url.module_name == dep.name
       ]
       if not ref:
         raise gclient_utils.Error('Failed to find one reference to %s. %s' % (
             url.module_name, ref))
       # It may happen that len(ref) > 1 but it's no big deal.
       ref = ref[0]
       sub_target = url.sub_target_name or self.name
       # Make sure the referenced dependency DEPS file is loaded and file the
       # inner referenced dependency.
       ref.ParseDepsFile()
       found_dep = None
       for d in ref.dependencies:
         if d.name == sub_target:
           found_dep = d
           break
       if not found_dep:
         raise gclient_utils.Error(
             'Couldn\'t find %s in %s, referenced by %s (parent: %s)\n%s' % (
                 sub_target, ref.name, self.name, self.parent.name,
                 str(self.root)))
 
       # Call LateOverride() again.
       parsed_url = found_dep.LateOverride(found_dep.url)
-      logging.info('%s, %s to %s' % (self.name, url, parsed_url))
+      logging.info(
+          'LateOverride(%s, %s) -> %s (From)' % (self.name, url, parsed_url))
       return parsed_url
-    elif isinstance(url, basestring):
+
+    if isinstance(url, basestring):
       parsed_url = urlparse.urlparse(url)
       if not parsed_url[0]:
         # A relative url. Fetch the real base.
         path = parsed_url[2]
         if not path.startswith('/'):
           raise gclient_utils.Error(
               'relative DEPS entry \'%s\' must begin with a slash' % url)
         # Create a scm just to query the full url.
         parent_url = self.parent.parsed_url
         if isinstance(parent_url, self.FileImpl):
           parent_url = parent_url.file_location
         scm = gclient_scm.CreateSCM(parent_url, self.root.root_dir, None)
         parsed_url = scm.FullUrlForRelativeUrl(url)
       else:
         parsed_url = url
-      logging.info('%s, %s -> %s' % (self.name, url, parsed_url))
+      logging.info('LateOverride(%s, %s) -> %s' % (self.name, url, parsed_url))
       return parsed_url
-    elif isinstance(url, self.FileImpl):
-      parsed_url = url
-      logging.info('%s, %s -> %s (File)' % (self.name, url, parsed_url))
-      return parsed_url
-    elif url is None:
-      return None
+
+    if isinstance(url, self.FileImpl):
+      logging.info('LateOverride(%s, %s) -> %s (File)' % (self.name, url, url))
+      return url
+
+    if url is None:
+      logging.info('LateOverride(%s, %s) -> %s' % (self.name, url, url))
+      return url
     else:
-      raise gclient_utils.Error('Unkown url type')
+      raise gclient_utils.Error('Unknown url type')
 
   def ParseDepsFile(self):
     """Parses the DEPS file for this dependency."""
     assert self.processed == True
     if self.deps_parsed:
       logging.debug('%s was already parsed' % self.name)
       return
     # One thing is unintuitive, vars= {} must happen before Var() use.
     local_scope = {}
     var = self.VarImpl(self.custom_vars, local_scope)
     global_scope = {
       'File': self.FileImpl,
       'From': self.FromImpl,
       'Var': var.Lookup,
       'deps_os': {},
     }
     filepath = os.path.join(self.root.root_dir, self.name, self.deps_file)
     if not os.path.isfile(filepath):
-      logging.info('%s: No %s file found at %s' % (self.name, self.deps_file,
-                                                   filepath))
+      logging.info(
+          'ParseDepsFile(%s): No %s file found at %s' % (
+            self.name, self.deps_file, filepath))
     else:
       deps_content = gclient_utils.FileRead(filepath)
-      logging.debug(deps_content)
+      logging.debug('ParseDepsFile(%s) read:\n%s' % (self.name, deps_content))
       # Eval the content.
       try:
         exec(deps_content, global_scope, local_scope)
       except SyntaxError, e:
         gclient_utils.SyntaxErrorToError(filepath, e)
     deps = local_scope.get('deps', {})
     # load os specific dependencies if defined.  these dependencies may
     # override or extend the values defined by the 'deps' member.
     if 'deps_os' in local_scope:
       enforced_os = self.root.enforced_os
@@ skipping 413 matching lines @@
     # Sometimes pprint.pformat will use {', sometimes it'll use { ' ... It
     # makes testing a bit too fun.
     result = 'entries = {\n'
     for entry in self.root.subtree(False):
       # Skip over File() dependencies as we can't version them.
       if not isinstance(entry.parsed_url, self.FileImpl):
         result += '  %s: %s,\n' % (pprint.pformat(entry.name),
             pprint.pformat(entry.parsed_url))
     result += '}\n'
     file_path = os.path.join(self.root_dir, self._options.entries_filename)
-    logging.info(result)
+    logging.debug(result)
     gclient_utils.FileWrite(file_path, result)
 
   def _ReadEntries(self):
     """Read the .gclient_entries file for the given client.
 
     Returns:
       A sequence of solution names, which will be empty if there is the
       entries file hasn't been created yet.
     """
     scope = {}
@@ skipping 538 matching lines @@
   parser.add_option('-v', '--verbose', action='count', default=0,
                     help='Produces additional output for diagnostics. Can be '
                           'used up to three times for more logging info.')
   parser.add_option('--gclientfile', dest='config_filename',
                     default=os.environ.get('GCLIENT_FILE', '.gclient'),
                     help='Specify an alternate %default file')
   # Integrate standard options processing.
   old_parser = parser.parse_args
   def Parse(args):
     (options, args) = old_parser(args)
-    level = None
-    if options.verbose == 2:
-      level = logging.INFO
-    elif options.verbose > 2:
-      level = logging.DEBUG
+    level = [logging.ERROR, logging.WARNING, logging.INFO, logging.DEBUG][
+        min(options.verbose, 3)]
     logging.basicConfig(level=level,
         format='%(module)s(%(lineno)d) %(funcName)s:%(message)s')
     options.entries_filename = options.config_filename + '_entries'
     if options.jobs < 1:
       parser.error('--jobs must be 1 or higher')
 
     # These hacks need to die.
     if not hasattr(options, 'revisions'):
       # GClient.RunOnDeps expects it even if not applicable.
       options.revisions = []
@@ skipping 45 matching lines @@
   except (gclient_utils.Error, subprocess2.CalledProcessError), e:
     print >> sys.stderr, 'Error: %s' % str(e)
     return 1
 
 
 if '__main__' == __name__:
   fix_encoding.fix_encoding()
   sys.exit(Main(sys.argv[1:]))
 
 # vim: ts=2:sw=2:tw=80:et: