[tor-commits] [ooni-probe/master] Make logged work again

art at torproject.org art at torproject.org
Tue Oct 23 10:04:45 UTC 2012


commit c39e1f412ce8362db0832072f0b870646b1eb42d
Author: Arturo Filastò <arturo at filasto.net>
Date:   Tue Oct 23 09:12:59 2012 +0000

    Make logged work again
    * A good opportunity to refactor logging related code
    * Implement time related utilities
    * Start outlining configuration script
    * Move netalyzr test to nettest
    * XXX the new API tests are not working properly
---
 nettests/core/dnstamper.py                         |   23 +++-
 nettests/core/http_host.py                         |   15 +++
 nettests/third_party/Makefile                      |    3 +
 nettests/third_party/README                        |   14 ++
 nettests/third_party/netalyzr.py                   |   42 ++++++
 .../ooni/plugins/netalyzr_plgoo.py                 |   30 -----
 old-to-be-ported-code/third-party/Makefile         |    3 -
 old-to-be-ported-code/third-party/README           |   14 --
 ooni/config.py                                     |    7 +
 ooni/nettest.py                                    |   11 ++-
 ooni/runner.py                                     |    1 +
 ooni/utils/log.py                                  |  132 ++++++-------------
 ooni/utils/otime.py                                |   43 +++++++
 13 files changed, 197 insertions(+), 141 deletions(-)

diff --git a/nettests/core/dnstamper.py b/nettests/core/dnstamper.py
index 0f40c1c..1028291 100644
--- a/nettests/core/dnstamper.py
+++ b/nettests/core/dnstamper.py
@@ -27,7 +27,7 @@ class DNSTamperTest(nettest.TestCase):
     name = "DNS tamper"
 
     description = "DNS censorship detection test"
-    version = '0.2'
+    version = "0.2"
 
     lookupTimeout = [1]
 
@@ -38,8 +38,7 @@ class DNSTamperTest(nettest.TestCase):
     optParameters = [['controlresolver', 'c', '8.8.8.8',
                       'Known good DNS server'],
                      ['testresolvers', 't', None,
-                      'file containing list of DNS resolvers to test against']
-                     ]
+                      'file containing list of DNS resolvers to test against']]
 
     def setUp(self):
         self.report['test_lookups'] = {}
@@ -130,6 +129,24 @@ class DNSTamperTest(nettest.TestCase):
             self.test_a_lookups[resolver] = None
 
     def test_lookup(self):
+        """
+        We perform an A lookup on the DNS test servers for the domains to be
+        tested and an A lookup on the known good DNS server.
+
+        We then compare the results from test_resolvers and that from
+        control_resolver and see if the match up.
+        If they match up then no censorship is happening (tampering: false).
+
+        If they do not we do a reverse lookup (PTR) on the test_resolvers and
+        the control resolver for every IP address we got back and check to see
+        if anyone of them matches the control ones.
+
+        If they do then we take not of the fact that censorship is probably not
+        happening (tampering: reverse-match).
+
+        If they do not match then censorship is probably going on (tampering:
+        true).
+        """
         print "Doing the test lookups on %s" % self.input
         list_of_ds = []
         hostname = self.input
diff --git a/nettests/core/http_host.py b/nettests/core/http_host.py
index 2228c52..62b50ca 100644
--- a/nettests/core/http_host.py
+++ b/nettests/core/http_host.py
@@ -12,6 +12,10 @@
 from ooni.templates import httpt
 
 class HTTPHost(httpt.HTTPTest):
+    """
+    This test is aimed at detecting the presence of a transparent HTTP proxy
+    and enumerating the sites that are being censored by it.
+    """
     name = "HTTP Host"
     author = "Arturo Filastò"
     version = 0.1
@@ -23,11 +27,22 @@ class HTTPHost(httpt.HTTPTest):
     inputFile = ['urls', 'f', None, 'Urls file']
 
     def test_send_host_header(self):
+        """
+        Stuffs the HTTP Host header field with the site to be tested for
+        censorship and does an HTTP request of this kind to our backend.
+
+        We randomize the HTTP User Agent headers.
+        """
         headers = {}
         headers["Host"] = [self.input]
         return self.doRequest(self.localOptions['backend'], headers=headers)
 
     def processResponseBody(self, body):
+        """
+        XXX this is to be filled in with either a domclass based classified or
+        with a rule that will allow to detect that the body of the result is
+        that of a censored site.
+        """
         if 'not censored' in body:
             self.report['trans_http_proxy'] = False
         else:
diff --git a/nettests/third_party/Makefile b/nettests/third_party/Makefile
new file mode 100644
index 0000000..16adfe0
--- /dev/null
+++ b/nettests/third_party/Makefile
@@ -0,0 +1,3 @@
+fetch:
+	wget http://netalyzr.icsi.berkeley.edu/NetalyzrCLI.jar
+	chmod +x NetalyzrCLI.jar
diff --git a/nettests/third_party/README b/nettests/third_party/README
new file mode 100644
index 0000000..d9e435f
--- /dev/null
+++ b/nettests/third_party/README
@@ -0,0 +1,14 @@
+There is no license for NetalyzrCLI.jar; so while we include it, it's just
+for ease of use.
+
+We currently support interfacing with the ICSI Netalyzr system by wrapping
+the NetalyzrCLI.jar client. It was downloaded on August 5th, 2011 from the
+following URL:
+  http://netalyzr.icsi.berkeley.edu/NetalyzrCLI.jar
+
+More information about the client is available on the cli web page:
+  http://netalyzr.icsi.berkeley.edu/cli.html
+
+After looking at NetalyzrCLI.jar, I discovered that '-d' runs it in a
+debugging mode that is quite useful for understanding their testing
+framework as it runs.
diff --git a/nettests/third_party/netalyzr.py b/nettests/third_party/netalyzr.py
new file mode 100644
index 0000000..041c0be
--- /dev/null
+++ b/nettests/third_party/netalyzr.py
@@ -0,0 +1,42 @@
+# -*- encoding: utf-8 -*-
+#
+# This is a wrapper around the Netalyzer Java command line client
+#
+# :authors: Jacob Appelbaum <jacob at appelbaum.net>
+#           Arturo "hellais" Filastò <art at fuffa.org>
+# :licence: see LICENSE
+
+from ooni import nettest
+from ooni.utils import log
+import time
+import os
+
+class NetalyzrWrapperTest(nettest.TestCase):
+    name = "NetalyzrWrapper"
+    type = "wrapper"
+
+    def setUp(self):
+        cwd = os.path.join(os.path.abspath(__file__), '..')
+
+        # XXX set the output directory to something more uniform
+        outputdir = os.path.join(cwd, '..', '..')
+
+        program_path = os.path.join(cwd, 'NetalyzrCLI')
+        program = "java -jar %s " % program_path
+
+        test_token = time.asctime(time.gmtime()).replace(" ", "_").strip()
+
+        output_file = os.path.join(outputdir,
+                "NetalyzrCLI_" + test_token + ".out")
+        output_file.strip()
+        self.run_me = program + " 2>&1 >> " + output_file
+
+    def test_run_netalyzr(self):
+        """
+        This test simply wraps netalyzr and runs it from command line
+        """
+        log.msg("running NetalyzrWrapper with command '%s'" % self.run_me)
+        os.system(self.run_me)
+        self.report['netalyzr_report'] = self.output_file
+        log.msg("finished running NetalzrWrapper")
+
diff --git a/old-to-be-ported-code/ooni/plugins/netalyzr_plgoo.py b/old-to-be-ported-code/ooni/plugins/netalyzr_plgoo.py
deleted file mode 100644
index 05e0990..0000000
--- a/old-to-be-ported-code/ooni/plugins/netalyzr_plgoo.py
+++ /dev/null
@@ -1,30 +0,0 @@
-#!/usr/bin/python
-# This is a wrapper around the Netalyzer Java command line client
-# by Jacob Appelbaum <jacob at appelbaum.net>
-#
-from ooni.plugooni import Plugoo
-import time
-import os
-
-class NetalyzrPlugin(Plugoo):
-  def __init__(self):
-    self.name = "Netalyzr"
-    self.type = "wrapper"
-    self.paranoia = "low"
-    self.modules_to_import = ["os", "time"]
-    self.output_dir = "results/"
-    self.program = "java -jar third-party/NetalyzrCLI.jar "
-    self.test_token = time.asctime(time.gmtime()).replace(" ", "_").strip()
-    self.output_file = self.output_dir + "NetalyzrCLI_" + self.test_token + ".out"
-    self.output_file.strip()
-    self.run_me = self.program + " 2>&1 >> " + self.output_file
-
-  def NetalzrWrapper(self):
-   return os.system(self.run_me)
-
-  def ooni_main(self, cmd):
-    print "running NetalzrWrapper"
-    r = self.NetalzrWrapper()
-    print "finished running NetalzrWrapper"
-    return r
-
diff --git a/old-to-be-ported-code/third-party/Makefile b/old-to-be-ported-code/third-party/Makefile
deleted file mode 100644
index 16adfe0..0000000
--- a/old-to-be-ported-code/third-party/Makefile
+++ /dev/null
@@ -1,3 +0,0 @@
-fetch:
-	wget http://netalyzr.icsi.berkeley.edu/NetalyzrCLI.jar
-	chmod +x NetalyzrCLI.jar
diff --git a/old-to-be-ported-code/third-party/README b/old-to-be-ported-code/third-party/README
deleted file mode 100644
index d9e435f..0000000
--- a/old-to-be-ported-code/third-party/README
+++ /dev/null
@@ -1,14 +0,0 @@
-There is no license for NetalyzrCLI.jar; so while we include it, it's just
-for ease of use.
-
-We currently support interfacing with the ICSI Netalyzr system by wrapping
-the NetalyzrCLI.jar client. It was downloaded on August 5th, 2011 from the
-following URL:
-  http://netalyzr.icsi.berkeley.edu/NetalyzrCLI.jar
-
-More information about the client is available on the cli web page:
-  http://netalyzr.icsi.berkeley.edu/cli.html
-
-After looking at NetalyzrCLI.jar, I discovered that '-d' runs it in a
-debugging mode that is quite useful for understanding their testing
-framework as it runs.
diff --git a/ooni/config.py b/ooni/config.py
new file mode 100644
index 0000000..96a1ee0
--- /dev/null
+++ b/ooni/config.py
@@ -0,0 +1,7 @@
+from ooni.utils import Storage
+
+# XXX move this to an actual configuration file
+basic = Storage()
+advanced = Storage()
+
+advanced.debug = True
diff --git a/ooni/nettest.py b/ooni/nettest.py
index f1232c7..768833a 100644
--- a/ooni/nettest.py
+++ b/ooni/nettest.py
@@ -3,7 +3,7 @@ import os
 
 from twisted.python import log, usage
 from twisted.trial import unittest, itrial
-from twisted.internet import defer
+from twisted.internet import defer, utils
 
 pyunit = __import__('unittest')
 
@@ -79,6 +79,15 @@ class TestCase(unittest.TestCase):
 
     optParameters = None
 
+    def _run(self, methodName, result):
+        from twisted.internet import reactor
+        method = getattr(self, methodName)
+        d = defer.maybeDeferred(
+                utils.runWithWarningsSuppressed, self._getSuppress(), method)
+        d.addBoth(lambda x : call.active() and call.cancel() or x)
+        return d
+
+
     def deferSetUp(self, ignored, result):
         """
         If we have the reporterFactory set we need to write the header. If such
diff --git a/ooni/runner.py b/ooni/runner.py
index 7aa8676..1fbc4fe 100644
--- a/ooni/runner.py
+++ b/ooni/runner.py
@@ -238,6 +238,7 @@ class ORunner(object):
         result.done()
 
     def run(self):
+        log.start()
         self.reporterFactory.options = self.options
         for inputUnit in InputUnitFactory(self.inputs):
             self.runWithInputUnit(inputUnit)
diff --git a/ooni/utils/log.py b/ooni/utils/log.py
index eef50d8..2b5c1ac 100644
--- a/ooni/utils/log.py
+++ b/ooni/utils/log.py
@@ -1,98 +1,50 @@
-"""
-OONI logging facility.
-"""
-from sys                    import stderr, stdout
-
-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 number['info']
+# -*- encoding: utf-8 -*-
+#
+# :authors: Arturo Filastò
+# :licence: see LICENSE
+
+import sys
+import os
+import logging
+
+from twisted.python import log as txlog
+from twisted.python.logfile import DailyLogFile
+
+from ooni.utils import otime
+from ooni import config
+
+# XXX make this a config option
+log_file = "/tmp/ooniprobe.log"
+
+log_folder = os.path.join('/', *log_file.split('/')[:-1])
+log_filename = log_file.split('/')[-1]
+daily_logfile = DailyLogFile(log_filename, log_folder)
+
+def start():
+    txlog.msg("Starting OONI on %s (%s UTC)" %  (otime.prettyDateNow(),
+                                                 otime.utcPrettyDateNow()))
+    logging.basicConfig()
+    python_logging = txlog.PythonLoggingObserver()
+    if config.advanced.debug:
+        python_logging.logger.setLevel(logging.DEBUG)
     else:
-        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
-
-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_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:
-            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)
+        python_logging.logger.setLevel(logging.INFO)
 
-def start(logfile=None, verbosity=None):
-    if log.defaultObserver:
-        verbosity = _get_log_level(verbosity)
+    txlog.startLoggingWithObserver(python_logging.emit)
 
-        ## Always log to file, keep level at info
-        file = open(logfile, 'a') if logfile else stderr
-        OONILogObserver(file, "info").start()
+    txlog.addObserver(txlog.FileLogObserver(daily_logfile).emit)
 
-        log.msg("Starting OONI...")
+def stop():
+    txlog.msg("Stopping OONI")
 
-def debug(message, level="debug", **kw):
-    print "[%s] %s" % (level, message)
-    ## If we want debug messages in the logfile:
-    #log.msg(message, logLevel=level, **kw)
+def msg(msg, *arg, **kw):
+    txlog.msg(msg, logLevel=logging.INFO, *arg, **kw)
 
-def msg(message, level="info", **kw):
-    log.msg(message, logLevel=level, **kw)
+def debug(msg, *arg, **kw):
+    txlog.msg(msg, logLevel=logging.DEBUG, *arg, **kw)
 
-def err(message, level="err", **kw):
-    log.err(logLevel=level, **kw)
+def err(msg, *arg, **kw):
+    txlog.err(msg, logLevel=logging.ERROR, *arg, **kw)
 
-def fail(message, exception, level="crit", **kw):
-    log.failure(message, OONITestFailure(exception, **kw), logLevel=level)
+def exception(*msg):
+    logging.exception(msg)
diff --git a/ooni/utils/otime.py b/ooni/utils/otime.py
new file mode 100644
index 0000000..11f7be1
--- /dev/null
+++ b/ooni/utils/otime.py
@@ -0,0 +1,43 @@
+# -*- encoding: utf-8 -*-
+#
+# :authors: Arturo Filastò
+# :licence: see LICENSE
+
+"""
+Here is the location for all time and date related utility functions.
+"""
+import time
+from datetime import datetime
+
+def utcDateNow():
+    """
+    Returns the datetime object of the current UTC time.
+    """
+    return datetime.utcnow()
+
+def utcTimeNow():
+    """
+    Returns seconds since epoch in UTC time, it's of type float.
+    """
+    return time.mktime(time.gmtime())
+
+def dateToTime(date):
+    """
+    Takes as input a datetime object and outputs the seconds since epoch.
+    """
+    return time.mktime(date.timetuple())
+
+def prettyDateNow():
+    """
+    Returns a good looking string for the local time.
+    """
+    return datetime.now().ctime()
+
+def utcPrettyDateNow():
+    """
+    Returns a good looking string for utc time.
+    """
+    return datetime.utcnow().ctime()
+
+def timeToPrettyDate(time_val):
+    return time.ctime(time_val)





More information about the tor-commits mailing list