commit df762643f4df5e9caec69b3b649d26f1e51c2210 Author: Isis Lovecruft <isis@torproject.org> Date: Thu Sep 13 12:47:40 2012 +0000 Implemented logging verbosity levels with global options. There's also an option now to suppress stdout. By default, all emit() messages still go the oonicli.log, regardless of logging level -- this is easily changed, however, by default we want all the info we can get. --- ooni/ooniprobe.py | 14 +++++- ooni/plugoo/tests.py | 10 +++- ooni/utils/log.py | 116 +++++++++++++++++++++++++++++++++++++------------ 3 files changed, 106 insertions(+), 34 deletions(-) diff --git a/ooni/ooniprobe.py b/ooni/ooniprobe.py index 4b5c086..03b98b8 100755 --- a/ooni/ooniprobe.py +++ b/ooni/ooniprobe.py @@ -72,7 +72,13 @@ def runTest(test, options, global_options, reactor=reactor): test_class = plugoo[test].__class__ report = reports.Report(test, global_options['output']) - log.start(global_options['log'], 1) + log_to_stdout = True + if global_options['quiet']: + log_to_stdout = False + + log.start(log_to_stdout, + global_options['log'], + global_options['verbosity']) resume = 0 if not options: options = {} @@ -103,7 +109,8 @@ class Options(usage.Options): optFlags = [ #['remote', 'r', "If the test should be run remotely (not supported)"], #['status', 'x', 'Show current state'], - #['restart', 'r', 'Restart OONI'] + #['restart', 'r', 'Restart OONI'], + ['quiet', 'q', "Don't log to stdout"] ] optParameters = [ @@ -111,6 +118,7 @@ class Options(usage.Options): #['target-node', 't', 'localhost:31415', 'Select target node'], ['output', 'o', 'report.log', "Specify output report file"], ['log', 'l', 'oonicli.log', "Specify output log file"], + ['verbosity', 'v', 1, "Specify the logging level"], #['password', 'p', 'opennetwork', "Specify the password for authentication"], ] @@ -134,7 +142,7 @@ if __name__ == "__main__": config.parseOptions() if not config.subCommand: - print "Error! No Test Specified." + #print "Error! No Test Specified." config.opt_help() sys.exit(1) diff --git a/ooni/plugoo/tests.py b/ooni/plugoo/tests.py index 13c06ed..a827093 100644 --- a/ooni/plugoo/tests.py +++ b/ooni/plugoo/tests.py @@ -58,7 +58,8 @@ class OONITest(object): return {} def __repr__(self): - return "<OONITest %s %s %s>" % (self.options, self.global_options, + return "<OONITest %s %s %s>" % (self.local_options, + self.global_options, self.assets) def end(self): @@ -132,6 +133,11 @@ class OONITest(object): @param args: the asset(s) lines that we are working on. """ self.start_time = date.now() - log.msg("Starting test %s" % self.__class__) + + if self.shortName: + log.msg("Starting test %s" % self.shortName) + else: + log.msg("Starting test %s" % self.__class__) + return self._do_experiment(args) diff --git a/ooni/utils/log.py b/ooni/utils/log.py index 3dc52dd..cf57186 100644 --- a/ooni/utils/log.py +++ b/ooni/utils/log.py @@ -1,43 +1,101 @@ """ OONI logging facility. """ -import sys -import logging -import warnings +from sys import stderr, stdout -from twisted.python import log - -# Logging levels -DEBUG = logging.DEBUG -INFO = logging.INFO -WARNING = logging.WARNING -ERROR = logging.ERROR -CRITICAL = logging.CRITICAL +from twisted.python import log, util +from twisted.python.failure import Failure def _get_log_level(level): + english = ['debug', 'info', 'warn', 'err', 'crit'] + + levels = dict(zip(range(len(english)), english)) + number = dict(zip(english, range(len(english)))) + if not level: - return INFO + return number['info'] else: - return level + ve = "Unknown log level: %s\n" % level + ve += "Allowed levels: %s\n" % [word for word in english] + + if type(level) is int: + if 0 <= level <= 4: + return level + elif type(level) is str: + if number.has_key(level.lower()): + return number[level] + else: + raise ValueError, ve + else: + raise ValueError, ve -def start(logfile=None, loglevel=None, logstdout=True): - if log.defaultObserver: - print "%s" % logstdout - loglevel = _get_log_level(loglevel) - file = open(logfile, 'a') if logfile else sys.stderr - observer = log.FileLogObserver(file) - if logstdout: - log.startLogging(sys.stdout) +class OONITestFailure(Failure): + """ + For handling Exceptions asynchronously. + + Can be given an Exception as an argument, else will use the + most recent Exception from the current stack frame. + """ + def __init__(self, exception=None, _type=None, + _traceback=None, _capture=False): + Failure.__init__(self, exc_value=exception, exc_type=_type, + exc_tb=_traceback, captureVars=_capture) + +class OONILogObserver(log.FileLogObserver): + """ + Supports logging level verbosity. + """ + def __init__(self, logfile, verb=None): + log.FileLogObserver.__init__(self, logfile) + self.level = _get_log_level(verb) if verb is not None else 1 + assert type(self.level) is int + + def emit(self, eventDict): + if 'logLevel' in eventDict: + msgLvl = _get_log_level(eventDict['logLevel']) + assert type(msgLvl) is int + ## only log our level and higher + if self.level <= msgLvl: + text = log.textFromEventDict(eventDict) + else: + text = None else: - log.startLogging() - log.addObserver(observer.emit) - msg("Started OONI") + text = log.textFromEventDict(eventDict) + + if text is None: + return + + timeStr = self.formatTime(eventDict['time']) + fmtDict = {'system': eventDict['system'], + 'text': text.replace('\n','\n\t')} + msgStr = log._safeFormat("[%(system)s] %(text)s\n", fmtDict) + + util.untilConcludes(self.write, timeStr + " " + msgStr) + util.untilConcludes(self.flush) + +def start(logstdout, logfile=None, verbosity=None): + if log.defaultObserver: + verbosity = _get_log_level(verbosity) + + ## Always log to file, keep level at info + file = open(logfile, 'a') if logfile else stderr + OONILogObserver(file, "info").start() + + if logstdout is True: + observerooni = OONILogObserver(stdout, verbosity) + log.addObserver(observerooni.emit) + + log.msg("Starting OONI...") + +def debug(message, level="debug", **kw): + log.msg(message, logLevel=level, **kw) -def msg(message, level=INFO, **kw): +def msg(message, level="info", **kw): log.msg(message, logLevel=level, **kw) -def err(message, **kw): - log.err(message, **kw) +## XXX fixme log.err messages get printed to stdout twice +def err(message, level="err", **kw): + log.err(message, logLevel=level, **kw) -def debug(message, **kw): - log.msg(message, logLevel=DEBUG, **kw) +def fail(message, exception=None, level="crit", **kw): + log.failure(message, OONITestFailure(exception, **kw), logLevel=level)