diff --git a/lib/vsc/utils/exceptions.py b/lib/vsc/utils/exceptions.py index e3ea0867..c55590e1 100644 --- a/lib/vsc/utils/exceptions.py +++ b/lib/vsc/utils/exceptions.py @@ -31,6 +31,7 @@ """ import inspect import logging +import os from vsc.utils import fancylogger @@ -69,6 +70,8 @@ class LoggedException(Exception): # name of logging method to use # must accept an argument of type string, i.e. the log message, and an optional list of formatting arguments LOGGING_METHOD_NAME = 'error' + # list of top-level package names to use to format location info; None implies not to include location info + LOC_INFO_TOP_PKG_NAMES = [] def __init__(self, msg, *args, **kwargs): """ @@ -81,6 +84,29 @@ def __init__(self, msg, *args, **kwargs): if args: msg = msg % args + if self.LOC_INFO_TOP_PKG_NAMES is not None: + # determine correct frame to fetch location information from + frames_up = 1 + if self.__class__ != LoggedException: + # move a level up when this instance is derived from LoggedException + frames_up += 1 + + # figure out where error was raised from + # current frame: this constructor, one frame above: location where this LoggedException was created/raised + frameinfo = inspect.getouterframes(inspect.currentframe())[frames_up] + + # determine short location of Python module where error was raised from, + # i.e. starting with an entry from LOC_INFO_TOP_PKG_NAMES + path_parts = frameinfo[1].split(os.path.sep) + if path_parts[0] == '': + path_parts[0] = os.path.sep + top_indices = [path_parts.index(n) for n in self.LOC_INFO_TOP_PKG_NAMES if n in path_parts] + relpath = os.path.join(*path_parts[max(top_indices or [0]):]) + + # include location info at the end of the message + # for example: "Nope, giving up (at easybuild/tools/somemodule.py:123 in some_function)" + msg = "%s (at %s:%s in %s)" % (msg, relpath, frameinfo[2], frameinfo[3]) + logger = kwargs.get('logger', None) # try to use logger defined in caller's environment if logger is None: diff --git a/test/exceptions.py b/test/exceptions.py index 846d11d4..d21ffd24 100644 --- a/test/exceptions.py +++ b/test/exceptions.py @@ -61,7 +61,7 @@ def test_loggedexception_defaultlogger(self): self.assertErrorRegex(LoggedException, 'BOOM', raise_loggedexception, 'BOOM') logToFile(tmplog, enable=False) - log_re = re.compile("^%s :: BOOM$" % getRootLoggerName(), re.M) + log_re = re.compile("^%s :: BOOM \(at .*:[0-9]+ in raise_loggedexception\)$" % getRootLoggerName(), re.M) logtxt = open(tmplog, 'r').read() self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt)) @@ -90,7 +90,8 @@ def test_loggedexception_specifiedlogger(self): self.assertErrorRegex(LoggedException, 'BOOM', raise_loggedexception, 'BOOM', logger=logger1) logToFile(tmplog, enable=False) - log_re = re.compile("^%s.testlogger_one :: BOOM$" % getRootLoggerName()) + rootlog = getRootLoggerName() + log_re = re.compile("^%s.testlogger_one :: BOOM \(at .*:[0-9]+ in raise_loggedexception\)$" % rootlog, re.M) logtxt = open(tmplog, 'r').read() self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt)) @@ -111,7 +112,64 @@ def test_loggedexception_callerlogger(self): self.assertErrorRegex(LoggedException, 'BOOM', raise_loggedexception, 'BOOM') logToFile(tmplog, enable=False) - log_re = re.compile("^%s.testlogger_local :: BOOM$" % getRootLoggerName()) + rootlog = getRootLoggerName() + log_re = re.compile("^%s.testlogger_local :: BOOM \(at .*:[0-9]+ in raise_loggedexception\)$" % rootlog) + logtxt = open(tmplog, 'r').read() + self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt)) + + os.remove(tmplog) + + def test_loggedexception_location(self): + """Test inclusion of location information in log message for LoggedException.""" + class TestException(LoggedException): + LOC_INFO_TOP_PKG_NAMES = None + + def raise_testexception(msg, *args, **kwargs): + """Utility function: just raise a TestException.""" + raise TestException(msg, *args, **kwargs) + + fd, tmplog = tempfile.mkstemp() + os.close(fd) + + # set log format, for each regex searching + setLogFormat("%(name)s :: %(message)s") + + # no location with default LOC_INFO_TOP_PKG_NAMES ([]) + logToFile(tmplog, enable=True) + self.assertErrorRegex(LoggedException, 'BOOM', raise_testexception, 'BOOM') + logToFile(tmplog, enable=False) + + rootlogname = getRootLoggerName() + + log_re = re.compile("^%s :: BOOM$" % rootlogname, re.M) + logtxt = open(tmplog, 'r').read() + self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt)) + + f = open(tmplog, 'w') + f.write('') + f.close() + + # location is included if LOC_INFO_TOP_PKG_NAMES is defined + TestException.LOC_INFO_TOP_PKG_NAMES = ['vsc'] + logToFile(tmplog, enable=True) + self.assertErrorRegex(LoggedException, 'BOOM', raise_testexception, 'BOOM') + logToFile(tmplog, enable=False) + + log_re = re.compile(r"^%s :: BOOM \(at vsc/utils/testing.py:[0-9]+ in assertErrorRegex\)$" % rootlogname) + logtxt = open(tmplog, 'r').read() + self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt)) + + f = open(tmplog, 'w') + f.write('') + f.close() + + # absolute path of location is included if there's no match in LOC_INFO_TOP_PKG_NAMES + TestException.LOC_INFO_TOP_PKG_NAMES = ['foobar'] + logToFile(tmplog, enable=True) + self.assertErrorRegex(LoggedException, 'BOOM', raise_testexception, 'BOOM') + logToFile(tmplog, enable=False) + + log_re = re.compile(r"^%s :: BOOM \(at /.*/vsc/utils/testing.py:[0-9]+ in assertErrorRegex\)$" % rootlogname) logtxt = open(tmplog, 'r').read() self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt))