From 69f31d02351e1daf8f4b4724cab52d5d53abb9f7 Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Sun, 5 Apr 2015 23:06:40 +0200 Subject: [PATCH 01/10] (optionally) include location info in LoggedException log message --- lib/vsc/utils/exceptions.py | 24 +++++++++++++++++++ test/exceptions.py | 46 ++++++++++++++++++++++++++++++++++--- 2 files changed, 67 insertions(+), 3 deletions(-) diff --git a/lib/vsc/utils/exceptions.py b/lib/vsc/utils/exceptions.py index e3ea0867..93189d22 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,27 @@ 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 EasyBuildError was created/raised + frameinfo = inspect.getouterframes(inspect.currentframe())[frames_up] + + # determine short location of Python module where error was raised from (starting with 'easybuild/' or 'vsc/') + path_parts = frameinfo[1].split(os.path.sep) + relpath = path_parts.pop() + while path_parts and not any([relpath.startswith(n + os.path.sep) for n in self.LOC_INFO_TOP_PKG_NAMES]): + relpath = os.path.join(path_parts.pop() or os.path.sep, relpath) + + # 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..d7f1bef8 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,7 @@ 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()) + log_re = re.compile("^runpy.testlogger_one :: BOOM \(at .*:[0-9]+ in raise_loggedexception\)$", re.M) logtxt = open(tmplog, 'r').read() self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt)) @@ -111,7 +111,47 @@ 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()) + log_re = re.compile("^runpy.testlogger_local :: BOOM \(at .*:[0-9]+ in raise_loggedexception\)$") + 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") + + # if no logger is available, and no logger is specified, use default 'root' fancylogger + logToFile(tmplog, enable=True) + self.assertErrorRegex(LoggedException, 'BOOM', raise_testexception, 'BOOM') + logToFile(tmplog, enable=False) + + log_re = re.compile("^%s :: BOOM$" % getRootLoggerName(), 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() + TestException.LOC_INFO_TOP_PKG_NAMES = ['test'] + + # if no logger is specified, logger available in calling context should be used + logToFile(tmplog, enable=True) + self.assertErrorRegex(LoggedException, 'BOOM', raise_testexception, 'BOOM') + logToFile(tmplog, enable=False) + + log_re = re.compile("^%s :: BOOM \(at test.*[0-9]+ in raise_testexception\)$" % getRootLoggerName()) logtxt = open(tmplog, 'r').read() self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt)) From 1c30bd86ce92af44f5a0fc3474fc0448c2c85975 Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Sun, 5 Apr 2015 23:11:17 +0200 Subject: [PATCH 02/10] fix typo --- lib/vsc/utils/exceptions.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/vsc/utils/exceptions.py b/lib/vsc/utils/exceptions.py index 93189d22..9aa3984b 100644 --- a/lib/vsc/utils/exceptions.py +++ b/lib/vsc/utils/exceptions.py @@ -89,7 +89,7 @@ def __init__(self, msg, *args, **kwargs): frames_up = 1 if self.__class__ != LoggedException: # move a level up when this instance is derived from LoggedException - frames_up = 1 + frames_up += 1 # figure out where error was raised from # current frame: this constructor, one frame above: location where this EasyBuildError was created/raised From 06759bce985d4174f24d83d2e66d2ac9a6adc763 Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Sun, 5 Apr 2015 23:13:05 +0200 Subject: [PATCH 03/10] don't hardcode 'runpy' root logger in tests --- test/exceptions.py | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/test/exceptions.py b/test/exceptions.py index d7f1bef8..af4cfa70 100644 --- a/test/exceptions.py +++ b/test/exceptions.py @@ -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("^runpy.testlogger_one :: BOOM \(at .*:[0-9]+ in raise_loggedexception\)$", re.M) + 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,8 @@ def test_loggedexception_callerlogger(self): self.assertErrorRegex(LoggedException, 'BOOM', raise_loggedexception, 'BOOM') logToFile(tmplog, enable=False) - log_re = re.compile("^runpy.testlogger_local :: BOOM \(at .*:[0-9]+ in raise_loggedexception\)$") + 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)) From b88f05e801c3ca81b6a03517cd41ba5156580b6a Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Sun, 5 Apr 2015 23:16:27 +0200 Subject: [PATCH 04/10] fix error regex in test --- test/exceptions.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/exceptions.py b/test/exceptions.py index af4cfa70..cf29723f 100644 --- a/test/exceptions.py +++ b/test/exceptions.py @@ -153,7 +153,7 @@ def raise_testexception(msg, *args, **kwargs): self.assertErrorRegex(LoggedException, 'BOOM', raise_testexception, 'BOOM') logToFile(tmplog, enable=False) - log_re = re.compile("^%s :: BOOM \(at test.*[0-9]+ in raise_testexception\)$" % getRootLoggerName()) + log_re = re.compile("^%s :: BOOM \(at .*:[0-9]+ in assertErrorRegex\)$" % getRootLoggerName()) logtxt = open(tmplog, 'r').read() self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt)) From 19298f285491dcc9b0ffd3e58cad616374754997 Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Tue, 7 Apr 2015 10:15:51 +0200 Subject: [PATCH 05/10] fix remarks --- lib/vsc/utils/exceptions.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/lib/vsc/utils/exceptions.py b/lib/vsc/utils/exceptions.py index 9aa3984b..46597a94 100644 --- a/lib/vsc/utils/exceptions.py +++ b/lib/vsc/utils/exceptions.py @@ -92,10 +92,11 @@ def __init__(self, msg, *args, **kwargs): frames_up += 1 # figure out where error was raised from - # current frame: this constructor, one frame above: location where this EasyBuildError was created/raised + # 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 (starting with 'easybuild/' or 'vsc/') + # 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) relpath = path_parts.pop() while path_parts and not any([relpath.startswith(n + os.path.sep) for n in self.LOC_INFO_TOP_PKG_NAMES]): From 3edf3f0ceee13d450dcf07600846da87cadee919 Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Wed, 8 Apr 2015 08:20:55 +0200 Subject: [PATCH 06/10] fix remark --- lib/vsc/utils/exceptions.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/lib/vsc/utils/exceptions.py b/lib/vsc/utils/exceptions.py index 46597a94..8b678bc5 100644 --- a/lib/vsc/utils/exceptions.py +++ b/lib/vsc/utils/exceptions.py @@ -98,9 +98,11 @@ def __init__(self, msg, *args, **kwargs): # 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) - relpath = path_parts.pop() - while path_parts and not any([relpath.startswith(n + os.path.sep) for n in self.LOC_INFO_TOP_PKG_NAMES]): - relpath = os.path.join(path_parts.pop() or os.path.sep, relpath) + top_indices = [path_parts.index(n) for n in self.LOC_INFO_TOP_PKG_NAMES if n in path_parts] + if top_indices: + relpath = os.path.join(path_parts[max(top_indices):]) + else: + relpath = os.path.join(path_parts) # include location info at the end of the message # for example: "Nope, giving up (at easybuild/tools/somemodule.py:123 in some_function)" From 7edfec8ccfe8f0bc92784dbf0bb93254f08dd2f3 Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Thu, 9 Apr 2015 08:14:09 +0200 Subject: [PATCH 07/10] correct os.path.join of log location, and check it in the tests --- lib/vsc/utils/exceptions.py | 4 ++-- test/exceptions.py | 8 ++++---- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/lib/vsc/utils/exceptions.py b/lib/vsc/utils/exceptions.py index 8b678bc5..cc5446fe 100644 --- a/lib/vsc/utils/exceptions.py +++ b/lib/vsc/utils/exceptions.py @@ -100,9 +100,9 @@ def __init__(self, msg, *args, **kwargs): path_parts = frameinfo[1].split(os.path.sep) top_indices = [path_parts.index(n) for n in self.LOC_INFO_TOP_PKG_NAMES if n in path_parts] if top_indices: - relpath = os.path.join(path_parts[max(top_indices):]) + relpath = os.path.join(*path_parts[max(top_indices):]) else: - relpath = os.path.join(path_parts) + relpath = os.path.join(*path_parts) # include location info at the end of the message # for example: "Nope, giving up (at easybuild/tools/somemodule.py:123 in some_function)" diff --git a/test/exceptions.py b/test/exceptions.py index cf29723f..9f57e7c3 100644 --- a/test/exceptions.py +++ b/test/exceptions.py @@ -134,7 +134,7 @@ def raise_testexception(msg, *args, **kwargs): # set log format, for each regex searching setLogFormat("%(name)s :: %(message)s") - # if no logger is available, and no logger is specified, use default 'root' fancylogger + # no location with default LOC_INFO_TOP_PKG_NAMES ([]) logToFile(tmplog, enable=True) self.assertErrorRegex(LoggedException, 'BOOM', raise_testexception, 'BOOM') logToFile(tmplog, enable=False) @@ -146,14 +146,14 @@ def raise_testexception(msg, *args, **kwargs): f = open(tmplog, 'w') f.write('') f.close() - TestException.LOC_INFO_TOP_PKG_NAMES = ['test'] + TestException.LOC_INFO_TOP_PKG_NAMES = ['vsc'] - # if no logger is specified, logger available in calling context should be used + # location is included if LOC_INFO_TOP_PKG_NAMES is defined logToFile(tmplog, enable=True) self.assertErrorRegex(LoggedException, 'BOOM', raise_testexception, 'BOOM') logToFile(tmplog, enable=False) - log_re = re.compile("^%s :: BOOM \(at .*:[0-9]+ in assertErrorRegex\)$" % getRootLoggerName()) + log_re = re.compile("^%s :: BOOM \(at vsc/utils/testing.py:[0-9]+ in assertErrorRegex\)$" % getRootLoggerName()) logtxt = open(tmplog, 'r').read() self.assertTrue(log_re.match(logtxt), "%s matches %s" % (log_re.pattern, logtxt)) From b3b549f695cbaadf688cd4c50d1ff91ba9b1abcd Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Thu, 9 Apr 2015 08:21:24 +0200 Subject: [PATCH 08/10] fix remark --- lib/vsc/utils/exceptions.py | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/lib/vsc/utils/exceptions.py b/lib/vsc/utils/exceptions.py index cc5446fe..d31a3678 100644 --- a/lib/vsc/utils/exceptions.py +++ b/lib/vsc/utils/exceptions.py @@ -99,10 +99,7 @@ def __init__(self, msg, *args, **kwargs): # i.e. starting with an entry from LOC_INFO_TOP_PKG_NAMES path_parts = frameinfo[1].split(os.path.sep) top_indices = [path_parts.index(n) for n in self.LOC_INFO_TOP_PKG_NAMES if n in path_parts] - if top_indices: - relpath = os.path.join(*path_parts[max(top_indices):]) - else: - relpath = os.path.join(*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)" From 770adf6a4d197aa08ddbe1fb833ab6dd4f880e1c Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Thu, 9 Apr 2015 08:37:38 +0200 Subject: [PATCH 09/10] make sure that full path to location has a leading / in LoggedException log message --- lib/vsc/utils/exceptions.py | 2 ++ test/exceptions.py | 22 +++++++++++++++++++--- 2 files changed, 21 insertions(+), 3 deletions(-) diff --git a/lib/vsc/utils/exceptions.py b/lib/vsc/utils/exceptions.py index d31a3678..c55590e1 100644 --- a/lib/vsc/utils/exceptions.py +++ b/lib/vsc/utils/exceptions.py @@ -98,6 +98,8 @@ def __init__(self, msg, *args, **kwargs): # 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]):]) diff --git a/test/exceptions.py b/test/exceptions.py index 9f57e7c3..d21ffd24 100644 --- a/test/exceptions.py +++ b/test/exceptions.py @@ -139,21 +139,37 @@ def raise_testexception(msg, *args, **kwargs): self.assertErrorRegex(LoggedException, 'BOOM', raise_testexception, 'BOOM') logToFile(tmplog, enable=False) - log_re = re.compile("^%s :: BOOM$" % getRootLoggerName(), re.M) + 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() - TestException.LOC_INFO_TOP_PKG_NAMES = ['vsc'] # 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("^%s :: BOOM \(at vsc/utils/testing.py:[0-9]+ in assertErrorRegex\)$" % getRootLoggerName()) + 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)) From 5fe093d6ee28e6128bd7d591beef36a2e0a662b5 Mon Sep 17 00:00:00 2001 From: Kenneth Hoste Date: Thu, 9 Apr 2015 18:06:05 +0200 Subject: [PATCH 10/10] bump version to 2.1.3 --- setup.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/setup.py b/setup.py index c3923c64..3dd7f39d 100755 --- a/setup.py +++ b/setup.py @@ -52,7 +52,7 @@ def remove_bdist_rpm_source_file(): PACKAGE = { 'name': 'vsc-base', - 'version': '2.1.2', + 'version': '2.1.3', 'author': [sdw, jt, ag, kh], 'maintainer': [sdw, jt, ag, kh], 'packages': ['vsc', 'vsc.utils', 'vsc.install'],