cookiecutter · hackebrot · Sep 11, 2016 · Jul 31, 2016 · Jul 31, 2016 · Jul 31, 2016
diff --git a/cookiecutter/cli.py b/cookiecutter/cli.py
@@ -9,13 +9,13 @@
 
 import os
 import sys
-import logging
 import json
 
 import click
 
 from cookiecutter import __version__
 from cookiecutter.config import USER_CONFIG_PATH
+from cookiecutter.log import configure_logger
 from cookiecutter.main import cookiecutter
 from cookiecutter.exceptions import (
     OutputDirExistsException,
@@ -27,8 +27,6 @@
     RepositoryCloneFailed
 )
 
-logger = logging.getLogger(__name__)
-
 
 def version_msg():
     """Returns the Cookiecutter version, location and Python powering it."""
@@ -89,28 +87,28 @@ def validate_extra_context(ctx, param, value):
     u'--default-config', is_flag=True,
     help=u'Do not load a config file. Use the defaults instead'
 )
-def main(template, extra_context, no_input, checkout, verbose, replay,
-         overwrite_if_exists, output_dir, config_file, default_config):
+@click.option(
+    u'--debug-file', type=click.Path(), default=None,
+    help=u'File to be used as a stream for DEBUG logging',
+)
+def main(
+        template, extra_context, no_input, checkout, verbose,
+        replay, overwrite_if_exists, output_dir, config_file,
+        default_config, debug_file):
     """Create a project from a Cookiecutter project template (TEMPLATE)."""
-    if verbose:
-        logging.basicConfig(
-            format=u'%(levelname)s %(filename)s: %(message)s',
-            level=logging.DEBUG
-        )
-    else:
-        # Log info and above to console
-        logging.basicConfig(
-            format=u'%(levelname)s: %(message)s',
-            level=logging.INFO
-        )
 
-    try:
-        # If you _need_ to support a local template in a directory
-        # called 'help', use a qualified path to the directory.
-        if template == u'help':
-            click.echo(click.get_current_context().get_help())
-            sys.exit(0)
+    # If you _need_ to support a local template in a directory
+    # called 'help', use a qualified path to the directory.
+    if template == u'help':
+        click.echo(click.get_current_context().get_help())
+        sys.exit(0)
 
+    configure_logger(
+        stream_level='DEBUG' if verbose else 'INFO',
+        debug_file=debug_file,
+    )
+
+    try:
         user_config = None if default_config else config_file
 
         cookiecutter(

diff --git a/cookiecutter/find.py b/cookiecutter/find.py
@@ -7,14 +7,16 @@
 
 from .exceptions import NonTemplatedInputDirException
 
+logger = logging.getLogger(__name__)
+
 
 def find_template(repo_dir):
     """Determine which child directory of `repo_dir` is the project template.
 
     :param repo_dir: Local directory of newly cloned repo.
     :returns project_template: Relative path to project template.
     """
-    logging.debug('Searching {0} for the project template.'.format(repo_dir))
+    logger.debug('Searching {} for the project template.'.format(repo_dir))
 
     repo_dir_contents = os.listdir(repo_dir)
 
@@ -26,8 +28,8 @@ def find_template(repo_dir):
 
     if project_template:
         project_template = os.path.join(repo_dir, project_template)
-        logging.debug(
-            'The project template appears to be {0}'.format(project_template)
+        logger.debug(
+            'The project template appears to be {}'.format(project_template)
         )
         return project_template
     else:

diff --git a/cookiecutter/generate.py b/cookiecutter/generate.py
@@ -26,6 +26,8 @@
 from .utils import make_sure_path_exists, work_in, rmtree
 from .hooks import run_hook
 
+logger = logging.getLogger(__name__)
+
 
 def copy_without_render(path, context):
     """Return True if `path` matches context dict pattern.
@@ -104,7 +106,7 @@ def generate_context(context_file='cookiecutter.json', default_context=None,
     if extra_context:
         apply_overwrites_to_context(obj, extra_context)
 
-    logging.debug('Context generated is {0}'.format(context))
+    logger.debug('Context generated is {}'.format(context))
     return context
 
 
@@ -129,24 +131,26 @@ def generate_file(project_dir, infile, context, env):
     :param context: Dict for populating the cookiecutter's variables.
     :param env: Jinja2 template execution environment.
     """
-    logging.debug('Generating file {0}'.format(infile))
+    logger.debug('Processing file {}'.format(infile))
 
     # Render the path to the output file (not including the root project dir)
     outfile_tmpl = env.from_string(infile)
 
     outfile = os.path.join(project_dir, outfile_tmpl.render(**context))
     file_name_is_empty = os.path.isdir(outfile)
     if file_name_is_empty:
-        logging.debug('The resulting file name is empty: {0}'.format(outfile))
+        logger.debug('The resulting file name is empty: {0}'.format(outfile))
         return
 
-    logging.debug('outfile is {0}'.format(outfile))
+    logger.debug('Created file at {0}'.format(outfile))
 
     # Just copy over binary files. Don't render.
-    logging.debug("Check {0} to see if it's a binary".format(infile))
+    logger.debug("Check {} to see if it's a binary".format(infile))
     if is_binary(infile):
-        logging.debug('Copying binary {0} to {1} without rendering'
-                      .format(infile, outfile))
+        logger.debug(
+            'Copying binary {} to {} without rendering'
+            ''.format(infile, outfile)
+        )
         shutil.copyfile(infile, outfile)
     else:
         # Force fwd slashes on Windows for get_template
@@ -163,7 +167,7 @@ def generate_file(project_dir, infile, context, env):
             raise
         rendered_file = tmpl.render(**context)
 
-        logging.debug('Writing {0}'.format(outfile))
+        logger.debug('Writing contents to file {}'.format(outfile))
 
         with io.open(outfile, 'w', encoding='utf-8') as fh:
             fh.write(rendered_file)
@@ -177,20 +181,24 @@ def render_and_create_dir(dirname, context, output_dir, environment,
     """Render name of a directory, create the directory, return its path."""
     name_tmpl = environment.from_string(dirname)
     rendered_dirname = name_tmpl.render(**context)
-    logging.debug('Rendered dir {0} must exist in output_dir {1}'.format(
-        rendered_dirname,
-        output_dir
-    ))
+
     dir_to_create = os.path.normpath(
         os.path.join(output_dir, rendered_dirname)
     )
 
+    logger.debug('Rendered dir {} must exist in output_dir {}'.format(
+        dir_to_create,
+        output_dir
+    ))
+
     output_dir_exists = os.path.exists(dir_to_create)
 
     if overwrite_if_exists:
         if output_dir_exists:
-            logging.debug('Output directory {} already exists,'
-                          'overwriting it'.format(dir_to_create))
+            logger.debug(
+                'Output directory {} already exists,'
+                'overwriting it'.format(dir_to_create)
+            )
     else:
         if output_dir_exists:
             msg = 'Error: "{}" directory already exists'.format(dir_to_create)
@@ -215,8 +223,10 @@ def _run_hook_from_repo_dir(repo_dir, hook_name, project_dir, context):
             run_hook(hook_name, project_dir, context)
         except FailedHookException:
             rmtree(project_dir)
-            logging.error("Stopping generation because %s"
-                          " hook script didn't exit successfully" % hook_name)
+            logger.error(
+                "Stopping generation because {} hook "
+                "script didn't exit successfully".format(hook_name)
+            )
             raise
 
 
@@ -231,7 +241,7 @@ def generate_files(repo_dir, context=None, output_dir='.',
         if it exists.
     """
     template_dir = find_template(repo_dir)
-    logging.debug('Generating project from {0}...'.format(template_dir))
+    logger.debug('Generating project from {}...'.format(template_dir))
     context = context or {}
 
     unrendered_dir = os.path.split(template_dir)[1]
@@ -260,7 +270,7 @@ def generate_files(repo_dir, context=None, output_dir='.',
     # absolute path for the target folder (project_dir)
 
     project_dir = os.path.abspath(project_dir)
-    logging.debug('project_dir is {0}'.format(project_dir))
+    logger.debug('Project directory is {}'.format(project_dir))
 
     _run_hook_from_repo_dir(repo_dir, 'pre_gen_project', project_dir, context)
 
@@ -287,8 +297,8 @@ def generate_files(repo_dir, context=None, output_dir='.',
             for copy_dir in copy_dirs:
                 indir = os.path.normpath(os.path.join(root, copy_dir))
                 outdir = os.path.normpath(os.path.join(project_dir, indir))
-                logging.debug(
-                    'Copying dir {0} to {1} without rendering'
+                logger.debug(
+                    'Copying dir {} to {} without rendering'
                     ''.format(indir, outdir)
                 )
                 shutil.copytree(indir, outdir)
@@ -318,14 +328,13 @@ def generate_files(repo_dir, context=None, output_dir='.',
                     outfile_tmpl = env.from_string(infile)
                     outfile_rendered = outfile_tmpl.render(**context)
                     outfile = os.path.join(project_dir, outfile_rendered)
-                    logging.debug(
-                        'Copying file {0} to {1} without rendering'
+                    logger.debug(
+                        'Copying file {} to {} without rendering'
                         ''.format(infile, outfile)
                     )
                     shutil.copyfile(infile, outfile)
                     shutil.copymode(infile, outfile)
                     continue
-                logging.debug('f is {0}'.format(f))
                 try:
                     generate_file(project_dir, infile, context, env)
                 except UndefinedError as err:

diff --git a/cookiecutter/hooks.py b/cookiecutter/hooks.py
@@ -14,6 +14,8 @@
 from cookiecutter import utils
 from .exceptions import FailedHookException
 
+logger = logging.getLogger(__name__)
+
 
 _HOOKS = [
     'pre_gen_project',
@@ -33,10 +35,10 @@ def find_hooks():
     """
     hooks_dir = 'hooks'
     hooks = {}
-    logging.debug('hooks_dir is {0}'.format(hooks_dir))
+    logger.debug('hooks_dir is {}'.format(hooks_dir))
 
     if not os.path.isdir(hooks_dir):
-        logging.debug('No hooks/ dir in template_dir')
+        logger.debug('No hooks/ dir in template_dir')
         return hooks
 
     for f in os.listdir(hooks_dir):
@@ -105,6 +107,7 @@ def run_hook(hook_name, project_dir, context):
     """
     script = find_hooks().get(hook_name)
     if script is None:
-        logging.debug('No hooks found')
+        logger.debug('No hooks found')
         return
+    logger.debug('Running hook {}'.format(hook_name))
     run_script_with_context(script, project_dir, context)
diff --git a/cookiecutter/log.py b/cookiecutter/log.py
@@ -0,0 +1,47 @@
+# -*- coding: utf-8 -*-
+
+import logging
+import sys
+
+LOG_LEVELS = {
+    'DEBUG': logging.DEBUG,
+    'INFO': logging.INFO,
+    'WARNING': logging.WARNING,
+    'ERROR': logging.ERROR,
+    'CRITICAL': logging.CRITICAL,
+}
+
+LOG_FORMATS = {
+    'DEBUG': u'%(levelname)s %(name)s: %(message)s',
+    'INFO': u'%(levelname)s: %(message)s',
+}
+
+
+def configure_logger(stream_level='DEBUG', debug_file=None):
+    # Set up 'cookiecutter' logger
+    logger = logging.getLogger('cookiecutter')
+    logger.setLevel(logging.DEBUG)
+
+    # Remove all attached handlers, in case there was
+    # a logger with using the name 'cookiecutter'
+    del logger.handlers[:]
+
+    # Create a file handler if a log file is provided
+    if debug_file is not None:
+        debug_formatter = logging.Formatter(LOG_FORMATS['DEBUG'])
+        file_handler = logging.FileHandler(debug_file)
+        file_handler.setLevel(LOG_LEVELS['DEBUG'])
+        file_handler.setFormatter(debug_formatter)
+        logger.addHandler(file_handler)
+
+    # Get settings based on the given stream_level
+    log_formatter = logging.Formatter(LOG_FORMATS[stream_level])
+    log_level = LOG_LEVELS[stream_level]
+
+    # Create a stream handler
+    stream_handler = logging.StreamHandler(stream=sys.stdout)
+    stream_handler.setLevel(log_level)
+    stream_handler.setFormatter(log_formatter)
+    logger.addHandler(stream_handler)
+
+    return logger
diff --git a/cookiecutter/main.py b/cookiecutter/main.py
@@ -67,7 +67,7 @@ def cookiecutter(
         context = load(config_dict['replay_dir'], template_name)
     else:
         context_file = os.path.join(repo_dir, 'cookiecutter.json')
-        logging.debug('context_file is {0}'.format(context_file))
+        logger.debug('context_file is {}'.format(context_file))
 
         context = generate_context(
             context_file=context_file,

diff --git a/cookiecutter/utils.py b/cookiecutter/utils.py
@@ -15,6 +15,8 @@
 import stat
 import shutil
 
+logger = logging.getLogger(__name__)
+
 
 def force_delete(func, path, exc_info):
     """
@@ -44,9 +46,10 @@ def make_sure_path_exists(path):
     :param path: A directory path.
     """
 
-    logging.debug('Making sure path exists: {0}'.format(path))
+    logger.debug('Making sure path exists: {}'.format(path))
     try:
         os.makedirs(path)
+        logger.debug('Created directory at: {}'.format(path))
     except OSError as exception:
         if exception.errno != errno.EEXIST:
             return False

diff --git a/cookiecutter/vcs.py b/cookiecutter/vcs.py
@@ -21,6 +21,8 @@
 from .prompt import read_user_yes_no
 from .utils import make_sure_path_exists, rmtree
 
+logger = logging.getLogger(__name__)
+
 
 BRANCH_ERRORS = [
     'error: pathspec',
@@ -42,8 +44,8 @@ def prompt_and_delete_repo(repo_dir, no_input=False):
         ok_to_delete = True
     else:
         question = (
-            "You've cloned {0} before. "
-            'Is it okay to delete and re-clone it?'
+            "You've cloned {} before. "
+            "Is it okay to delete and re-clone it?"
         ).format(repo_dir)
 
         ok_to_delete = read_user_yes_no(question, 'yes')
@@ -117,7 +119,7 @@ def clone(repo_url, checkout=None, clone_to_dir='.', no_input=False):
                                                  tail.rsplit('.git')[0]))
     elif repo_type == 'hg':
         repo_dir = os.path.normpath(os.path.join(clone_to_dir, tail))
-    logging.debug('repo_dir is {0}'.format(repo_dir))
+    logger.debug('repo_dir is {0}'.format(repo_dir))
 
     if os.path.isdir(repo_dir):
         prompt_and_delete_repo(repo_dir, no_input=no_input)