ENH: adding ability to incorporate tracebacks into log lines while running tests

fail2ban-testcases

@@ -36,6 +36,8 @@ from testcases import servertestcase
 from testcases import datedetectortestcase
 from testcases import actiontestcase
 from testcases import sockettestcase
+
+from testcases.utils import FormatterWithTraceBack
 from server.mytime import MyTime
 
 from optparse import OptionParser, Option
@@ -52,12 +54,14 @@ def get_opt_parser():
 			   choices=('debug', 'info', 'warn', 'error', 'fatal'),
 			   default=None,
 			   help="Log level for the logger to use during running tests"),
-		])
-
-	p.add_options([
 		Option('-n', "--no-network", action="store_true",
 			   dest="no_network",
 			   help="Do not run tests that require the network"),
+		Option("-t", "--log-traceback", action='store_true',
+			   help="Enrich log-messages with compressed tracebacks"),
+		Option("--full-traceback", action='store_true',
+			   help="Either to make the tracebacks full, not compressed (as by default)"),
+
 		])
 
 	return p
@@ -89,12 +93,21 @@ else: # pragma: no cover
 
 # Add the default logging handler
 stdout = logging.StreamHandler(sys.stdout)
+
+fmt = ' %(message)s'
+
+if opts.log_traceback:
+	Formatter = FormatterWithTraceBack
+	fmt = (opts.full_traceback and ' %(tb)s' or ' %(tbc)s') + fmt
+else:
+	Formatter = logging.Formatter
+
 # Custom log format for the verbose tests runs
 if verbosity > 1: # pragma: no cover
-	stdout.setFormatter(logging.Formatter(' %(asctime)-15s %(thread)s %(message)s'))
+	stdout.setFormatter(Formatter(' %(asctime)-15s %(thread)s' + fmt))
 else: # pragma: no cover
 	# just prefix with the space
-	stdout.setFormatter(logging.Formatter(' %(message)s'))
+	stdout.setFormatter(Formatter(fmt))
 logSys.addHandler(stdout)
 
 #

testcases/utils.py

@@ -0,0 +1,101 @@
+# emacs: -*- mode: python; py-indent-offset: 4; indent-tabs-mode: t -*-
+# vi: set ft=python sts=4 ts=4 sw=4 noet :
+
+# This file is part of Fail2Ban.
+#
+# Fail2Ban is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation; either version 2 of the License, or
+# (at your option) any later version.
+#
+# Fail2Ban is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with Fail2Ban; if not, write to the Free Software
+# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
+
+
+__author__ = "Yaroslav Halchenko"
+__copyright__ = "Copyright (c) 2013 Yaroslav Halchenko"
+__license__ = "GPL"
+
+import logging, os, re, traceback
+from os.path import basename, dirname
+
+#
+# Following "traceback" functions are adopted from PyMVPA distributed
+# under MIT/Expat and copyright by PyMVPA developers (i.e. me and
+# Michael).  Hereby I re-license derivative work on these pieces under GPL
+# to stay in line with the main Fail2Ban license
+#
+def mbasename(s):
+	"""Custom function to include directory name if filename is too common
+
+	Also strip .py at the end
+	"""
+	base = basename(s)
+	if base.endswith('.py'):
+		base = base[:-3]
+	if base in set(['base', '__init__']):
+		base = basename(dirname(s)) + '.' + base
+	return base
+
+class TraceBack(object):
+	"""Customized traceback to be included in debug messages
+	"""
+
+	def __init__(self, compress=False):
+		"""Initialize TrackBack metric
+
+		Parameters
+		----------
+		compress : bool
+		  if True then prefix common with previous invocation gets
+		  replaced with ...
+		"""
+		self.__prev = ""
+		self.__compress = compress
+
+	def __call__(self):
+		ftb = traceback.extract_stack(limit=100)[:-2]
+		entries = [[mbasename(x[0]), str(x[1])] for x in ftb]
+		entries = [ e for e in entries
+					if not e[0] in ['unittest', 'logging.__init__' ]]
+
+		# lets make it more consize
+		entries_out = [entries[0]]
+		for entry in entries[1:]:
+			if entry[0] == entries_out[-1][0]:
+				entries_out[-1][1] += ',%s' % entry[1]
+			else:
+				entries_out.append(entry)
+		sftb = '>'.join(['%s:%s' % (mbasename(x[0]),
+									x[1]) for x in entries_out])
+		if self.__compress:
+			# lets remove part which is common with previous invocation
+			prev_next = sftb
+			common_prefix = os.path.commonprefix((self.__prev, sftb))
+			common_prefix2 = re.sub('>[^>]*$', '', common_prefix)
+
+			if common_prefix2 != "":
+				sftb = '...' + sftb[len(common_prefix2):]
+			self.__prev = prev_next
+
+		return sftb
+
+class FormatterWithTraceBack(logging.Formatter):
+	"""Custom formatter which expands %(tb) and %(tbc) with tracebacks
+
+	TODO: might need locking in case of compressed tracebacks
+	"""
+	def __init__(self, fmt, *args, **kwargs):
+		logging.Formatter.__init__(self, fmt=fmt, *args, **kwargs)
+		compress = '%(tbc)s' in fmt
+		self._tb = TraceBack(compress=compress)
+
+	def format(self, record):
+		record.tbc = record.tb = self._tb()
+		return logging.Formatter.format(self, record)