Per-module logger, add cli switch to log debug

when using lesana as a library, having a per-module logger is better
instead of logging everything in root.

When `lesana` cli command is used, logger is configured to print simple
logline and loglevel is set to INFO, unless user pass the option `-v` or
`--verbose` which sets the level to DEBUG

4 files changed, 57 insertions, 37 deletions

diff --git a/lesana/collection.py b/lesana/collection.py
index c148890..41dd23f 100644
--- a/lesana/collection.py
+++ b/lesana/collection.py
@@ -12,6 +12,8 @@ import jinja2
 from pkg_resources import resource_string, resource_filename
 from . import types, templating
 
+logger = logging.getLogger(__name__)
+
 try:
     import git
 
@@ -65,7 +67,7 @@ class Entry(object):
                         indent=0
                     )
                 except AttributeError:
-                    logging.warning(
+                    logger.warning(
                         "Not adding comments because they are not"
                         "supported by the yaml loader."
                     )
@@ -161,7 +163,7 @@ class Collection(object):
             try:
                 self.stemmer = xapian.Stem(self.settings['lang'])
             except xapian.InvalidArgumentError:
-                logging.warning(
+                logger.warning(
                     "Invalid language %s, in settings.yaml: using english.",
                     self.settings['lang'],
                 )
@@ -195,7 +197,7 @@ class Collection(object):
                 # unknown fields are treated as if they were
                 # (unvalidated) generic YAML to support working with
                 # collections based on lesana derivatives
-                logging.warning(
+                logger.warning(
                     "Unknown field type %s in field %s",
                     field['type'],
                     field['name'],
@@ -209,7 +211,7 @@ class Collection(object):
         entry = self.entry_class(self, data, fname)
         valid, errors = entry.validate()
         if not valid:
-            logging.warning(
+            logger.warning(
                 "Not indexing {fname}: invalid data".format(fname=fname)
             )
             return False, errors
@@ -268,7 +270,7 @@ class Collection(object):
             try:
                 fnames = os.listdir(self.itemdir)
             except FileNotFoundError:
-                logging.warning(
+                logger.warning(
                     "No such file or directory: {}, not updating cache".format(
                         self.itemdir
                     )
@@ -279,14 +281,14 @@ class Collection(object):
             try:
                 valid, errors = self._index_file(fname, cache)
             except IOError as e:
-                logging.warning(
+                logger.warning(
                     "Could not load file {}: {}".format(fname, str(e))
                 )
             else:
                 if valid:
                     updated += 1
                 else:
-                    logging.warning(
+                    logger.warning(
                         "File {fname} could not be indexed: {errors}".format(
                             fname=fname, errors=errors
                         )
@@ -301,18 +303,18 @@ class Collection(object):
 
     def git_add_files(self, files=[]):
         if not git_available:
-            logging.warning(
+            logger.warning(
                 "python3-git not available, could not initalise "
                 + "the git repository."  # noqa: W503
             )
             return False
         if not self.settings.get('git', False):
-            logging.info("This collection is configured not to use git")
+            logger.info("This collection is configured not to use git")
             return False
         try:
             repo = git.Repo(self.basedir, search_parent_directories=True)
         except git.exc.InvalidGitRepositoryError:
-            logging.warning(
+            logger.warning(
                 "Could not find a git repository in {}".format(self.basedir)
             )
             return False
@@ -325,7 +327,7 @@ class Collection(object):
                 os.path.join(self.basedir, '.lesana/xapian'),
             )
         except xapian.DatabaseOpeningError:
-            logging.info("No database found, indexing entries.")
+            logger.info("No database found, indexing entries.")
             self.update_cache()
             cache = xapian.Database(
                 os.path.join(self.basedir, '.lesana/xapian'),
@@ -421,10 +423,10 @@ class Collection(object):
                 }
 
         else:
-            logging.info(
+            logger.info(
                 "Trying to get the list of values for a non sortable field."
             )
-            logging.info(
+            logger.info(
                 "This is going to be pretty inefficient."
             )
             values = (
@@ -477,7 +479,7 @@ class Collection(object):
                     cache.delete_document(entry.idterm)
                     self.remove_file(entry.fname)
                 else:
-                    logging.warning("No such entry: {}, ignoring".format(eid))
+                    logger.warning("No such entry: {}, ignoring".format(eid))
         cache.commit()
         cache.close()
 
@@ -487,7 +489,7 @@ class Collection(object):
             try:
                 repo = git.Repo(self.basedir, search_parent_directories=True)
             except git.exc.InvalidGitRepositoryError:
-                logging.warning(
+                logger.warning(
                     "Could not find a git repository in {}".format(
                         self.basedir
                     )
@@ -542,7 +544,7 @@ class Collection(object):
             if git_available:
                 repo = git.Repo.init(c_dir, bare=False)
             else:
-                logging.warning(
+                logger.warning(
                     "python3-git not available, could not initalise "
                     + "the git repository."  # noqa: W503
                 )
diff --git a/lesana/command.py b/lesana/command.py
index 564b7e1..6d2a753 100644
--- a/lesana/command.py
+++ b/lesana/command.py
@@ -8,6 +8,7 @@ import ruamel.yaml
 
 from . import Collection, Entry, TemplatingError
 
+logger = logging.getLogger(__name__)
 
 def _get_first_docstring_line(obj):
     try:
@@ -25,6 +26,9 @@ class MainCommand:
     def main(self):
         desc = _get_first_docstring_line(self)
         self.parser = argparse.ArgumentParser(description=desc)
+        self.parser.add_argument('--verbose', '-v',
+                                 action='store_true',
+                                 help="Display debug messages")
         self.parser.set_defaults(func=self._main)
         self.subparsers = self.parser.add_subparsers()
         for name, sub in self.commands:
@@ -38,6 +42,10 @@ class MainCommand:
                 s_parser.add_argument(*arg[0], **arg[1])
             s_parser.set_defaults(func=sub._main)
         self.args = self.parser.parse_args()
+
+        if self.args.verbose:
+            logging.getLogger('lesana').setLevel(logging.DEBUG)
+
         self.args.func(self.args)
 
 
@@ -58,14 +66,14 @@ class Command:
                 subprocess.call([editor, filepath])
             except FileNotFoundError as e:
                 if editor in str(e):
-                    logging.info(
+                    logger.info(
                         'Could not open file {} with $EDITOR (currently {})'
                         .format(
                             filepath, editor
                         )
                     )
                 else:
-                    logging.warning("Could not open file {}".format(filepath))
+                    logger.warning("Could not open file {}".format(filepath))
                     return False
             else:
                 return True
@@ -75,12 +83,12 @@ class Command:
             subprocess.call(['sensible-editor', filepath])
         except FileNotFoundError as e:
             if 'sensible-editor' in e.strerror:
-                logging.debug(
+                logger.debug(
                     "Could not open file {} with editor: sensible-editor"
                     .format(filepath)
                 )
             else:
-                logging.warning("Could not open file {}".format(filepath))
+                logger.warning("Could not open file {}".format(filepath))
                 return False
         else:
             return True
@@ -90,14 +98,14 @@ class Command:
             subprocess.call(['vi', filepath])
         except FileNotFoundError as e:
             if 'vi' in e.strerror:
-                logging.warning(
+                logger.warning(
                     "Could not open file {} with any known editor".format(
                         filepath
                     )
                 )
                 return False
             else:
-                logging.warning("Could not open file {}".format(filepath))
+                logger.warning("Could not open file {}".format(filepath))
                 return False
         else:
             return True
@@ -208,7 +216,7 @@ class Show(Command):
             try:
                 print(entry.render(self.args.template))
             except TemplatingError as e:
-                logging.error("{}".format(e))
+                logger.error("{}".format(e))
                 sys.exit(1)
         else:
             print(entry.yaml_data)
@@ -289,12 +297,12 @@ class Search(Command):
     def main(self):
         # TODO: implement "searching" for everything
         if self.args.offset:
-            logging.warning(
+            logger.warning(
                 "offset exposes an internal knob and MAY BE REMOVED "
                 + "from a future release of lesana"  # noqa: W503
             )
         if self.args.pagesize:
-            logging.warning(
+            logger.warning(
                 "pagesize exposes an internal knob and MAY BE REMOVED "
                 + "from a future release of lesana"  # noqa: W503
             )
@@ -322,7 +330,7 @@ class Search(Command):
                 template = collection.get_template(self.args.template)
                 print(template.render(entries=results))
             except TemplatingError as e:
-                logging.error("{}".format(e))
+                logger.error("{}".format(e))
                 sys.exit(1)
         else:
             for entry in results:
@@ -375,7 +383,7 @@ class GetValues(Command):
                 template = collection.get_template(self.args.template)
                 print(template.render(counts=counts))
             except TemplatingError as e:
-                logging.error("{}".format(e))
+                logger.error("{}".format(e))
                 sys.exit(1)
         else:
             for v in counts:
@@ -415,15 +423,15 @@ class Export(Command):
                 template = collection.get_template(self.args.template)
                 rendered = template.render(entry=entry, **entry.data)
             except TemplatingError as e:
-                logging.error("Error converting entry: {}".format(entry))
-                logging.error("{}".format(e))
+                logger.error("Error converting entry: {}".format(entry))
+                logger.error("{}".format(e))
                 sys.exit(1)
             try:
                 data = ruamel.yaml.load(rendered, ruamel.yaml.RoundTripLoader)
             except ruamel.yaml.YAMLError as e:
-                logging.error("Error loading exported entry: {}".format(entry))
-                logging.error("exported data was\n{}".format(rendered))
-                logging.error("{}".format(e))
+                logger.error("Error loading exported entry: {}".format(entry))
+                logger.error("exported data was\n{}".format(rendered))
+                logger.error("{}".format(e))
                 sys.exit(1)
             e = self.entry_class(destination, data=data)
             destination.save_entries([e])
diff --git a/lesana/types.py b/lesana/types.py
index 677fbdf..37753d1 100644
--- a/lesana/types.py
+++ b/lesana/types.py
@@ -12,6 +12,7 @@ import dateutil.parser
 
 import xapian
 
+logger = logging.getLogger(__name__)
 
 class LesanaType:
     """
@@ -62,7 +63,7 @@ class LesanaType:
         if not to_index:
             return
         if not value:
-            logging.info(
+            logger.info(
                 "Not indexing empty value {}".format(value)
             )
             return
@@ -75,7 +76,7 @@ class LesanaType:
             if self.value_index and self.value_index >= 16:
                 doc.add_value(self.value_index, self._to_value(value))
             else:
-                logging.debug(
+                logger.debug(
                     "Index values up to 15 are reserved for internal use"
                 )
 
@@ -147,7 +148,7 @@ class LesanaInt(LesanaType):
             if int(increment) == increment:
                 return value + increment
             else:
-                logging.warning(
+                logger.warning(
                     "Invalid configuration value for increment in field %s: "
                     + "%s",
                     self.field['name'],
@@ -381,7 +382,7 @@ class LesanaList(LesanaType):
         try:
             self.sub_type = types[field['list']](field, types)
         except KeyError:
-            logging.warning(
+            logger.warning(
                 "Unknown field type %s in field %s",
                 field['type'],
                 field['name'],
diff --git a/scripts/lesana b/scripts/lesana
index 51d5f7a..8f38a67 100755
--- a/scripts/lesana
+++ b/scripts/lesana
@@ -2,7 +2,7 @@
 """
 Lesana Command Line interface
 """
-
+import logging
 import lesana.command
 
 
@@ -26,4 +26,13 @@ class Lesana(lesana.command.MainCommand):
 
 
 if __name__ == "__main__":
+
+    # setup logging for lesana cli
+    logger = logging.getLogger('lesana')
+    ch = logging.StreamHandler()
+    formatter = logging.Formatter('%(levelname)s: %(message)s')
+    ch.setFormatter(formatter)
+    logger.addHandler(ch)
+    logger.setLevel(logging.INFO)
+
     Lesana().main()