Update all uses of rpki.log.traceback() for use with logging module.

svn path=/trunk/; revision=5838

15 files changed, 59 insertions, 128 deletions

diff --git a/ca/tests/smoketest.py b/ca/tests/smoketest.py
index 42e259e6..b8472ba3 100644
--- a/ca/tests/smoketest.py
+++ b/ca/tests/smoketest.py
@@ -301,7 +301,7 @@ def main():
   except Exception, e:
 
     logger.info("Event loop exited with an exception: %r" % e)
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
 
   finally:
 
@@ -631,7 +631,7 @@ class allocation(object):
 
     def done(e):
       if isinstance(e, Exception):
-        rpki.log.traceback()
+        rpki.log.traceback(logger)
         raise e
       cb()
 
@@ -648,7 +648,7 @@ class allocation(object):
 
     def done(e):
       if isinstance(e, Exception):
-        rpki.log.traceback()
+        rpki.log.traceback(logger)
         raise e
       cb()
 
@@ -1296,7 +1296,7 @@ def call_pubd(pdus, cb):
 
   def call_pubd_eb(e):
     logger.warning("Problem calling pubd: %s" % e)
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
 
   rpki.http.client(
     url          = q_url,
diff --git a/ca/tests/testpoke.py b/ca/tests/testpoke.py
index fd5ab206..bf1e1e43 100644
--- a/ca/tests/testpoke.py
+++ b/ca/tests/testpoke.py
@@ -53,9 +53,6 @@ args = parser.parse_args()
 
 rpki.log.init("testpoke")
 
-if args.debug:
-  rpki.log.set_trace(True)
-
 yaml_data = yaml.load(args.yaml)
 
 yaml_cmd = args.request
@@ -133,7 +130,7 @@ def do_revoke():
 dispatch = { "list" : do_list, "issue" : do_issue, "revoke" : do_revoke }
 
 def fail(e):                            # pylint: disable=W0621
-  rpki.log.traceback(args.debug)
+  rpki.log.traceback(logger, args.debug)
   sys.exit("Testpoke failed: %s" % e)
 
 cms_ta         = get_PEM("cms-ca-cert", rpki.x509.X509)
diff --git a/rpki/async.py b/rpki/async.py
index 16f85087..012d8f06 100644
--- a/rpki/async.py
+++ b/rpki/async.py
@@ -219,7 +219,7 @@ class timer(object):
           t.errback(e)
         else:
           logger.error("Unhandled exception from timer %r: %s" % (t, e))
-          rpki.log.traceback()
+          rpki.log.traceback(logger)
 
   def __repr__(self):
     return rpki.log.log_repr(self, self.when, repr(self.handler))
diff --git a/rpki/http.py b/rpki/http.py
index 812f45b2..64af0d4d 100644
--- a/rpki/http.py
+++ b/rpki/http.py
@@ -472,7 +472,7 @@ class http_stream(asynchat.async_chat):
     etype = sys.exc_info()[0]
     if etype in (SystemExit, rpki.async.ExitNow):
       raise
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     if etype is not rpki.exceptions.HTTPClientAborted:
       self.log("Closing due to error", logging.WARNING)
       self.close()
@@ -553,7 +553,7 @@ class http_server(http_stream):
       except (rpki.async.ExitNow, SystemExit):
         raise
       except Exception, e:
-        rpki.log.traceback()
+        rpki.log.traceback(logger)
         self.send_error(500, reason = "Unhandled exception %s: %s" % (e.__class__.__name__, e))
     else:
       self.send_error(code = error[0], reason = error[1])
@@ -623,7 +623,7 @@ class http_listener(asyncore.dispatcher):
       self.listen(5)
     except Exception, e:
       self.log("Couldn't set up HTTP listener: %s" % e, logging.WARNING)
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       self.close()
     for h in handlers:
       self.log("Handling %s" % h[0])
@@ -650,7 +650,7 @@ class http_listener(asyncore.dispatcher):
     if sys.exc_info()[0] in (SystemExit, rpki.async.ExitNow):
       raise
     self.log("Error in HTTP listener", logging.WARNING)
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
 
 class http_client(http_stream):
   """
@@ -952,7 +952,7 @@ class http_queue(object):
         # really bad happened.
         #
         self.log("Exception in exception callback", logging.WARNING)
-        rpki.log.traceback(True)
+        rpki.log.traceback(logger, True)
 
     self.log("Queue: %r" % self.queue)
 
diff --git a/rpki/irdbd.py b/rpki/irdbd.py
index 591e345a..02d90609 100644
--- a/rpki/irdbd.py
+++ b/rpki/irdbd.py
@@ -125,7 +125,7 @@ class main(object):
       except (rpki.async.ExitNow, SystemExit):
         raise
       except Exception, e:
-        rpki.log.traceback()
+        rpki.log.traceback(logger)
         if q_pdu is None:
           r_msg.append(rpki.left_right.report_error_elt.from_exception(e))
         else:
@@ -135,7 +135,7 @@ class main(object):
     except (rpki.async.ExitNow, SystemExit):
       raise
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       cb(500, reason = "Unhandled exception %s: %s" % (e.__class__.__name__, e))
 
   def dispatch(self, q_pdu, r_msg):
diff --git a/rpki/left_right.py b/rpki/left_right.py
index 74ae97d4..69a06c09 100644
--- a/rpki/left_right.py
+++ b/rpki/left_right.py
@@ -220,7 +220,6 @@ class self_elt(data_elt):
     """
     Extra server actions for self_elt.
     """
-    rpki.log.trace()
     actions = []
     if q_pdu.rekey:
       actions.append(self.serve_rekey)
@@ -244,7 +243,6 @@ class self_elt(data_elt):
     """
     Handle a left-right rekey action for this self.
     """
-    rpki.log.trace()
     def loop(iterator, parent):
       parent.serve_rekey(iterator, eb)
     rpki.async.iterator(self.parents, loop, cb)
@@ -253,7 +251,6 @@ class self_elt(data_elt):
     """
     Handle a left-right revoke action for this self.
     """
-    rpki.log.trace()
     def loop(iterator, parent):
       parent.serve_revoke(iterator, eb)
     rpki.async.iterator(self.parents, loop, cb)
@@ -262,7 +259,6 @@ class self_elt(data_elt):
     """
     Handle a left-right reissue action for this self.
     """
-    rpki.log.trace()
     def loop(iterator, parent):
       parent.serve_reissue(iterator, eb)
     rpki.async.iterator(self.parents, loop, cb)
@@ -271,7 +267,6 @@ class self_elt(data_elt):
     """
     Handle a left-right revoke_forgotten action for this self.
     """
-    rpki.log.trace()
     def loop(iterator, parent):
       parent.serve_revoke_forgotten(iterator, eb)
     rpki.async.iterator(self.parents, loop, cb)
@@ -280,7 +275,6 @@ class self_elt(data_elt):
     """
     Handle a left-right clear_replay_protection action for this self.
     """
-    rpki.log.trace()
     def loop(iterator, obj):
       obj.serve_clear_replay_protection(iterator, eb)
     rpki.async.iterator(self.parents + self.children + self.repositories, loop, cb)
@@ -289,7 +283,6 @@ class self_elt(data_elt):
     """
     Extra cleanup actions when destroying a self_elt.
     """
-    rpki.log.trace()
     def loop(iterator, parent):
       parent.delete(iterator)
     rpki.async.iterator(self.parents, loop, cb)
@@ -542,8 +535,6 @@ class repository_elt(data_elt):
     """
 
     try:
-      rpki.log.trace()
-
       self.gctx.sql.sweep()
 
       if not q_msg:
@@ -796,8 +787,6 @@ class parent_elt(data_elt):
     Client code for sending one up-down query PDU to this parent.
     """
 
-    rpki.log.trace()
-
     bsc = self.bsc
     if bsc is None:
       raise rpki.exceptions.BSCNotFound, "Could not find BSC %s" % self.bsc_id
@@ -948,8 +937,6 @@ class child_elt(data_elt):
     Outer layer of server handling for one up-down PDU from this child.
     """
 
-    rpki.log.trace()
-
     bsc = self.bsc
     if bsc is None:
       raise rpki.exceptions.BSCNotFound, "Could not find BSC %s" % self.bsc_id
@@ -982,7 +969,7 @@ class child_elt(data_elt):
     except rpki.exceptions.NoActiveCA, data:
       done(q_msg.serve_error(data))
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       done(q_msg.serve_error(e))
 
 class list_resources_elt(rpki.xml_utils.base_elt, left_right_namespace):
@@ -1266,7 +1253,7 @@ class msg(rpki.xml_utils.msg, left_right_namespace):
 
       def fail(e):
         if not isinstance(e, rpki.exceptions.NotFound):
-          rpki.log.traceback()
+          rpki.log.traceback(logger)
         r_msg.append(report_error_elt.from_exception(
           e, self_handle = q_pdu.self_handle, tag = q_pdu.tag))
         cb(r_msg)
diff --git a/rpki/log.py b/rpki/log.py
index 728cb321..d68a1da0 100644
--- a/rpki/log.py
+++ b/rpki/log.py
@@ -39,11 +39,6 @@ except ImportError:
 
 logger = logging.getLogger(__name__)
 
-## @var enable_trace
-# Whether call tracing is enabled.
-
-enable_trace = False
-
 ## @var show_python_ids
 # Whether __repr__() methods should show Python id numbers
 
@@ -80,7 +75,7 @@ def argparse_setup(parser):
   class RotatingFile(argparse.Action):
     def __call__(self, parser, namespace, values, option_string = None):
       setattr(namespace, self.dest, values[0])
-      setattr(namespace, self.dest + "_maxBytes",    int(values[1]))
+      setattr(namespace, self.dest + "_maxBytes",    int(values[1]) * 1024)
       setattr(namespace, self.dest + "_backupCount", int(values[2]))
       if len(values) > 3:
         raise ValueError
@@ -173,27 +168,7 @@ def init(ident = "rpki", args = argparse.Namespace(log_level = logging.DEBUG, lo
       setproctitle.setproctitle(ident)
 
 
-def set_trace(enable):
-  """
-  Enable or disable call tracing.
-  """
-
-  global enable_trace
-  enable_trace = enable
-
-def trace():
-  """
-  Execution trace -- where are we now, and whence came we here?
-
-  At this point we might be better off using logging's built in
-  support (pathname, lineno, etc) rather than this ancient hack.
-  """
-
-  if enable_trace:
-    bt = tb.extract_stack(limit = 3)
-    return logger.debug("[%s() at %s:%d from %s:%d]" % (bt[1][2], bt[1][0], bt[1][1], bt[0][0], bt[0][1]))
-
-def traceback(do_it = None):
+def traceback(trace_logger, do_it = None):
   """
   Consolidated backtrace facility with a bit of extra info.  Argument
   specifies whether or not to log the traceback (some modules and
@@ -206,10 +181,14 @@ def traceback(do_it = None):
   definition, and (b) it's often hard to figure out what's triggering
   a particular assertion failure without the backtrace.
 
-  The logger calls here are arguably wrong, as they use the rpki.log
-  module's logger object rather than the calling module's logger.
-  Might need to fix this some day, need to think about what the API
-  for this should be (just take the logger to use as an argument?).
+  logging.exception() doesn't do quite what we want here, or we'd just
+  use that.  In particular, logging.exception() puts the entire
+  traceback (or, rather, the portion that it choses to print) into a
+  single log message, and is pretty much tied to that model because
+  its getting the exception data from one log record.  This doesn't
+  work well with syslog, which has a maximum record size.  Maybe the
+  real answer here is just that we shouldn't attempt to backtrace when
+  logging via syslog, but, for now, keep using our old hack.
   """
 
   if do_it is None:
@@ -220,11 +199,11 @@ def traceback(do_it = None):
 
   if do_it or isinstance(e, AssertionError):
     bt = tb.extract_stack(limit = 3)
-    logger.error("Exception caught in %s() at %s:%d called from %s:%d" % (bt[1][2], bt[1][0], bt[1][1], bt[0][0], bt[0][1]))
+    trace_logger.error("Exception caught in %s() at %s:%d called from %s:%d" % (bt[1][2], bt[1][0], bt[1][1], bt[0][0], bt[0][1]))
     bt = tb.format_exc()
     assert bt is not None, "Apparently I'm still not using the right test for null backtrace"
     for line in bt.splitlines():
-      logger.warning(line)
+      trace_logger.warning(line)
 
 def log_repr(obj, *tokens):
   """
@@ -247,7 +226,7 @@ def log_repr(obj, *tokens):
       except:
         s = "???"
         logger.debug("Failed to generate repr() string for object of type %r" % type(token))
-        traceback()
+        traceback(logger)
       if s:
         words.append(s)
 
diff --git a/rpki/old_irdbd.py b/rpki/old_irdbd.py
index 109fdcfd..953d951d 100644
--- a/rpki/old_irdbd.py
+++ b/rpki/old_irdbd.py
@@ -256,14 +256,14 @@ class main(object):
             raise
 
           except Exception, e:
-            rpki.log.traceback()
+            rpki.log.traceback(logger)
             r_msg.append(rpki.left_right.report_error_elt.from_exception(e, q_pdu.self_handle, q_pdu.tag))
 
       except (rpki.async.ExitNow, SystemExit):
         raise
 
       except Exception, e:
-        rpki.log.traceback()
+        rpki.log.traceback(logger)
         r_msg.append(rpki.left_right.report_error_elt.from_exception(e))
 
       cb(200, body = rpki.left_right.cms_msg().wrap(r_msg, self.irdbd_key, self.irdbd_cert))
@@ -272,7 +272,7 @@ class main(object):
       raise
 
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
 
       # We only get here in cases where we couldn't or wouldn't generate
       # <report_error/>, so just return HTTP failure.
diff --git a/rpki/pubd.py b/rpki/pubd.py
index 0cb4c6fd..5a345c4d 100644
--- a/rpki/pubd.py
+++ b/rpki/pubd.py
@@ -137,13 +137,12 @@ class main(object):
     def done(body):
       cb(200, body = body)
 
-    rpki.log.trace()
     try:
       self.handler_common(query, None, done, (self.bpki_ta, self.irbe_cert))
     except (rpki.async.ExitNow, SystemExit):
       raise
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       cb(500, reason = "Unhandled exception %s: %s" % (e.__class__.__name__, e))
 
   client_url_regexp = re.compile("/client/([-A-Z0-9_/]+)$", re.I)
@@ -156,7 +155,6 @@ class main(object):
     def done(body):
       cb(200, body = body)
 
-    rpki.log.trace()
     try:
       match = self.client_url_regexp.search(path)
       if match is None:
@@ -172,5 +170,5 @@ class main(object):
     except (rpki.async.ExitNow, SystemExit):
       raise
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       cb(500, reason = "Could not process PDU: %s" % e)
diff --git a/rpki/publication.py b/rpki/publication.py
index c4ef8b44..59650548 100644
--- a/rpki/publication.py
+++ b/rpki/publication.py
@@ -432,7 +432,7 @@ class msg(rpki.xml_utils.msg, publication_namespace):
 
       def fail(e):
         if not isinstance(e, rpki.exceptions.NotFound):
-          rpki.log.traceback()
+          rpki.log.traceback(logger)
         r_msg.append(report_error_elt.from_exception(e, q_pdu.tag))
         cb(r_msg)
 
diff --git a/rpki/rootd.py b/rpki/rootd.py
index f8dc4eb3..c8398ef7 100644
--- a/rpki/rootd.py
+++ b/rpki/rootd.py
@@ -277,7 +277,7 @@ class main(object):
     except (rpki.async.ExitNow, SystemExit):
       raise
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       return cb(400, reason = "Could not process PDU: %s" % e)
 
     def done(r_msg):
@@ -290,13 +290,13 @@ class main(object):
     except (rpki.async.ExitNow, SystemExit):
       raise
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       try:
         done(q_msg.serve_error(e))
       except (rpki.async.ExitNow, SystemExit):
         raise
       except Exception, e:
-        rpki.log.traceback()
+        rpki.log.traceback(logger)
         cb(500, reason = "Could not process PDU: %s" % e)
 
 
diff --git a/rpki/rpkid.py b/rpki/rpkid.py
index b6f2bcb2..b619b8e2 100644
--- a/rpki/rpkid.py
+++ b/rpki/rpkid.py
@@ -168,8 +168,6 @@ class main(object):
     Perform an IRDB callback query.
     """
 
-    rpki.log.trace()
-
     try:
       q_types = tuple(type(q_pdu) for q_pdu in q_pdus)
 
@@ -213,8 +211,6 @@ class main(object):
     Ask IRDB about a child's resources.
     """
 
-    rpki.log.trace()
-
     q_pdu = rpki.left_right.list_resources_elt()
     q_pdu.self_handle = self_handle
     q_pdu.child_handle = child_handle
@@ -233,8 +229,6 @@ class main(object):
     Ask IRDB about self's ROA requests.
     """
 
-    rpki.log.trace()
-
     q_pdu = rpki.left_right.list_roa_requests_elt()
     q_pdu.self_handle = self_handle
 
@@ -245,8 +239,6 @@ class main(object):
     Ask IRDB about self's ghostbuster record requests.
     """
 
-    rpki.log.trace()
-
     q_pdus = []
 
     for parent_handle in parent_handles:
@@ -262,8 +254,6 @@ class main(object):
     Ask IRDB about self's EE certificate requests.
     """
 
-    rpki.log.trace()
-
     q_pdu = rpki.left_right.list_ee_certificate_requests_elt()
     q_pdu.self_handle = self_handle
 
@@ -274,8 +264,6 @@ class main(object):
     Process one left-right PDU.
     """
 
-    rpki.log.trace()
-
     def done(r_msg):
       reply = rpki.left_right.cms_msg().wrap(r_msg, self.rpkid_key, self.rpkid_cert)
       self.sql.sweep()
@@ -291,7 +279,7 @@ class main(object):
     except (rpki.async.ExitNow, SystemExit):
       raise
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       cb(500, reason = "Unhandled exception %s: %s" % (e.__class__.__name__, e))
 
   up_down_url_regexp = re.compile("/up-down/([-A-Z0-9_]+)/([-A-Z0-9_]+)$", re.I)
@@ -301,8 +289,6 @@ class main(object):
     Process one up-down PDU.
     """
 
-    rpki.log.trace()
-
     def done(reply):
       self.sql.sweep()
       cb(200, body = reply)
@@ -325,7 +311,7 @@ class main(object):
       logger.warning(str(e))
       cb(400, reason = str(e))
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       cb(400, reason = "Could not process PDU: %s" % e)
 
   def checkpoint(self, force = False):
@@ -373,8 +359,6 @@ class main(object):
     Periodic tasks.
     """
 
-    rpki.log.trace()
-
     now = rpki.sundial.now()
 
     logger.debug("Starting cron run")
@@ -678,7 +662,7 @@ class ca_obj(rpki.sql.sql_persistent):
     """
 
     def lose(e):
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       logger.warning("Could not delete CA %r, skipping: %s" % (self, e))
       callback()
 
@@ -724,8 +708,6 @@ class ca_obj(rpki.sql.sql_persistent):
     the new ca_detail.
     """
 
-    rpki.log.trace()
-
     parent = self.parent
     old_detail = self.active_ca_detail
     new_detail = ca_detail_obj.create(self)
@@ -750,8 +732,6 @@ class ca_obj(rpki.sql.sql_persistent):
     all ca_details associated with this CA if revoke_all is set.
     """
 
-    rpki.log.trace()
-
     def loop(iterator, ca_detail):
       ca_detail.revoke(cb = iterator, eb = eb)
 
diff --git a/rpki/rpkid_tasks.py b/rpki/rpkid_tasks.py
index ab8beaa6..0d5048b2 100644
--- a/rpki/rpkid_tasks.py
+++ b/rpki/rpkid_tasks.py
@@ -167,7 +167,6 @@ class PollParentTask(AbstractTask):
     self.class_iterator = None
 
   def start(self):
-    rpki.log.trace()
     self.gctx.checkpoint()
     logger.debug("Self %s[%d] polling parents" % (self.self_handle, self.self_id))
     rpki.async.iterator(self.parents, self.parent_loop, self.exit)
@@ -183,7 +182,7 @@ class PollParentTask(AbstractTask):
     rpki.async.iterator(r_msg.payload.classes, self.class_loop, self.class_done)
 
   def list_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't get resource class list from parent %r, skipping: %s (%r)" % (
       self.parent, e, e))
     self.parent_iterator()
@@ -199,12 +198,12 @@ class PollParentTask(AbstractTask):
       ca.check_for_updates(self.parent, rc, class_iterator, self.class_update_failed)
 
   def class_update_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't update class, skipping: %s" % e)
     self.class_iterator()
 
   def class_create_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't create class, skipping: %s" % e)
     self.class_iterator()
 
@@ -238,7 +237,6 @@ class UpdateChildrenTask(AbstractTask):
     self.child_certs = None
 
   def start(self):
-    rpki.log.trace()
     self.gctx.checkpoint()
     logger.debug("Self %s[%d] updating children" % (self.self_handle, self.self_id))
     self.now = rpki.sundial.now()
@@ -265,7 +263,7 @@ class UpdateChildrenTask(AbstractTask):
       self.iterator()
 
   def lose(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't update child %r, skipping: %s" % (self.child, e))
     self.iterator()
 
@@ -338,7 +336,7 @@ class UpdateChildrenTask(AbstractTask):
     self.publisher.call_pubd(self.exit, self.publication_failed)
 
   def publication_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't publish for %s, skipping: %s" % (self.self_handle, e))
     self.gctx.checkpoint()
     self.exit()
@@ -358,7 +356,6 @@ class UpdateROAsTask(AbstractTask):
     self.count = None
 
   def start(self):
-    rpki.log.trace()
     self.gctx.checkpoint()
     self.gctx.sql.sweep()
     logger.debug("Self %s[%d] updating ROAs" % (self.self_handle, self.self_id))
@@ -428,7 +425,7 @@ class UpdateROAsTask(AbstractTask):
     except rpki.exceptions.NoCoveringCertForROA:
       logger.warning("No covering certificate for %r, skipping" % roa)
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       logger.warning("Could not update %r, skipping: %s" % (roa, e))
     self.count += 1
     if self.overdue:
@@ -449,7 +446,7 @@ class UpdateROAsTask(AbstractTask):
     self.publisher.call_pubd(done, self.publication_failed)
 
   def publication_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't publish for %s, skipping: %s" % (self.self_handle, e))
     self.gctx.checkpoint()
     self.exit()
@@ -462,14 +459,14 @@ class UpdateROAsTask(AbstractTask):
       except (SystemExit, rpki.async.ExitNow):
         raise
       except Exception, e:
-        rpki.log.traceback()
+        rpki.log.traceback(logger)
         logger.warning("Could not revoke %r: %s" % (roa, e))
     self.gctx.sql.sweep()
     self.gctx.checkpoint()
     self.publish(self.exit)
 
   def roa_requests_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Could not fetch ROA requests for %s, skipping: %s" % (self.self_handle, e))
     self.exit()
 
@@ -487,7 +484,6 @@ class UpdateGhostbustersTask(AbstractTask):
   """
 
   def start(self):
-    rpki.log.trace()
     self.gctx.checkpoint()
     logger.debug("Self %s[%d] updating Ghostbuster records" % (self.self_handle, self.self_id))
 
@@ -557,18 +553,18 @@ class UpdateGhostbustersTask(AbstractTask):
     except (SystemExit, rpki.async.ExitNow):
       raise
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       logger.warning("Could not update Ghostbuster records for %s, skipping: %s" % (self.self_handle, e))
       self.exit()
 
   def publication_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't publish Ghostbuster updates for %s, skipping: %s" % (self.self_handle, e))
     self.gctx.checkpoint()
     self.exit()
 
   def ghostbuster_requests_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Could not fetch Ghostbuster record requests for %s, skipping: %s" % (self.self_handle, e))
     self.exit()
 
@@ -583,7 +579,6 @@ class UpdateEECertificatesTask(AbstractTask):
   """
 
   def start(self):
-    rpki.log.trace()
     self.gctx.checkpoint()
     logger.debug("Self %s[%d] updating EE certificates" % (self.self_handle, self.self_id))
 
@@ -661,18 +656,18 @@ class UpdateEECertificatesTask(AbstractTask):
     except (SystemExit, rpki.async.ExitNow):
       raise
     except Exception, e:
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       logger.warning("Could not update EE certificates for %s, skipping: %s" % (self.self_handle, e))
       self.exit()
 
   def publication_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't publish EE certificate updates for %s, skipping: %s" % (self.self_handle, e))
     self.gctx.checkpoint()
     self.exit()
 
   def get_requests_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Could not fetch EE certificate requests for %s, skipping: %s" % (self.self_handle, e))
     self.exit()
 
@@ -691,7 +686,6 @@ class RegenerateCRLsAndManifestsTask(AbstractTask):
   """
 
   def start(self):
-    rpki.log.trace()
     self.gctx.checkpoint()
     logger.debug("Self %s[%d] regenerating CRLs and manifests" % (self.self_handle, self.self_id))
 
@@ -713,7 +707,7 @@ class RegenerateCRLsAndManifestsTask(AbstractTask):
         except (SystemExit, rpki.async.ExitNow):
           raise
         except Exception, e:
-          rpki.log.traceback()
+          rpki.log.traceback(logger)
           logger.warning("Couldn't regenerate CRLs and manifests for CA %r, skipping: %s" % (ca, e))
 
     self.gctx.checkpoint()
@@ -721,7 +715,7 @@ class RegenerateCRLsAndManifestsTask(AbstractTask):
     publisher.call_pubd(self.exit, self.lose)
 
   def lose(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't publish updated CRLs and manifests for self %r, skipping: %s" % (self.self_handle, e))
     self.gctx.checkpoint()
     self.exit()
@@ -735,7 +729,6 @@ class CheckFailedPublication(AbstractTask):
   """
 
   def start(self):
-    rpki.log.trace()
     publisher = rpki.rpkid.publication_queue()
     for parent in self.parents:
       for ca in parent.cas:
@@ -747,7 +740,7 @@ class CheckFailedPublication(AbstractTask):
     publisher.call_pubd(self.exit, self.publication_failed)
 
   def publication_failed(self, e):
-    rpki.log.traceback()
+    rpki.log.traceback(logger)
     logger.warning("Couldn't publish for %s, skipping: %s" % (self.self_handle, e))
     self.gctx.checkpoint()
     self.exit()
diff --git a/rpki/up_down.py b/rpki/up_down.py
index 15596eff..cc4ed196 100644
--- a/rpki/up_down.py
+++ b/rpki/up_down.py
@@ -669,7 +669,7 @@ class message_pdu(base_elt):
       callback(r_msg)
 
     def lose(e):
-      rpki.log.traceback()
+      rpki.log.traceback(logger)
       callback(self.serve_error(e))
 
     try:
diff --git a/rpki/x509.py b/rpki/x509.py
index 41daade5..c9a8f9c1 100644
--- a/rpki/x509.py
+++ b/rpki/x509.py
@@ -1514,8 +1514,6 @@ class CMS_object(DER_object):
     Sign and wrap inner content.
     """
 
-    rpki.log.trace()
-
     if isinstance(certs, X509):
       cert = certs
       certs = ()
@@ -1844,7 +1842,6 @@ class XML_CMS_object(Wrapped_CMS_object):
     """
     Wrap an XML PDU in CMS and return its DER encoding.
     """
-    rpki.log.trace()
     if self.saxify is None:
       self.set_content(msg)
     else: