Merge 68b70ca into 9ff5424

src/python/pants/bin/BUILD

@@ -6,45 +6,25 @@ python_library(
   sources = ['goal_runner.py', 'pants_exe.py'],
   dependencies = [
     '3rdparty/python:setuptools',
-
-    'src/python/pants/backend/android:plugin',
-    'src/python/pants/backend/authentication:authentication',
-    'src/python/pants/backend/codegen:plugin',
-    'src/python/pants/backend/core:plugin',
-    'src/python/pants/backend/core/tasks:common',
     'src/python/pants/backend/core/tasks:task',
-    'src/python/pants/backend/jvm:plugin',
     'src/python/pants/backend/jvm/tasks:nailgun_task',
-    'src/python/pants/backend/maven_layout:plugin',
-    'src/python/pants/backend/python:plugin',
-    'src/python/pants/base:address',
     'src/python/pants/base:build_environment',
+    'src/python/pants/base:build_file',
     'src/python/pants/base:build_file_address_mapper',
     'src/python/pants/base:build_file_parser',
     'src/python/pants/base:build_graph',
-    'src/python/pants/base:config',
     'src/python/pants/base:cmd_line_spec_parser',
+    'src/python/pants/base:config',
     'src/python/pants/base:extension_loader',
-    'src/python/pants/base:target',
     'src/python/pants/base:workunit',
     'src/python/pants/engine',
     'src/python/pants/goal',
     'src/python/pants/goal:context',
     'src/python/pants/goal:initialize_reporting',
     'src/python/pants/goal:run_tracker',
+    'src/python/pants/logging',
     'src/python/pants/option',
     'src/python/pants/reporting',
-    'src/python/pants/util:dirutil',
-
-    # XXX these are necessary to parse BUILD.commons.  Should instead be
-    # added as plugins to pants.ini
-    'src/python/pants/backend/core/tasks:what_changed',
-    'src/python/pants/backend/jvm/targets:java',
-    'src/python/pants/backend/jvm/targets:jvm',
-    'src/python/pants/backend/jvm/targets:scala',
-    'src/python/pants/backend/jvm/tasks:checkstyle',
-    'src/python/pants/backend/python:python_chroot',
-    'src/python/pants/scm:git',
   ],
 )
 

src/python/pants/bin/goal_runner.py

@@ -7,7 +7,6 @@
 
 import logging
 import logging.config
-import os
 import sys
 
 import pkg_resources
@@ -28,10 +27,10 @@
 from pants.goal.goal import Goal
 from pants.goal.initialize_reporting import initial_reporting, update_reporting
 from pants.goal.run_tracker import RunTracker
+from pants.logging.setup import setup_logging
 from pants.option.global_options import register_global_options
 from pants.option.options_bootstrapper import OptionsBootstrapper
 from pants.reporting.report import Report
-from pants.util.dirutil import safe_mkdir
 
 
 logger = logging.getLogger(__name__)
@@ -54,6 +53,9 @@ def setup(self):
     bootstrap_options = options_bootstrapper.get_bootstrap_options()
     self.config = Config.from_cache()
 
+    # Get logging setup prior to loading backends so that they can log as needed.
+    self._setup_logging(bootstrap_options.for_global_scope())
+
     # Add any extra paths to python path (eg for loading extra source backends)
     for path in bootstrap_options.for_global_scope().pythonpath:
       sys.path.append(path)
@@ -77,10 +79,6 @@ def setup(self):
     self.options = options_bootstrapper.get_full_options(known_scopes=known_scopes)
     self.register_options()
 
-    # TODO(Eric Ayers) We are missing log messages. Set the log level earlier
-    # Enable standard python logging for code with no handle to a context/work-unit.
-    self._setup_logging()  # NB: self.options are needed for this call.
-
     self.run_tracker = RunTracker.from_options(self.options)
     report = initial_reporting(self.config, self.run_tracker)
     self.run_tracker.start(report)
@@ -231,45 +229,8 @@ def is_quiet_task():
     engine = RoundEngine()
     return engine.execute(context, self.goals)
 
-  def _setup_logging(self):
-    # TODO(John Sirois): Consider moving to straight python logging.  The divide between the
-    # context/work-unit logging and standard python logging doesn't buy us anything.
-
-    # TODO(John Sirois): Support logging.config.fileConfig so a site can setup fine-grained
-    # logging control and we don't need to be the middleman plumbing an option for each python
-    # standard logging knob.
-
+  def _setup_logging(self, global_options):
     # NB: quiet help says 'Squelches all console output apart from errors'.
-    level = 'ERROR' if self.global_options.quiet else self.global_options.level.upper()
-
-    logging_config = {'version': 1,  # required and there is only a version 1 format so far.
-                      'disable_existing_loggers': False}
-
-    formatters_config = {'brief': {'format': '%(levelname)s] %(message)s'}}
-    handlers_config = {'console': {'class': 'logging.StreamHandler',
-                                   'formatter': 'brief',  # defined above
-                                   'level': level}}
-
-    log_dir = self.global_options.logdir
-    if log_dir:
-      safe_mkdir(log_dir)
-
-      # This is close to but not quite glog format.  Namely the leading levelname is not a single
-      # character and the fractional second is only to millis precision and not micros.
-      glog_date_format = '%m%d %H:%M:%S'
-      glog_format = ('%(levelname)s %(asctime)s.%(msecs)d %(process)d %(filename)s:%(lineno)d] '
-                     '%(message)s')
-
-      formatters_config['glog'] = {'format': glog_format, 'datefmt': glog_date_format}
-      handlers_config['file'] = {'class': 'logging.handlers.RotatingFileHandler',
-                                 'formatter': 'glog',  # defined above
-                                 'level': level,
-                                 'filename': os.path.join(log_dir, 'pants.log'),
-                                 'maxBytes': 10 * 1024 * 1024,
-                                 'backupCount': 4}
-
-    logging_config['formatters'] = formatters_config
-    logging_config['handlers'] = handlers_config
-    logging_config['root'] = {'level': level, 'handlers': handlers_config.keys()}
-
-    logging.config.dictConfig(logging_config)
+    level = 'ERROR' if global_options.quiet else global_options.level.upper()
+
+    setup_logging(level, log_dir=global_options.logdir)

src/python/pants/logging/BUILD

@@ -0,0 +1,10 @@
+# Copyright 2015 Pants project contributors (see CONTRIBUTORS.md).
+# Licensed under the Apache License, Version 2.0 (see LICENSE).
+
+python_library(
+  name='logging',
+  sources=globs('*.py'),
+  dependencies=[
+    'src/python/pants/util:dirutil',
+  ],
+)

src/python/pants/logging/setup.py

@@ -0,0 +1,82 @@
+# coding=utf-8
+# Copyright 2015 Pants project contributors (see CONTRIBUTORS.md).
+# Licensed under the Apache License, Version 2.0 (see LICENSE).
+
+from __future__ import (absolute_import, division, generators, nested_scopes, print_function,
+                        unicode_literals, with_statement)
+
+import logging
+import os
+import time
+from logging import Formatter, StreamHandler
+from logging.handlers import RotatingFileHandler
+
+from pants.util.dirutil import safe_mkdir
+
+
+def setup_logging(level, console_stream=None, log_dir=None, scope=None):
+  """Configures logging for a given scope, by default the global scope.
+
+  :param str level: The logging level to enable, must be one of the level names listed here:
+                    https://docs.python.org/2/library/logging.html#levels
+  :param str console_stream: The stream to use for default (console) logging.  Will be sys.stderr
+                             if unspecified.
+  :param str log_dir: An optional directory to emit logs files in.  If unspecified, no disk logging
+                      will occur.  If supplied, the directory will be created if it does not already
+                      exist and all logs will be tee'd to a rolling set of log files in that
+                      directory.
+  :param str scope: A logging scope to configure.  The scopes are hierarchichal logger names, with
+                    The '.' separator providing the scope hierarchy.  By default the root logger is
+                    configured.
+  :returns: The full path to the main log file if file logging is configured or else `None`.
+  :rtype: str
+  """
+
+  # TODO(John Sirois): Consider moving to straight python logging.  The divide between the
+  # context/work-unit logging and standard python logging doesn't buy us anything.
+
+  # TODO(John Sirois): Support logging.config.fileConfig so a site can setup fine-grained
+  # logging control and we don't need to be the middleman plumbing an option for each python
+  # standard logging knob.
+
+  logger = logging.getLogger(scope)
+  for handler in logger.handlers:
+    logger.removeHandler(handler)
+
+  log_file = None
+  console_handler = StreamHandler(stream=console_stream)
+  console_handler.setFormatter(Formatter(fmt='%(levelname)s] %(message)s'))
+  console_handler.setLevel(level)
+  logger.addHandler(console_handler)
+
+  if log_dir:
+    safe_mkdir(log_dir)
+    log_file = os.path.join(log_dir, 'pants.log')
+    file_handler = RotatingFileHandler(log_file, maxBytes=10 * 1024 * 1024, backupCount=4)
+
+    class GlogFormatter(Formatter):
+      LEVEL_MAP = {
+          logging.FATAL: 'F',
+          logging.ERROR: 'E',
+          logging.WARN: 'W',
+          logging.INFO: 'I',
+          logging.DEBUG: 'D'}
+
+      def format(self, record):
+        datetime = time.strftime('%m%d %H:%M:%S', time.localtime(record.created))
+        microseconds = int((record.created - int(record.created)) * 1e6)
+        return '{levelchar}{datetime}.{microseconds} {process} {filename}:{lineno}] {msg}'.format(
+            levelchar=self.LEVEL_MAP[record.levelno],
+            datetime=datetime,
+            microseconds=microseconds,
+            process=record.process,
+            filename=record.filename,
+            lineno=record.lineno,
+            msg=record.getMessage())
+
+    file_handler.setFormatter(GlogFormatter())
+    file_handler.setLevel(level)
+    logger.addHandler(file_handler)
+
+  logger.setLevel(level)
+  return log_file

src/python/pants/option/global_options.py

@@ -9,6 +9,20 @@
 
 
 def register_global_options(register):
+  """Register options not tied to any particular task.
+
+  It's important to note that another set of global options is registered in
+  `pants.option.options_bootstrapper:register_bootstrap_options`, but those are reserved for options
+  that other options or tasks may need to build upon directly or indirectly.  For a direct-use
+  example, a doc generation task may want to provide an option for its user-visible output location
+  that defaults to `${pants-distdir}/docs` and thus needs to interpolate the bootstrap option of
+  `pants-distdir`.  An indirect example would be logging options that are needed by pants itself to
+  setup logging prior to loading plugins so that plugin registration can log confidently to a
+  configured logging subsystem.
+
+  Global options here on the other hand are reserved for infrastructure objects (not tasks) that
+  have leaf configuration data.
+  """
   register('-t', '--timeout', type=int, metavar='<seconds>',
            help='Number of seconds to wait for http connections.')
   register('-x', '--time', action='store_true',
@@ -22,12 +36,6 @@ def register_global_options(register):
   register('--ng-daemons', action='store_true', default=True,
            help='Use nailgun daemons to execute java tasks.')
 
-  register('-d', '--logdir', metavar='<dir>',
-           help='Write logs to files under this directory.')
-  register('-l', '--level', choices=['debug', 'info', 'warn'], default='info',
-           help='Set the logging level.')
-  register('-q', '--quiet', action='store_true',
-           help='Squelches all console output apart from errors.')
   register('-i', '--interpreter', default=[], action='append', metavar='<requirement>',
            help="Constrain what Python interpreters to use.  Uses Requirement format from "
                 "pkg_resources, e.g. 'CPython>=2.6,<3' or 'PyPy'. By default, no constraints "

src/python/pants/option/options_bootstrapper.py

@@ -5,6 +5,9 @@
 from __future__ import (absolute_import, division, generators, nested_scopes, print_function,
                         unicode_literals, with_statement)
 
+import itertools
+import logging
+
 import os
 import sys
 
@@ -46,6 +49,21 @@ def register_bootstrap_options(register, buildroot=None):
   register('--target-spec-file', action='append', dest='target_spec_files',
            help='Read additional specs from this file, one per line')
 
+  # These logging options are registered in the bootstrap phase so that plugins can log during
+  # registration and not so that their values can be interpolated in configs.
+  register('-d', '--logdir', metavar='<dir>',
+           help='Write logs to files under this directory.')
+
+  # Although logging supports the WARN level, its not documented and could conceivably be yanked.
+  # Since pants has supported 'warn' since inception, leave the 'warn' choice as-is but explicitly
+  # setup a 'WARN' logging level name that maps to 'WARNING'.
+  logging.addLevelName(logging.WARNING, 'WARN')
+  register('-l', '--level', choices=['debug', 'info', 'warn'], default='info',
+           help='Set the logging level.')
+
+  register('-q', '--quiet', action='store_true',
+           help='Squelches all console output apart from errors.')
+
 
 class OptionsBootstrapper(object):
   """An object that knows how to create options in two stages: bootstrap, and then full options."""
@@ -66,16 +84,31 @@ def get_bootstrap_options(self):
     """Returns an Options instance that only knows about the bootstrap options."""
     if not self._bootstrap_options:
       flags = set()
+      short_flags = set()
 
       def capture_the_flags(*args, **kwargs):
         for flag in Parser.expand_flags(*args, **kwargs):
           flags.add(flag.name)
+          if len(flag.name) == 2:
+            short_flags.add(flag.name)
           if flag.inverse_name:
             flags.add(flag.inverse_name)
 
       register_bootstrap_options(capture_the_flags, buildroot=self._buildroot)
+
+      def is_bootstrap_option(arg):
+        components = arg.split('=', 1)
+        if components[0] in flags:
+          return True
+        for flag in short_flags:
+          if arg.startswith(flag):
+            return True
+        return False
+
       # Take just the bootstrap args, so we don't choke on other global-scope args on the cmd line.
-      bargs = filter(lambda x: x.partition('=')[0] in flags, self._args or [])
+      # Stop before '--' since args after that are pass-through and may have duplicate names to our
+      # bootstrap options.
+      bargs = filter(is_bootstrap_option, itertools.takewhile(lambda arg: arg != '--', self._args))
 
       self._bootstrap_options = Options(env=self._env, config=self._pre_bootstrap_config,
                                         known_scopes=[GLOBAL_SCOPE], args=bargs)

tests/python/pants_test/BUILD

@@ -104,6 +104,7 @@ target(
     'tests/python/pants_test/graph',
     'tests/python/pants_test/goal',
     'tests/python/pants_test/java',
+    'tests/python/pants_test/logging',
     'tests/python/pants_test/net',
     'tests/python/pants_test/option',
     'tests/python/pants_test/process',

tests/python/pants_test/logging/BUILD

@@ -0,0 +1,12 @@
+# Copyright 2015 Pants project contributors (see CONTRIBUTORS.md).
+# Licensed under the Apache License, Version 2.0 (see LICENSE).
+
+python_tests(
+  name='logging',
+  sources=globs('*.py'),
+  dependencies=[
+    '3rdparty/python:six',
+    'src/python/pants/logging',
+    'src/python/pants/util:contextutil',
+  ],
+)