[tor-commits] [ooni-probe/master] Add support for loglevels.

art at torproject.org art at torproject.org
Mon Sep 19 12:14:24 UTC 2016


commit 5a6a483bd0e1f1443f170955085543ef11aac34f
Author: Arturo Filastò <arturo at filasto.net>
Date:   Wed Jul 27 23:47:45 2016 +0200

    Add support for loglevels.
    
    Small refactor of the logging facilities
    
    Note: now all messages printed with print() are not output to stdout by default
    and all messages that are not printed via the ooni logging infrastructure that
    are not critical are also ignored.
    
    This is useful to avoid cluttering the CLI with too many messages and also to
    reduce the size of the logs.
    
    This implements: #502
---
 ooni/nettest.py   |   8 +--
 ooni/settings.py  |  25 ++++++---
 ooni/ui/cli.py    |  12 ++--
 ooni/utils/log.py | 160 +++++++++++++++++++++++++++++++++++-------------------
 4 files changed, 133 insertions(+), 72 deletions(-)

diff --git a/ooni/nettest.py b/ooni/nettest.py
index 566c391..1978c68 100644
--- a/ooni/nettest.py
+++ b/ooni/nettest.py
@@ -148,7 +148,7 @@ def usageOptionsFactory(test_name, test_version):
             """
             Display the net_test version and exit.
             """
-            print "{} version: {}".format(test_name, test_version)
+            log.msg("{} version: {}".format(test_name, test_version))
             sys.exit(0)
 
     return UsageOptions
@@ -513,13 +513,13 @@ class NetTest(object):
 
     def doneNetTest(self, result):
         if self.summary:
-            print "Summary for %s" % self.testDetails['test_name']
-            print "------------" + "-"*len(self.testDetails['test_name'])
+            log.msg("Summary for %s" % self.testDetails['test_name'])
+            log.msg("------------" + "-"*len(self.testDetails['test_name']))
             for test_class in self.uniqueClasses():
                 test_instance = test_class()
                 test_instance.displaySummary(self.summary)
         if self.testDetails["report_id"]:
-            print "Report ID: %s" % self.testDetails["report_id"]
+            log.msg("Report ID: %s" % self.testDetails["report_id"])
 
     def doneReport(self, report_results):
         """
diff --git a/ooni/settings.py b/ooni/settings.py
index acb1895..194729a 100644
--- a/ooni/settings.py
+++ b/ooni/settings.py
@@ -9,7 +9,6 @@ from twisted.internet.endpoints import TCP4ClientEndpoint
 from os.path import abspath, expanduser
 
 from ooni.utils.net import ConnectAndCloseProtocol, connectProtocol
-from ooni import geoip
 from ooni.utils import Storage, log, get_ooni_root
 from ooni import errors
 
@@ -101,8 +100,6 @@ class OConfig(object):
             self.inputs_directory = os.path.join(self.ooni_home, 'inputs')
 
         self.scheduler_directory = os.path.join(self.ooni_home, 'scheduler')
-        if not os.path.exists(self.scheduler_directory):
-            os.mkdir(self.scheduler_directory)
 
         if self.advanced.decks_dir:
             self.decks_directory = self.advanced.decks_dir
@@ -136,11 +133,25 @@ class OConfig(object):
 
         ooni_home = self.ooni_home
         if not os.path.isdir(ooni_home):
-            print "Ooni home directory does not exist."
-            print "Creating it in '%s'." % ooni_home
+            log.msg("Ooni home directory does not exist")
+            log.msg("Creating it in '%s'" % ooni_home)
             os.mkdir(ooni_home)
-            os.mkdir(self.inputs_directory)
-            os.mkdir(self.decks_directory)
+
+        # also ensure the subdirectories exist
+        sub_directories = [
+            self.inputs_directory,
+            self.decks_directory,
+            self.scheduler_directory,
+            self.measurements_directory,
+            self.resources_directory
+        ]
+        for path in sub_directories:
+            try:
+                os.mkdir(path)
+            except OSError as exc:
+                if exc.errno != 17:
+                    raise
+
 
     def _create_config_file(self):
         target_config_file = self.config_file
diff --git a/ooni/ui/cli.py b/ooni/ui/cli.py
index 51ed3b9..2f5c467 100644
--- a/ooni/ui/cli.py
+++ b/ooni/ui/cli.py
@@ -339,9 +339,9 @@ def runWithDirector(global_options, create_input_store=True):
     director = Director()
     if global_options['list']:
         net_tests = [net_test for net_test in director.getNetTests().items()]
-        print ""
-        print "Installed nettests"
-        print "=================="
+        log.msg("")
+        log.msg("Installed nettests")
+        log.msg("==================")
         for net_test_id, net_test in net_tests:
             optList = []
             for name, details in net_test['arguments'].items():
@@ -359,9 +359,9 @@ def runWithDirector(global_options, create_input_store=True):
                     '\n\n' +
                     ''.join(usage.docMakeChunks(optList))
             )
-            print desc
-            print "Note: Third party tests require an external "\
-                  "application to run properly."
+            map(log.msg, desc.split("\n"))
+            log.msg("Note: Third party tests require an external "
+                    "application to run properly.")
 
         raise SystemExit(0)
 
diff --git a/ooni/utils/log.py b/ooni/utils/log.py
index fd80594..c8a7360 100644
--- a/ooni/utils/log.py
+++ b/ooni/utils/log.py
@@ -2,11 +2,8 @@ import os
 import sys
 import codecs
 import logging
-import traceback
 
-from twisted.python import log as txlog
-from twisted.python import util
-from twisted.python.failure import Failure
+from twisted.python import log as tw_log
 from twisted.python.logfile import DailyLogFile
 
 from ooni import otime
@@ -15,7 +12,6 @@ from ooni import otime
 # IPv6 destination warnings":
 logging.getLogger("scapy.runtime").setLevel(logging.ERROR)
 
-
 def log_encode(logmsg):
     """
     I encode logmsg (a str or unicode) as printable ASCII. Each case
@@ -38,17 +34,97 @@ def log_encode(logmsg):
                                                      repr(logmsg)))
 
 
-class LogWithNoPrefix(txlog.FileLogObserver):
+levels = {
+    'NONE': 9999,
+    'CRITICAL': 50,
+    'ERROR': 40,
+    'WARNING': 30,
+    # This is the name twisted gives it
+    'WARN': 30,
+    'NOTICE': 25,
+    'INFO': 20,
+    'DEBUG': 10,
+}
+
+class LogLevelObserver(tw_log.FileLogObserver):
+    def __init__(self, f, log_level=levels['INFO']):
+        tw_log.FileLogObserver.__init__(self, f)
+        self.log_level = log_level
+
+    def should_emit(self, eventDict):
+        if eventDict['isError']:
+            level = levels['ERROR']
+        elif 'log_level' in eventDict:
+            level = eventDict['log_level']
+        else:
+            level = levels['INFO']
+
+        # To support twisted > 15.2 log_level argument
+        if hasattr(level, 'name'):
+            level = levels[level.name.upper()]
+
+        source = 'unknown'
+        if 'source' in eventDict:
+            source = eventDict['source']
+
+        # Don't log messages not coming from OONI unless the configured log
+        # level is debug and unless they are really important.
+        if (source != 'ooni' and
+                level <= levels['WARN'] and
+                self.log_level >= levels['DEBUG']):
+            return False
+
+        if level >= self.log_level:
+            return True
+        return False
+
     def emit(self, eventDict):
-        text = txlog.textFromEventDict(eventDict)
-        if text is None:
+        if not self.should_emit(eventDict):
             return
+        tw_log.FileLogObserver.emit(self, eventDict)
 
-        util.untilConcludes(self.write, "%s\n" % text)
-        util.untilConcludes(self.flush)  # Hoorj!
+class StdoutStderrObserver(LogLevelObserver):
+    stderr = sys.stderr
 
+    def emit(self, eventDict):
+        if not self.should_emit(eventDict):
+            return
+
+        text = tw_log.textFromEventDict(eventDict)
+        if eventDict['isError']:
+            self.stderr.write(text + "\n")
+            self.stderr.flush()
+        else:
+            self.write(text + "\n")
+            self.flush()
 
 class OONILogger(object):
+    def msg(self, msg, *arg, **kw):
+        text = log_encode(msg)
+        tw_log.msg(text, log_level=levels['INFO'], source="ooni")
+
+    def debug(self, msg, *arg, **kw):
+        text = log_encode(msg)
+        tw_log.msg(text, log_level=levels['DEBUG'], source="ooni")
+
+    def err(self, msg, *arg, **kw):
+        if isinstance(msg, str) or isinstance(msg, unicode):
+            text = "[!] " + log_encode(msg)
+            tw_log.msg(text, log_level=levels['ERROR'], source="ooni")
+        else:
+            tw_log.err(msg, source="ooni")
+
+    def warn(self, *arg, **kw):
+        text = log_encode(msg)
+        tw_log.msg(text, log_level=levels['WARNING'], source="ooni")
+
+    def exception(self, error):
+        """
+        Error can either be an error message to print to stdout and to the logfile
+        or it can be a twisted.python.failure.Failure instance.
+        """
+        tw_log.err(error, source="ooni")
+
     def start(self, logfile=None, application_name="ooniprobe"):
         from ooni.settings import config
 
@@ -57,18 +133,25 @@ class OONILogger(object):
 
         log_folder = os.path.dirname(logfile)
         log_filename = os.path.basename(logfile)
+        file_log_level = levels.get(config.basic.loglevel,
+                                    levels['INFO'])
+        stdout_log_level = levels['INFO']
+        if config.advanced.debug:
+            stdout_log_level = levels['DEBUG']
 
         daily_logfile = DailyLogFile(log_filename, log_folder)
 
-        txlog.msg("Starting %s on %s (%s UTC)" % (application_name,
-                                                  otime.prettyDateNow(),
-                                                  otime.prettyDateNowUTC()))
+        tw_log.msg("Starting %s on %s (%s UTC)" % (application_name,
+                                                   otime.prettyDateNow(),
+                                                   otime.prettyDateNowUTC()))
 
-        self.fileObserver = txlog.FileLogObserver(daily_logfile)
-        self.stdoutObserver = LogWithNoPrefix(sys.stdout)
+        self.fileObserver = LogLevelObserver(daily_logfile,
+                                             log_level=file_log_level)
+        self.stdoutObserver = StdoutStderrObserver(sys.stdout,
+                                                   log_level=stdout_log_level)
 
-        txlog.startLoggingWithObserver(self.stdoutObserver.emit)
-        txlog.addObserver(self.fileObserver.emit)
+        tw_log.startLoggingWithObserver(self.fileObserver.emit)
+        tw_log.addObserver(self.stdoutObserver.emit)
 
     def stop(self):
         self.stdoutObserver.stop()
@@ -76,42 +159,9 @@ class OONILogger(object):
 
 oonilogger = OONILogger()
 
+start = oonilogger.start
+stop = oonilogger.stop
 
-def start(logfile=None, application_name="ooniprobe"):
-    oonilogger.start(logfile, application_name)
-
-
-def stop():
-    oonilogger.stop()
-
-
-def msg(msg, *arg, **kw):
-    from ooni.settings import config
-    if config.logging:
-        print "%s" % log_encode(msg)
-
-
-def debug(msg, *arg, **kw):
-    from ooni.settings import config
-    if config.advanced.debug and config.logging:
-        print "[D] %s" % log_encode(msg)
-
-
-def err(msg, *arg, **kw):
-    from ooni.settings import config
-    if config.logging:
-        if isinstance(msg, Exception):
-            msg = "%s: %s" % (msg.__class__.__name__, msg)
-        print "[!] %s" % log_encode(msg)
-
-
-def exception(error):
-    """
-    Error can either be an error message to print to stdout and to the logfile
-    or it can be a twisted.python.failure.Failure instance.
-    """
-    if isinstance(error, Failure):
-        error.printTraceback(sys.stdout)
-    else:
-        exc_type, exc_value, exc_traceback = sys.exc_info()
-        traceback.print_exception(exc_type, exc_value, exc_traceback)
+msg = oonilogger.msg
+debug = oonilogger.debug
+err = oonilogger.err





More information about the tor-commits mailing list