make config-loading debug messages more explicit

It was never clear in debug messages that the cwd is searched
for config files.  This adjusts various debug messages during
config-file loading to make things more clear:

The following debug messages were added:
* specify search-path at start of load-config routine
* on success, full path of loaded config files
* always note when config files are not found

IPython/config/application.py

@@ -1,431 +1,435 b''
 # encoding: utf-8
 """
 A base class for a configurable application.
 
 Authors:
 
 * Brian Granger
 * Min RK
 """
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2008-2011  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 import logging
 import os
 import re
 import sys
 from copy import deepcopy
 
 from IPython.config.configurable import SingletonConfigurable
 from IPython.config.loader import (
     KeyValueConfigLoader, PyFileConfigLoader, Config, ArgumentError
 )
 
 from IPython.utils.traitlets import (
     Unicode, List, Int, Enum, Dict, Instance, TraitError
 )
 from IPython.utils.importstring import import_item
 from IPython.utils.text import indent, wrap_paragraphs, dedent
 
 #-----------------------------------------------------------------------------
 # function for re-wrapping a helpstring
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Descriptions for the various sections
 #-----------------------------------------------------------------------------
 
 # merge flags&aliases into options
 option_description = """
 IPython command-line arguments are passed as '--<flag>', or '--<name>=<value>'.
 
 Arguments that take values are actually convenience aliases to full
 Configurables, whose aliases are listed on the help line. For more information
 on full configurables, see '--help-all'.
 """.strip() # trim newlines of front and back
 
 keyvalue_description = """
 Parameters are set from command-line arguments of the form:
 `--Class.trait=value`.
 This line is evaluated in Python, so simple expressions are allowed, e.g.::
 `--C.a='range(3)'` For setting C.a=[0,1,2].
 """.strip() # trim newlines of front and back
 
 subcommand_description = """
 Subcommands are launched as `{app} cmd [args]`. For information on using
 subcommand 'cmd', do: `{app} cmd -h`.
 """.strip().format(app=os.path.basename(sys.argv[0]))
 # get running program name
 
 #-----------------------------------------------------------------------------
 # Application class
 #-----------------------------------------------------------------------------
 
 
 class ApplicationError(Exception):
     pass
 
 
 class Application(SingletonConfigurable):
     """A singleton application with full configuration support."""
 
     # The name of the application, will usually match the name of the command
     # line application
     name = Unicode(u'application')
 
     # The description of the application that is printed at the beginning
     # of the help.
     description = Unicode(u'This is an application.')
     # default section descriptions
     option_description = Unicode(option_description)
     keyvalue_description = Unicode(keyvalue_description)
     subcommand_description = Unicode(subcommand_description)
 
     # The usage and example string that goes at the end of the help string.
     examples = Unicode()
 
     # A sequence of Configurable subclasses whose config=True attributes will
     # be exposed at the command line.
     classes = List([])
 
     # The version string of this application.
     version = Unicode(u'0.0')
 
     # The log level for the application
     log_level = Enum((0,10,20,30,40,50,'DEBUG','INFO','WARN','ERROR','CRITICAL'),
                     default_value=logging.WARN,
                     config=True,
                     help="Set the log level by value or name.")
     def _log_level_changed(self, name, old, new):
         """Adjust the log level when log_level is set."""
         if isinstance(new, basestring):
             new = getattr(logging, new)
             self.log_level = new
         self.log.setLevel(new)
     
     # the alias map for configurables
     aliases = Dict({'log-level' : 'Application.log_level'})
     
     # flags for loading Configurables or store_const style flags
     # flags are loaded from this dict by '--key' flags
     # this must be a dict of two-tuples, the first element being the Config/dict
     # and the second being the help string for the flag
     flags = Dict()
     def _flags_changed(self, name, old, new):
         """ensure flags dict is valid"""
         for key,value in new.iteritems():
             assert len(value) == 2, "Bad flag: %r:%s"%(key,value)
             assert isinstance(value[0], (dict, Config)), "Bad flag: %r:%s"%(key,value)
             assert isinstance(value[1], basestring), "Bad flag: %r:%s"%(key,value)
         
     
     # subcommands for launching other applications
     # if this is not empty, this will be a parent Application
     # this must be a dict of two-tuples, 
     # the first element being the application class/import string
     # and the second being the help string for the subcommand
     subcommands = Dict()
     # parse_command_line will initialize a subapp, if requested
     subapp = Instance('IPython.config.application.Application', allow_none=True)
     
     # extra command-line arguments that don't set config values
     extra_args = List(Unicode)
     
 
     def __init__(self, **kwargs):
         SingletonConfigurable.__init__(self, **kwargs)
         # Ensure my class is in self.classes, so my attributes appear in command line
         # options and config files.
         if self.__class__ not in self.classes:
             self.classes.insert(0, self.__class__)
         
         self.init_logging()
 
     def _config_changed(self, name, old, new):
         SingletonConfigurable._config_changed(self, name, old, new)
         self.log.debug('Config changed:')
         self.log.debug(repr(new))
 
     def init_logging(self):
         """Start logging for this application.
 
         The default is to log to stdout using a StreaHandler. The log level
         starts at loggin.WARN, but this can be adjusted by setting the 
         ``log_level`` attribute.
         """
         self.log = logging.getLogger(self.__class__.__name__)
         self.log.setLevel(self.log_level)
         if sys.executable.endswith('pythonw.exe'):
             # this should really go to a file, but file-logging is only
             # hooked up in parallel applications
             self._log_handler = logging.StreamHandler(open(os.devnull, 'w'))
         else:
             self._log_handler = logging.StreamHandler()
         self._log_formatter = logging.Formatter("[%(name)s] %(message)s")
         self._log_handler.setFormatter(self._log_formatter)
         self.log.addHandler(self._log_handler)
 
     def initialize(self, argv=None):
         """Do the basic steps to configure me.
         
         Override in subclasses.
         """
         self.parse_command_line(argv)
         
     
     def start(self):
         """Start the app mainloop.
         
         Override in subclasses.
         """
         if self.subapp is not None:
             return self.subapp.start()
     
     def print_alias_help(self):
         """Print the alias part of the help."""
         if not self.aliases:
             return
         
         lines = []
         classdict = {}
         for cls in self.classes:
             # include all parents (up to, but excluding Configurable) in available names
             for c in cls.mro()[:-3]:
                 classdict[c.__name__] = c
         
         for alias, longname in self.aliases.iteritems():
             classname, traitname = longname.split('.',1)
             cls = classdict[classname]
             
             trait = cls.class_traits(config=True)[traitname]
             help = cls.class_get_trait_help(trait).splitlines()
             # reformat first line
             help[0] = help[0].replace(longname, alias) + ' (%s)'%longname
             lines.extend(help)
         # lines.append('')
         print os.linesep.join(lines)
     
     def print_flag_help(self):
         """Print the flag part of the help."""
         if not self.flags:
             return
         
         lines = []
         for m, (cfg,help) in self.flags.iteritems():
             lines.append('--'+m)
             lines.append(indent(dedent(help.strip())))
         # lines.append('')
         print os.linesep.join(lines)
     
     def print_options(self):
         if not self.flags and not self.aliases:
             return
         lines = ['Options']
         lines.append('-'*len(lines[0]))
         lines.append('')
         for p in wrap_paragraphs(self.option_description):
             lines.append(p)
             lines.append('')
         print os.linesep.join(lines)
         self.print_flag_help()
         self.print_alias_help()
         print
     
     def print_subcommands(self):
         """Print the subcommand part of the help."""
         if not self.subcommands:
             return
         
         lines = ["Subcommands"]
         lines.append('-'*len(lines[0]))
         lines.append('')
         for p in wrap_paragraphs(self.subcommand_description):
             lines.append(p)
             lines.append('')
         for subc, (cls, help) in self.subcommands.iteritems():
             lines.append(subc)
             if help:
                 lines.append(indent(dedent(help.strip())))
         lines.append('')
         print os.linesep.join(lines)
     
     def print_help(self, classes=False):
         """Print the help for each Configurable class in self.classes.
         
         If classes=False (the default), only flags and aliases are printed.
         """
         self.print_subcommands()
         self.print_options()
         
         if classes:
             if self.classes:
                 print "Class parameters"
                 print "----------------"
                 print
                 for p in wrap_paragraphs(self.keyvalue_description):
                     print p
                     print
         
             for cls in self.classes:
                 cls.class_print_help()
                 print
         else:
             print "To see all available configurables, use `--help-all`"
             print
 
     def print_description(self):
         """Print the application description."""
         for p in wrap_paragraphs(self.description):
             print p
             print
 
     def print_examples(self):
         """Print usage and examples.
 
         This usage string goes at the end of the command line help string
         and should contain examples of the application's usage.
         """
         if self.examples:
             print "Examples"
             print "--------"
             print
             print indent(dedent(self.examples.strip()))
             print
 
     def print_version(self):
         """Print the version string."""
         print self.version
 
     def update_config(self, config):
         """Fire the traits events when the config is updated."""
         # Save a copy of the current config.
         newconfig = deepcopy(self.config)
         # Merge the new config into the current one.
         newconfig._merge(config)
         # Save the combined config as self.config, which triggers the traits
         # events.
         self.config = newconfig
     
     def initialize_subcommand(self, subc, argv=None):
         """Initialize a subcommand with argv."""
         subapp,help = self.subcommands.get(subc)
         
         if isinstance(subapp, basestring):
             subapp = import_item(subapp)
         
         # clear existing instances
         self.__class__.clear_instance()
         # instantiate
         self.subapp = subapp.instance()
         # and initialize subapp
         self.subapp.initialize(argv)
         
     def parse_command_line(self, argv=None):
         """Parse the command line arguments."""
         argv = sys.argv[1:] if argv is None else argv
 
         if self.subcommands and len(argv) > 0:
             # we have subcommands, and one may have been specified
             subc, subargv = argv[0], argv[1:]
             if re.match(r'^\w(\-?\w)*$', subc) and subc in self.subcommands:
                 # it's a subcommand, and *not* a flag or class parameter
                 return self.initialize_subcommand(subc, subargv)
             
         if '-h' in argv or '--help' in argv or '--help-all' in argv:
             self.print_description()
             self.print_help('--help-all' in argv)
             self.print_examples()
             self.exit(0)
 
         if '--version' in argv:
             self.print_version()
             self.exit(0)
         
         loader = KeyValueConfigLoader(argv=argv, aliases=self.aliases,
                                         flags=self.flags)
         try:
             config = loader.load_config()
             self.update_config(config)
         except (TraitError, ArgumentError) as e:
             self.print_description()
             self.print_help()
             self.print_examples()
             self.log.fatal(str(e))
             self.exit(1)
         # store unparsed args in extra_args
         self.extra_args = loader.extra_args
 
     def load_config_file(self, filename, path=None):
         """Load a .py based config file by filename and path."""
         loader = PyFileConfigLoader(filename, path=path)
         try:
             config = loader.load_config()
         except IOError:
             # problem with the file (probably doesn't exist), raise
             raise
         except Exception:
+            # try to get the full filename, but it will be empty in the
+            # unlikely event that the error raised before filefind finished
+            filename = loader.full_filename or filename
             # problem while running the file
-            self.log.error("Exception while loading config file %s [path=%s]"%
-                            (filename, path), exc_info=True)
+            self.log.error("Exception while loading config file %s",
+                            filename, exc_info=True)
         else:
+            self.log.debug("Loaded config file: %s", loader.full_filename)
             self.update_config(config)
     
     def generate_config_file(self):
         """generate default config file from Configurables"""
         lines = ["# Configuration file for %s."%self.name]
         lines.append('')
         lines.append('c = get_config()')
         lines.append('')
         for cls in self.classes:
             lines.append(cls.class_config_section())
         return '\n'.join(lines)
 
     def exit(self, exit_status=0):
         self.log.debug("Exiting application: %s" % self.name)
         sys.exit(exit_status)
 
 #-----------------------------------------------------------------------------
 # utility functions, for convenience
 #-----------------------------------------------------------------------------
 
 def boolean_flag(name, configurable, set_help='', unset_help=''):
     """Helper for building basic --trait, --no-trait flags.
     
     Parameters
     ----------
     
     name : str
         The name of the flag.
     configurable : str
         The 'Class.trait' string of the trait to be set/unset with the flag
     set_help : unicode
         help string for --name flag
     unset_help : unicode
         help string for --no-name flag
     
     Returns
     -------
     
     cfg : dict
         A dict with two keys: 'name', and 'no-name', for setting and unsetting
         the trait, respectively.
     """
     # default helpstrings
     set_help = set_help or "set %s=True"%configurable
     unset_help = unset_help or "set %s=False"%configurable
     
     cls,trait = configurable.split('.')
     
     setter = {cls : {trait : True}}
     unsetter = {cls : {trait : False}}
     return {name : (setter, set_help), 'no-'+name : (unsetter, unset_help)}
 

IPython/core/application.py

@@ -1,309 +1,313 b''
 # encoding: utf-8
 """
 An application for IPython.
 
 All top-level applications should use the classes in this module for
 handling configuration and creating componenets.
 
 The job of an :class:`Application` is to create the master configuration 
 object and then create the configurable objects, passing the config to them.
 
 Authors:
 
 * Brian Granger
 * Fernando Perez
 * Min RK
 
 """
 
 #-----------------------------------------------------------------------------
 #  Copyright (C) 2008-2011  The IPython Development Team
 #
 #  Distributed under the terms of the BSD License.  The full license is in
 #  the file COPYING, distributed as part of this software.
 #-----------------------------------------------------------------------------
 
 #-----------------------------------------------------------------------------
 # Imports
 #-----------------------------------------------------------------------------
 
 import glob
 import logging
 import os
 import shutil
 import sys
 
 from IPython.config.application import Application
 from IPython.config.configurable import Configurable
 from IPython.config.loader import Config
 from IPython.core import release, crashhandler
 from IPython.core.profiledir import ProfileDir, ProfileDirError
 from IPython.utils.path import get_ipython_dir, get_ipython_package_dir
 from IPython.utils.traitlets import List, Unicode, Type, Bool, Dict
 
 #-----------------------------------------------------------------------------
 # Classes and functions
 #-----------------------------------------------------------------------------
 
 
 #-----------------------------------------------------------------------------
 # Base Application Class
 #-----------------------------------------------------------------------------
 
 # aliases and flags
 
 base_aliases = {
     'profile' : 'BaseIPythonApplication.profile',
     'ipython-dir' : 'BaseIPythonApplication.ipython_dir',
     'log-level' : 'Application.log_level',
 }
 
 base_flags = dict(
     debug = ({'Application' : {'log_level' : logging.DEBUG}},
             "set log level to logging.DEBUG (maximize logging output)"),
     quiet = ({'Application' : {'log_level' : logging.CRITICAL}},
             "set log level to logging.CRITICAL (minimize logging output)"),
     init = ({'BaseIPythonApplication' : {
                     'copy_config_files' : True,
                     'auto_create' : True}
             }, """Initialize profile with default config files.  This is equivalent
             to running `ipython profile create <profile>` prior to startup.
             """)
 )
 
 
 class BaseIPythonApplication(Application):
 
     name = Unicode(u'ipython')
     description = Unicode(u'IPython: an enhanced interactive Python shell.')
     version = Unicode(release.version)
     
     aliases = Dict(base_aliases)
     flags = Dict(base_flags)
     classes = List([ProfileDir])
     
     # Track whether the config_file has changed,
     # because some logic happens only if we aren't using the default.
     config_file_specified = Bool(False)
     
     config_file_name = Unicode(u'ipython_config.py')
     def _config_file_name_default(self):
         return self.name.replace('-','_') + u'_config.py'
     def _config_file_name_changed(self, name, old, new):
         if new != old:
             self.config_file_specified = True
 
     # The directory that contains IPython's builtin profiles.
     builtin_profile_dir = Unicode(
         os.path.join(get_ipython_package_dir(), u'config', u'profile', u'default')
     )
 
     config_file_paths = List(Unicode)
     def _config_file_paths_default(self):
         return [os.getcwdu()]
 
     profile = Unicode(u'default', config=True,
         help="""The IPython profile to use."""
     )
     def _profile_changed(self, name, old, new):
         self.builtin_profile_dir = os.path.join(
                 get_ipython_package_dir(), u'config', u'profile', new
         )
     
     ipython_dir = Unicode(get_ipython_dir(), config=True, 
         help="""
         The name of the IPython directory. This directory is used for logging
         configuration (through profiles), history storage, etc. The default
         is usually $HOME/.ipython. This options can also be specified through
         the environment variable IPYTHON_DIR.
         """
     )
     
     overwrite = Bool(False, config=True,
         help="""Whether to overwrite existing config files when copying""")
     auto_create = Bool(False, config=True,
         help="""Whether to create profile dir if it doesn't exist""")
     
     config_files = List(Unicode)
     def _config_files_default(self):
         return [u'ipython_config.py']
     
     copy_config_files = Bool(False, config=True,
         help="""Whether to install the default config files into the profile dir.
         If a new profile is being created, and IPython contains config files for that
         profile, then they will be staged into the new directory.  Otherwise,
         default config files will be automatically generated.
         """)
 
     # The class to use as the crash handler.
     crash_handler_class = Type(crashhandler.CrashHandler)
 
     def __init__(self, **kwargs):
         super(BaseIPythonApplication, self).__init__(**kwargs)
         # ensure even default IPYTHON_DIR exists
         if not os.path.exists(self.ipython_dir):
             self._ipython_dir_changed('ipython_dir', self.ipython_dir, self.ipython_dir)
     
     #-------------------------------------------------------------------------
     # Various stages of Application creation
     #-------------------------------------------------------------------------
 
     def init_crash_handler(self):
         """Create a crash handler, typically setting sys.excepthook to it."""
         self.crash_handler = self.crash_handler_class(self)
         sys.excepthook = self.crash_handler
 
     def _ipython_dir_changed(self, name, old, new):
         if old in sys.path:
             sys.path.remove(old)
         sys.path.append(os.path.abspath(new))
         if not os.path.isdir(new):
             os.makedirs(new, mode=0777)
         readme = os.path.join(new, 'README')
         if not os.path.exists(readme):
             path = os.path.join(get_ipython_package_dir(), u'config', u'profile')
             shutil.copy(os.path.join(path, 'README'), readme)
         self.log.debug("IPYTHON_DIR set to: %s" % new)
 
     def load_config_file(self, suppress_errors=True):
         """Load the config file.
 
         By default, errors in loading config are handled, and a warning
         printed on screen. For testing, the suppress_errors option is set
         to False, so errors will make tests fail.
         """
+        self.log.debug("Searching path %s for config files", self.config_file_paths)
         base_config = 'ipython_config.py'
         self.log.debug("Attempting to load config file: %s" %
                        base_config)
         try:
             Application.load_config_file(
                 self,
                 base_config, 
                 path=self.config_file_paths
             )
         except IOError:
             # ignore errors loading parent
+            self.log.debug("Config file %s not found", base_config)
             pass
         if self.config_file_name == base_config:
             # don't load secondary config
             return
         self.log.debug("Attempting to load config file: %s" %
                        self.config_file_name)
         try:
             Application.load_config_file(
                 self,
                 self.config_file_name, 
                 path=self.config_file_paths
             )
         except IOError:
             # Only warn if the default config file was NOT being used.
             if self.config_file_specified:
-                self.log.warn("Config file not found, skipping: %s" %
-                               self.config_file_name)
+                msg = self.log.warn
+            else:
+                msg = self.log.debug
+            msg("Config file not found, skipping: %s", self.config_file_name)
         except:
             # For testing purposes.
             if not suppress_errors:
                 raise
             self.log.warn("Error loading config file: %s" %
                           self.config_file_name, exc_info=True)
 
     def init_profile_dir(self):
         """initialize the profile dir"""
         try:
             # location explicitly specified:
             location = self.config.ProfileDir.location
         except AttributeError:
             # location not specified, find by profile name
             try:
                 p = ProfileDir.find_profile_dir_by_name(self.ipython_dir, self.profile, self.config)
             except ProfileDirError:
                 # not found, maybe create it (always create default profile)
                 if self.auto_create or self.profile=='default':
                     try:
                         p = ProfileDir.create_profile_dir_by_name(self.ipython_dir, self.profile, self.config)
                     except ProfileDirError:
                         self.log.fatal("Could not create profile: %r"%self.profile)
                         self.exit(1)
                     else:
                         self.log.info("Created profile dir: %r"%p.location)
                 else:
                     self.log.fatal("Profile %r not found."%self.profile)
                     self.exit(1)
             else:
                 self.log.info("Using existing profile dir: %r"%p.location)
         else:
             # location is fully specified
             try:
                 p = ProfileDir.find_profile_dir(location, self.config)
             except ProfileDirError:
                 # not found, maybe create it
                 if self.auto_create:
                     try:
                         p = ProfileDir.create_profile_dir(location, self.config)
                     except ProfileDirError:
                         self.log.fatal("Could not create profile directory: %r"%location)
                         self.exit(1)
                     else:
                         self.log.info("Creating new profile dir: %r"%location)
                 else:
                     self.log.fatal("Profile directory %r not found."%location)
                     self.exit(1)
             else:
                 self.log.info("Using existing profile dir: %r"%location)
         
         self.profile_dir = p
         self.config_file_paths.append(p.location)
     
     def init_config_files(self):
         """[optionally] copy default config files into profile dir."""
         # copy config files
         path = self.builtin_profile_dir
         if self.copy_config_files:
             src = self.profile
             
             cfg = self.config_file_name
             if path and os.path.exists(os.path.join(path, cfg)):
                 self.log.warn("Staging %r from %s into %r [overwrite=%s]"%(
                         cfg, src, self.profile_dir.location, self.overwrite)
                 )
                 self.profile_dir.copy_config_file(cfg, path=path, overwrite=self.overwrite)
             else:
                 self.stage_default_config_file()
         else:
             # Still stage *bundled* config files, but not generated ones
             # This is necessary for `ipython profile=sympy` to load the profile
             # on the first go
             files = glob.glob(os.path.join(path, '*.py'))
             for fullpath in files:
                 cfg = os.path.basename(fullpath)
                 if self.profile_dir.copy_config_file(cfg, path=path, overwrite=False):
                     # file was copied
                     self.log.warn("Staging bundled %s from %s into %r"%(
                             cfg, self.profile, self.profile_dir.location)
                     )
             
     
     def stage_default_config_file(self):
         """auto generate default config file, and stage it into the profile."""
         s = self.generate_config_file()
         fname = os.path.join(self.profile_dir.location, self.config_file_name)
         if self.overwrite or not os.path.exists(fname):
             self.log.warn("Generating default config file: %r"%(fname))
             with open(fname, 'w') as f:
                 f.write(s)
         
     
     def initialize(self, argv=None):
         # don't hook up crash handler before parsing command-line
         self.parse_command_line(argv)
         self.init_crash_handler()
         if self.subapp is not None:
             # stop here if subapp is taking over
             return
         cl_config = self.config
         self.init_profile_dir()
         self.init_config_files()
         self.load_config_file()
         # enforce cl-opts override configfile opts:
         self.update_config(cl_config)