Kill twiggy.

I used it on a whim when I first started writing bugwarrior, but it has
proved to be annoying.  It has problems interpolating strings when we
don't want it to and it has all kinds of weird encoding handling that
keeps raising new bugs.

The stdlib logging is sufficient.

bugwarrior/command.py

@@ -1,10 +1,8 @@
 import os
 
-from twiggy import log
 from lockfile import LockTimeout
 from lockfile.pidlockfile import PIDLockFile
 
-import twiggy
 import getpass
 import keyring
 import click
@@ -16,6 +14,9 @@
     synchronize,
 )
 
+import logging
+log = logging.getLogger(__name__)
+
 
 # We overwrite 'list' further down.
 lst = list
@@ -37,7 +38,7 @@ def pull(dry_run, flavor, interactive, debug):
 
     Relies on configuration in bugwarriorrc
     """
-    twiggy.quickSetup()
+
     try:
         main_section = _get_section_name(flavor)
 
@@ -56,17 +57,17 @@ def pull(dry_run, flavor, interactive, debug):
         finally:
             lockfile.release()
     except LockTimeout:
-        log.name('command').critical(
+        log.critical(
             'Your taskrc repository is currently locked. '
             'Remove the file at %s if you are sure no other '
             'bugwarrior processes are currently running.' % (
                 lockfile_path
             )
         )
     except RuntimeError as e:
-        log.name('command').critical("Aborted (%s)" % e)
+        log.critical("Aborted (%s)" % e)
     except:
-        log.name('command').trace('error').critical('oh noes')
+        log.exception('oh noes')
 
 
 @click.group()

bugwarrior/config.py

@@ -5,11 +5,11 @@
 import sys
 
 import six
-import twiggy
-from twiggy import log
-from twiggy.levels import name2level
 from xdg import BaseDirectory
 
+import logging
+log = logging.getLogger(__name__)
+
 
 def asbool(some_value):
     """ Cast config values to boolean. """
@@ -90,16 +90,16 @@ def load_example_rc():
 error_template = """
 *************************************************
 * There was a problem with your bugwarriorrc    *
-*   {msg}
+*   {error_msg}
 * Here's an example template to help:           *
 *************************************************
 {example}"""
 
 
-def die(msg):
-    log.options(suppress_newlines=False).critical(
+def die(error_msg):
+    log.critical(
         error_template,
-        msg=msg,
+        error_msg=error_msg,
         example=load_example_rc(),
     )
     sys.exit(1)
@@ -109,11 +109,22 @@ def validate_config(config, main_section):
     if not config.has_section(main_section):
         die("No [%s] section found." % main_section)
 
-    twiggy.quickSetup(
-        name2level(config.get(main_section, 'log.level')),
-        config.get(main_section, 'log.file')
+    logging.basicConfig(
+        level=getattr(logging, config.get(main_section, 'log.level')),
+        filename=config.get(main_section, 'log.file'),
     )
 
+    # In general, its nice to log "everything", but some of the loggers from
+    # our dependencies are very very spammy.  Here, we silence most of their
+    # noise:
+    spammers = [
+        'bugzilla.base',
+        'bugzilla.bug',
+        'requests.packages.urllib3.connectionpool',
+    ]
+    for spammer in spammers:
+        logging.getLogger(spammer).setLevel(logging.WARN)
+
     if not config.has_option(main_section, 'targets'):
         die("No targets= item in [%s] found." % main_section)
 
@@ -141,7 +152,7 @@ def validate_config(config, main_section):
 
 
 def load_config(main_section, interactive=False):
-    config = ConfigParser({'log.level': "DEBUG", 'log.file': None})
+    config = ConfigParser({'log.level': "INFO", 'log.file': None})
     path = None
     first_path = BaseDirectory.load_first_config('bugwarrior')
     if first_path is not None:

bugwarrior/db.py

@@ -8,13 +8,15 @@
 import requests
 import dogpile.cache
 import six
-from twiggy import log
 from taskw import TaskWarriorShellout
 from taskw.exceptions import TaskwarriorError
 
 from bugwarrior.config import asbool, get_taskrc_path
 from bugwarrior.notifications import send_notification
 
+import logging
+log = logging.getLogger(__name__)
+
 
 MARKUP = "(bw)"
 
@@ -66,17 +68,6 @@ def get_normalized_annotation(annotation):
     )
 
 
-def sanitize(string):
-    """ Sanitize a string for logging with twiggy.
-
-    It is obnoxious that we have to do this ourselves, but twiggy doesn't like
-    strings with non-ascii characters or with curly braces in them.
-    """
-    if not isinstance(string, six.string_types):
-        return string
-    return six.text_type(string.replace('{', '{{').replace('}', '}}'))
-
-
 def get_annotation_hamming_distance(left, right):
     left = get_normalized_annotation(left)
     right = get_normalized_annotation(right)
@@ -256,19 +247,12 @@ def merge_left(field, local_task, remote_issue, hamming=False):
                 found = True
                 break
         if not found:
-            log.name('db').debug(
-                "%s not found in %r" % (remote, local_field)
-            )
+            log.debug("%s not found in %r" % (remote, local_field))
             local_task[field].append(remote)
             new_count += 1
     if new_count > 0:
-        log.name('db').debug(
-            'Added %s new values to %s (total: %s)' % (
-                new_count,
-                field,
-                len(local_task[field]),
-            )
-        )
+        log.debug('Added %s new values to %s (total: %s)' % (
+            new_count, field, len(local_task[field]),))
 
 
 def run_hooks(conf, name):
@@ -283,7 +267,7 @@ def run_hooks(conf, name):
                     msg = 'Non-zero exit code %d on hook %s' % (
                         exit_code, hook
                     )
-                    log.name('hooks:%s' % name).error(msg)
+                    log.error(msg)
                     raise RuntimeError(msg)
 
 
@@ -300,7 +284,7 @@ def _bool_option(section, option, default):
     uda_list = build_uda_config_overrides(services)
 
     if uda_list:
-        log.name('bugwarrior').info(
+        log.info(
             'Service-defined UDAs exist: you can optionally use the '
             '`bugwarrior-uda` command to export a list of UDAs you can '
             'add to your ~/.taskrc file.'
@@ -366,20 +350,16 @@ def _bool_option(section, option, default):
                 issue_updates['closed'].remove(existing_uuid)
 
         except MultipleMatches as e:
-            log.name('db').error("Multiple matches: {0}", six.text_type(e))
-            log.name('db').trace(e)
+            log.exception("Multiple matches: %s", six.text_type(e))
         except NotFound:
             issue_updates['new'].append(dict(issue))
 
     notreally = ' (not really)' if dry_run else ''
     # Add new issues
-    log.name('db').info("Adding {0} tasks", len(issue_updates['new']))
+    log.info("Adding %i tasks", len(issue_updates['new']))
     for issue in issue_updates['new']:
-        log.name('db').info(
-            "Adding task {0}{1}",
-            issue['description'].encode("utf-8"),
-            notreally
-        )
+        log.info("Adding task %s%s",
+            issue['description'].encode("utf-8"), notreally)
         if dry_run:
             continue
         if notify:
@@ -388,10 +368,9 @@ def _bool_option(section, option, default):
         try:
             tw.task_add(**issue)
         except TaskwarriorError as e:
-            log.name('db').error("Unable to add task: %s" % e.stderr)
-            log.name('db').trace(e)
+            log.exception("Unable to add task: %s" % e.stderr)
 
-    log.name('db').info("Updating {0} tasks", len(issue_updates['changed']))
+    log.info("Updating %i tasks", len(issue_updates['changed']))
     for issue in issue_updates['changed']:
         changes = '; '.join([
             '{field}: {f} -> {t}'.format(
@@ -401,8 +380,8 @@ def _bool_option(section, option, default):
             )
             for field, ch in six.iteritems(issue.get_changes(keep=True))
         ])
-        log.name('db').info(
-            "Updating task {0}, {1}; {2}{3}",
+        log.info(
+            "Updating task %s, %s; %s%s",
             six.text_type(issue['uuid']).encode("utf-8"),
             issue['description'].encode("utf-8"),
             changes,
@@ -414,14 +393,13 @@ def _bool_option(section, option, default):
         try:
             tw.task_update(issue)
         except TaskwarriorError as e:
-            log.name('db').error("Unable to modify task: %s" % e.stderr)
-            log.name('db').trace(e)
+            log.exception("Unable to modify task: %s" % e.stderr)
 
-    log.name('db').info("Closing {0} tasks", len(issue_updates['closed']))
+    log.info("Closing %i tasks", len(issue_updates['closed']))
     for issue in issue_updates['closed']:
         _, task_info = tw.get_task(uuid=issue)
-        log.name('db').info(
-            "Completing task {0} {1}{2}",
+        log.info(
+            "Completing task %s %s%s",
             issue,
             task_info.get('description', '').encode('utf-8'),
             notreally
@@ -435,8 +413,7 @@ def _bool_option(section, option, default):
         try:
             tw.task_done(uuid=issue)
         except TaskwarriorError as e:
-            log.name('db').error("Unable to close task: %s" % e.stderr)
-            log.name('db').trace(e)
+            log.exception("Unable to close task: %s" % e.stderr)
 
     # Send notifications
     if notify:

bugwarrior/services/__init__.py

@@ -11,13 +11,15 @@
 from jinja2 import Template
 import pytz
 import six
-from twiggy import log
 
 from taskw.task import Task
 
 from bugwarrior.config import asbool, die, get_service_password
 from bugwarrior.db import MARKUP, URLShortener
 
+import logging
+log = logging.getLogger(__name__)
+
 
 # Sentinels for process completion status
 SERVICE_FINISHED_OK = 0
@@ -90,7 +92,7 @@ def __init__(self, config, main_section, target):
         if config.has_option(self.target, 'default_priority'):
             self.default_priority = config.get(self.target, 'default_priority')
 
-        log.name(target).info("Working on [{0}]", self.target)
+        log.info("Working on [%s]", self.target)
 
     def get_templates(self):
         """ Get any defined templates for configuration values.
@@ -514,34 +516,28 @@ def _aggregate_issues(conf, main_section, target, queue, service_name):
             queue.put(issue)
             issue_count += 1
     except SystemExit as e:
-        log.name(target).critical(str(e))
+        log.critical(str(e))
         queue.put((SERVICE_FINISHED_ERROR, (target, e)))
     except BaseException as e:
-        log.name(target).trace('error').critical(
-            "Worker for [%s] failed: %s" % (target, e)
-        )
-        queue.put(
-            (SERVICE_FINISHED_ERROR, (target, e))
-        )
+        log.exception("Worker for [%s] failed: %s" % (target, e))
+        queue.put((SERVICE_FINISHED_ERROR, (target, e)))
     else:
-        queue.put(
-            (SERVICE_FINISHED_OK, (target, issue_count, ))
-        )
+        queue.put((SERVICE_FINISHED_OK, (target, issue_count, )))
     finally:
         duration = time.time() - start
-        log.name(target).info("Done with [%s] in %fs" % (target, duration))
+        log.info("Done with [%s] in %fs" % (target, duration))
 
 
 def aggregate_issues(conf, main_section, debug):
     """ Return all issues from every target. """
-    log.name('bugwarrior').info("Starting to aggregate remote issues.")
+    log.info("Starting to aggregate remote issues.")
 
     # Create and call service objects for every target in the config
     targets = [t.strip() for t in conf.get(main_section, 'targets').split(',')]
 
     queue = multiprocessing.Queue()
 
-    log.name('bugwarrior').info("Spawning %i workers." % len(targets))
+    log.info("Spawning %i workers." % len(targets))
     processes = []
 
     if debug:
@@ -575,7 +571,7 @@ def aggregate_issues(conf, main_section, debug):
             completion_type, args = issue
             if completion_type == SERVICE_FINISHED_ERROR:
                 target, e = args
-                log.name('bugwarrior').info("Terminating workers")
+                log.info("Terminating workers")
                 for process in processes:
                     process.terminate()
                 raise RuntimeError(
@@ -584,4 +580,4 @@ def aggregate_issues(conf, main_section, debug):
             continue
         yield issue
 
-    log.name('bugwarrior').info("Done aggregating remote issues.")
+    log.info("Done aggregating remote issues.")

bugwarrior/services/activecollab.py

@@ -1,11 +1,13 @@
 import re
 
 import pypandoc
-from twiggy import log
 from pyac.library import activeCollab
 from bugwarrior.services import IssueService, Issue
 from bugwarrior.config import die
 
+import logging
+log = logging.getLogger(__name__)
+
 
 class ActiveCollabClient(object):
     def __init__(self, url, key, user_id):
@@ -242,8 +244,8 @@ def issues(self):
                             subtask['task_id'] = task['task_id']
                             subtask['milestone'] = task['milestone']
                             issues.append(subtask)
-        log.name(self.target).debug(" Found {0} total", task_count)
-        log.name(self.target).debug(" Pruned down to {0}", len(issues))
+        log.debug(" Found %i total", task_count)
+        log.debug(" Pruned down to %i", len(issues))
         for issue in issues:
             issue_obj = self.get_issue_for_record(issue)
             extra = {