From a09f3e06c36f440b9975cbdb8379734eae9f47cc Mon Sep 17 00:00:00 2001
From: Aldo Cortesi <aldo@nullcube.com>
Date: Sat, 30 May 2015 17:43:01 +1200
Subject: [PATCH] Factor logger out of pathoc, use it in pathod as well.

---
 libpathod/log.py           |  57 ++++++++
 libpathod/pathoc.py        |  58 +-------
 libpathod/pathod.py        | 290 ++++++++++++++++++-------------------
 libpathod/test.py          |   1 +
 libpathod/utils.py         |  10 +-
 test/test_language_base.py |   2 +-
 test/test_pathod.py        |   4 +-
 test/test_utils.py         |   2 +-
 8 files changed, 213 insertions(+), 211 deletions(-)
 create mode 100644 libpathod/log.py

diff --git a/libpathod/log.py b/libpathod/log.py
new file mode 100644
index 000000000..67898dd18
--- /dev/null
+++ b/libpathod/log.py
@@ -0,0 +1,57 @@
+import netlib.utils
+import netlib.tcp
+import netlib.http
+
+
+class Log:
+    def __init__(self, fp, hex, rfile, wfile):
+        self.lines = []
+        self.fp = fp
+        self.suppressed = False
+        self.hex = hex
+        self.rfile, self.wfile = rfile, wfile
+
+    def __enter__(self):
+        if self.wfile:
+            self.wfile.start_log()
+        if self.rfile:
+            self.rfile.start_log()
+        return self
+
+    def __exit__(self, exc_type, exc_value, traceback):
+        wlog = self.wfile.get_log() if self.wfile else None
+        rlog = self.rfile.get_log() if self.rfile else None
+        if self.suppressed or not self.fp:
+            return
+        if wlog:
+            self("Bytes written:")
+            self.dump(wlog, self.hex)
+        if rlog:
+            self("Bytes read:")
+            self.dump(rlog, self.hex)
+        if exc_type == netlib.tcp.NetLibTimeout:
+            self("Timeout")
+        elif exc_type in (
+            netlib.tcp.NetLibDisconnect,
+            netlib.http.HttpErrorConnClosed
+        ):
+            self("Disconnected")
+        elif exc_type == netlib.http.HttpError:
+            self("HTTP Error: %s" % exc_value.message)
+        self.fp.write("\n".join(self.lines))
+        self.fp.write("\n")
+        self.fp.flush()
+
+    def suppress(self):
+        self.suppressed = True
+
+    def dump(self, data, hexdump):
+        if hexdump:
+            for line in netlib.utils.hexdump(data):
+                self("\t%s %s %s" % line)
+        else:
+            for i in netlib.utils.cleanBin(data).split("\n"):
+                self("\t%s" % i)
+
+    def __call__(self, line):
+        self.lines.append(line)
diff --git a/libpathod/pathoc.py b/libpathod/pathoc.py
index edb6108fd..59c88910c 100644
--- a/libpathod/pathoc.py
+++ b/libpathod/pathoc.py
@@ -10,68 +10,16 @@ import threading
 import OpenSSL.crypto
 
 from netlib import tcp, http, certutils, websockets
-import netlib.utils
 
 import language.http
 import language.websockets
-import utils
+from . import utils, log
 
 
 class PathocError(Exception):
     pass
 
 
-class Log:
-    def __init__(self, fp, hex, rfile, wfile):
-        self.lines = []
-        self.fp = fp
-        self.suppressed = False
-        self.hex = hex
-        self.rfile, self.wfile = rfile, wfile
-
-    def __enter__(self):
-        if self.wfile:
-            self.wfile.start_log()
-        if self.rfile:
-            self.rfile.start_log()
-        return self
-
-    def __exit__(self, exc_type, exc_value, traceback):
-        wlog = self.wfile.get_log() if self.wfile else None
-        rlog = self.rfile.get_log() if self.rfile else None
-        if self.suppressed or not self.fp:
-            return
-        if wlog:
-            self("Bytes written:")
-            self.dump(wlog, self.hex)
-        if rlog:
-            self("Bytes read:")
-            self.dump(rlog, self.hex)
-        if exc_type == tcp.NetLibTimeout:
-            self("Timeout")
-        elif exc_type in (tcp.NetLibDisconnect, http.HttpErrorConnClosed):
-            self("Disconnected")
-        elif exc_type == http.HttpError:
-            self("HTTP Error: %s" % exc_value.message)
-        self.fp.write("\n".join(self.lines))
-        self.fp.write("\n")
-        self.fp.flush()
-
-    def suppress(self):
-        self.suppressed = True
-
-    def dump(self, data, hexdump):
-        if hexdump:
-            for line in netlib.utils.hexdump(data):
-                self("\t%s %s %s" % line)
-        else:
-            for i in netlib.utils.cleanBin(data).split("\n"):
-                self("\t%s" % i)
-
-    def __call__(self, line):
-        self.lines.append(line)
-
-
 class SSLInfo:
     def __init__(self, certchain, cipher):
         self.certchain, self.cipher = certchain, cipher
@@ -149,7 +97,7 @@ class WebsocketFrameReader(threading.Thread):
         self.is_done = Queue.Queue()
 
     def log(self, rfile):
-        return Log(
+        return log.Log(
             self.logfp,
             self.hexdump,
             rfile if self.showresp else None,
@@ -242,7 +190,7 @@ class Pathoc(tcp.TCPClient):
         self.ws_framereader = None
 
     def log(self):
-        return Log(
+        return log.Log(
             self.fp,
             self.hexdump,
             self.rfile if self.showresp else None,
diff --git a/libpathod/pathod.py b/libpathod/pathod.py
index 4ad6cc194..b93d0d5cf 100644
--- a/libpathod/pathod.py
+++ b/libpathod/pathod.py
@@ -7,7 +7,7 @@ import urllib
 from netlib import tcp, http, wsgi, certutils, websockets
 import netlib.utils
 
-from . import version, app, language, utils
+from . import version, app, language, utils, log
 import language.http
 import language.actions
 
@@ -60,7 +60,8 @@ class PathodHandler(tcp.BaseHandler):
     wbufsize = 0
     sni = None
 
-    def __init__(self, connection, address, server, settings):
+    def __init__(self, connection, address, server, logfp, settings):
+        self.logfp = logfp
         tcp.BaseHandler.__init__(self, connection, address, server)
         self.settings = copy.copy(settings)
 
@@ -106,158 +107,145 @@ class PathodHandler(tcp.BaseHandler):
             again: True if request handling should continue.
             log: A dictionary, or None
         """
-        if self.server.logreq:
-            self.rfile.start_log()
-        if self.server.logresp:
-            self.wfile.start_log()
+        lr = self.rfile if self.server.logreq else None
+        lw = self.wfile if self.server.logresp else None
+        with log.Log(self.logfp, self.server.hexdump, lr, lw) as lg:
+            line = http.get_request_line(self.rfile)
+            if not line:
+                # Normal termination
+                return False
 
-        line = http.get_request_line(self.rfile)
-        if not line:
-            # Normal termination
-            return False
+            m = utils.MemBool()
+            if m(http.parse_init_connect(line)):
+                headers = http.read_headers(self.rfile)
+                self.wfile.write(
+                    'HTTP/1.1 200 Connection established\r\n' +
+                    ('Proxy-agent: %s\r\n' % version.NAMEVERSION) +
+                    '\r\n'
+                )
+                self.wfile.flush()
+                if not self.server.ssloptions.not_after_connect:
+                    try:
+                        cert, key, chain_file = self.server.ssloptions.get_cert(
+                            m.v[0]
+                        )
+                        self.convert_to_ssl(
+                            cert,
+                            key,
+                            handle_sni=self.handle_sni,
+                            request_client_cert=self.server.ssloptions.request_client_cert,
+                            cipher_list=self.server.ssloptions.ciphers,
+                            method=self.server.ssloptions.sslversion,
+                        )
+                    except tcp.NetLibError as v:
+                        s = str(v)
+                        lg(s)
+                        self.addlog(dict(type="error", msg=s))
+                        return False
+                return True
+            elif m(http.parse_init_proxy(line)):
+                method, _, _, _, path, httpversion = m.v
+            elif m(http.parse_init_http(line)):
+                method, path, httpversion = m.v
+            else:
+                s = "Invalid first line: %s" % repr(line)
+                lg(s)
+                self.addlog(dict(type="error", msg=s))
+                return False
 
-        m = utils.MemBool()
-        if m(http.parse_init_connect(line)):
             headers = http.read_headers(self.rfile)
-            self.wfile.write(
-                'HTTP/1.1 200 Connection established\r\n' +
-                ('Proxy-agent: %s\r\n' % version.NAMEVERSION) +
-                '\r\n'
+            if headers is None:
+                s = "Invalid headers"
+                lg(s)
+                self.addlog(dict(type="error", msg=s))
+                return False
+
+            clientcert = None
+            if self.clientcert:
+                clientcert = dict(
+                    cn=self.clientcert.cn,
+                    subject=self.clientcert.subject,
+                    serial=self.clientcert.serial,
+                    notbefore=self.clientcert.notbefore.isoformat(),
+                    notafter=self.clientcert.notafter.isoformat(),
+                    keyinfo=self.clientcert.keyinfo,
+                )
+
+            retlog = dict(
+                type="crafted",
+                request=dict(
+                    path=path,
+                    method=method,
+                    headers=headers.lst,
+                    httpversion=httpversion,
+                    sni=self.sni,
+                    remote_address=self.address(),
+                    clientcert=clientcert,
+                ),
+                cipher=None,
             )
-            self.wfile.flush()
-            if not self.server.ssloptions.not_after_connect:
+            if self.ssl_established:
+                retlog["cipher"] = self.get_current_cipher()
+
+            try:
+                content = http.read_http_body(
+                    self.rfile, headers, None,
+                    method, None, True
+                )
+            except http.HttpError as s:
+                s = str(s)
+                lg(s)
+                self.addlog(dict(type="error", msg=s))
+                return False
+
+            for i in self.server.anchors:
+                if i[0].match(path):
+                    lg("crafting anchor: %s" % path)
+                    again, retlog["response"] = self.serve_crafted(i[1])
+                    self.addlog(retlog)
+                    return again
+
+            if not self.server.nocraft and utils.matchpath(
+                    path,
+                    self.server.craftanchor):
+                spec = urllib.unquote(path)[len(self.server.craftanchor) + 1:]
+                key = websockets.check_client_handshake(headers)
+                self.settings.websocket_key = key
+                if key and not spec:
+                    spec = "ws"
+                lg("crafting spec: %s" % spec)
                 try:
-                    cert, key, chain_file = self.server.ssloptions.get_cert(
-                        m.v[0]
+                    crafted = language.parse_response(spec)
+                except language.ParseException as v:
+                    lg("Parse error: %s" % v.msg)
+                    crafted = language.http.make_error_response(
+                        "Parse Error",
+                        "Error parsing response spec: %s\n" % v.msg + v.marked()
                     )
-                    self.convert_to_ssl(
-                        cert,
-                        key,
-                        handle_sni=self.handle_sni,
-                        request_client_cert=self.server.ssloptions.request_client_cert,
-                        cipher_list=self.server.ssloptions.ciphers,
-                        method=self.server.ssloptions.sslversion,
-                    )
-                except tcp.NetLibError as v:
-                    s = str(v)
-                    self.info(s)
-                    self.addlog(dict(type="error", msg=s))
-                    return False
-            return True
-        elif m(http.parse_init_proxy(line)):
-            method, _, _, _, path, httpversion = m.v
-        elif m(http.parse_init_http(line)):
-            method, path, httpversion = m.v
-        else:
-            s = "Invalid first line: %s" % repr(line)
-            self.info(s)
-            self.addlog(dict(type="error", msg=s))
-            return False
-
-        headers = http.read_headers(self.rfile)
-        if headers is None:
-            s = "Invalid headers"
-            self.info(s)
-            self.addlog(dict(type="error", msg=s))
-            return False
-
-        clientcert = None
-        if self.clientcert:
-            clientcert = dict(
-                cn=self.clientcert.cn,
-                subject=self.clientcert.subject,
-                serial=self.clientcert.serial,
-                notbefore=self.clientcert.notbefore.isoformat(),
-                notafter=self.clientcert.notafter.isoformat(),
-                keyinfo=self.clientcert.keyinfo,
-            )
-
-        retlog = dict(
-            type="crafted",
-            request=dict(
-                path=path,
-                method=method,
-                headers=headers.lst,
-                httpversion=httpversion,
-                sni=self.sni,
-                remote_address=self.address(),
-                clientcert=clientcert,
-            ),
-            cipher=None,
-        )
-        if self.ssl_established:
-            retlog["cipher"] = self.get_current_cipher()
-
-        try:
-            content = http.read_http_body(
-                self.rfile, headers, None,
-                method, None, True
-            )
-        except http.HttpError as s:
-            s = str(s)
-            self.info(s)
-            self.addlog(dict(type="error", msg=s))
-            return False
-
-        for i in self.server.anchors:
-            if i[0].match(path):
-                self.info("crafting anchor: %s" % path)
-                again, retlog["response"] = self.serve_crafted(i[1])
+                again, retlog["response"] = self.serve_crafted(crafted)
                 self.addlog(retlog)
                 return again
-
-        if not self.server.nocraft and utils.matchpath(
-                path,
-                self.server.craftanchor):
-            spec = urllib.unquote(path)[len(self.server.craftanchor) + 1:]
-            key = websockets.check_client_handshake(headers)
-            self.settings.websocket_key = key
-            if key and not spec:
-                spec = "ws"
-            self.info("crafting spec: %s" % spec)
-            try:
-                crafted = language.parse_response(spec)
-            except language.ParseException as v:
-                self.info("Parse error: %s" % v.msg)
-                crafted = language.http.make_error_response(
-                    "Parse Error",
-                    "Error parsing response spec: %s\n" % v.msg + v.marked()
+            elif self.server.noweb:
+                crafted = language.http.make_error_response("Access Denied")
+                language.serve(crafted, self.wfile, self.settings)
+                self.addlog(dict(
+                    type="error",
+                    msg="Access denied: web interface disabled"
+                ))
+                return False
+            else:
+                lg("app: %s %s" % (method, path))
+                req = wsgi.Request("http", method, path, headers, content)
+                flow = wsgi.Flow(self.address, req)
+                sn = self.connection.getsockname()
+                a = wsgi.WSGIAdaptor(
+                    self.server.app,
+                    sn[0],
+                    self.server.address.port,
+                    version.NAMEVERSION
                 )
-            again, retlog["response"] = self.serve_crafted(crafted)
-            self.addlog(retlog)
-            return again
-        elif self.server.noweb:
-            crafted = language.http.make_error_response("Access Denied")
-            language.serve(crafted, self.wfile, self.settings)
-            self.addlog(dict(
-                type="error",
-                msg="Access denied: web interface disabled"
-            ))
-            return False
-        else:
-            self.info("app: %s %s" % (method, path))
-            req = wsgi.Request("http", method, path, headers, content)
-            flow = wsgi.Flow(self.address, req)
-            sn = self.connection.getsockname()
-            a = wsgi.WSGIAdaptor(
-                self.server.app,
-                sn[0],
-                self.server.address.port,
-                version.NAMEVERSION
-            )
-            a.serve(flow, self.wfile)
-            return True
-
-    def _log_bytes(self, header, data, hexdump):
-        s = []
-        if hexdump:
-            s.append("%s (hex dump):" % header)
-            for line in netlib.utils.hexdump(data):
-                s.append("\t%s %s %s" % line)
-        else:
-            s.append("%s (unprintables escaped):" % header)
-            s.append(netlib.utils.cleanBin(data))
-        self.info("\n".join(s))
+                a.serve(flow, self.wfile)
+                return True
 
     def addlog(self, log):
         # FIXME: The bytes in the log should not be escaped. We do this at the
@@ -265,11 +253,9 @@ class PathodHandler(tcp.BaseHandler):
         # want to base64 everything.
         if self.server.logreq:
             bytes = self.rfile.get_log().encode("string_escape")
-            self._log_bytes("Request", bytes, self.server.hexdump)
             log["request_bytes"] = bytes
         if self.server.logresp:
             bytes = self.wfile.get_log().encode("string_escape")
-            self._log_bytes("Response", bytes, self.server.hexdump)
             log["response_bytes"] = bytes
         self.server.add_log(log)
 
@@ -324,6 +310,7 @@ class Pathod(tcp.TCPServer):
         explain=False,
         hexdump=False,
         webdebug=False,
+        logfp=sys.stdout,
     ):
         """
             addr: (address, port) tuple. If port is 0, a free port will be
@@ -350,6 +337,7 @@ class Pathod(tcp.TCPServer):
         self.timeout, self.logreq = timeout, logreq
         self.logresp, self.hexdump = logresp, hexdump
         self.explain = explain
+        self.logfp = logfp
 
         self.app = app.make_app(noapi, webdebug)
         self.app.config["pathod"] = self
@@ -378,7 +366,13 @@ class Pathod(tcp.TCPServer):
         return None, req
 
     def handle_client_connection(self, request, client_address):
-        h = PathodHandler(request, client_address, self, self.settings)
+        h = PathodHandler(
+            request,
+            client_address,
+            self,
+            self.logfp,
+            self.settings
+        )
         try:
             h.handle()
             h.finish()
diff --git a/libpathod/test.py b/libpathod/test.py
index 136a62374..afd41f816 100644
--- a/libpathod/test.py
+++ b/libpathod/test.py
@@ -83,6 +83,7 @@ class _PaThread(threading.Thread):
         self.server = pathod.Pathod(
             (self.iface, 0),
             ssl = self.ssl,
+            logfp = None,
             **self.daemonargs
         )
         self.name = "PathodThread (%s:%s)" % (
diff --git a/libpathod/utils.py b/libpathod/utils.py
index dd0ae425d..1475500a1 100644
--- a/libpathod/utils.py
+++ b/libpathod/utils.py
@@ -10,11 +10,11 @@ SSLVERSIONS = {
 }
 
 SIZE_UNITS = dict(
-    b = 1024**0,
-    k = 1024**1,
-    m = 1024**2,
-    g = 1024**3,
-    t = 1024**4,
+    b = 1024 ** 0,
+    k = 1024 ** 1,
+    m = 1024 ** 2,
+    g = 1024 ** 3,
+    t = 1024 ** 4,
 )
 
 
diff --git a/test/test_language_base.py b/test/test_language_base.py
index d59ee88ba..020d68edb 100644
--- a/test/test_language_base.py
+++ b/test/test_language_base.py
@@ -85,7 +85,7 @@ class TestTokValueGenerate:
         v = base.TokValue.parseString("@10k")[0]
         assert v.bytes() == 10240
         v = base.TokValue.parseString("@10g")[0]
-        assert v.bytes() == 1024**3 * 10
+        assert v.bytes() == 1024 ** 3 * 10
 
         v = base.TokValue.parseString("@10g,digits")[0]
         assert v.datatype == "digits"
diff --git a/test/test_pathod.py b/test/test_pathod.py
index 7f07c0413..5ff3e68cb 100644
--- a/test/test_pathod.py
+++ b/test/test_pathod.py
@@ -1,3 +1,4 @@
+import cStringIO
 from libpathod import pathod, version
 from netlib import tcp, http
 import tutils
@@ -5,7 +6,8 @@ import tutils
 
 class TestPathod(object):
     def test_logging(self):
-        p = pathod.Pathod(("127.0.0.1", 0))
+        s = cStringIO.StringIO()
+        p = pathod.Pathod(("127.0.0.1", 0), logfp=s)
         assert len(p.get_log()) == 0
         id = p.add_log(dict(s="foo"))
         assert p.log_by_id(id)
diff --git a/test/test_utils.py b/test/test_utils.py
index 2a158a078..7d24e9e48 100644
--- a/test/test_utils.py
+++ b/test/test_utils.py
@@ -20,7 +20,7 @@ def test_parse_size():
 
 def test_parse_anchor_spec():
     assert utils.parse_anchor_spec("foo=200") == ("foo", "200")
-    assert utils.parse_anchor_spec("foo") == None
+    assert utils.parse_anchor_spec("foo") is None
 
 
 def test_data_path():