add support for log levels

10 files changed, 65 insertions, 60 deletions

diff --git a/libmproxy/console/__init__.py b/libmproxy/console/__init__.py
index ecca0909..1d58c01f 100644
--- a/libmproxy/console/__init__.py
+++ b/libmproxy/console/__init__.py
@@ -437,20 +437,20 @@ class ConsoleMaster(flow.FlowMaster):
         status, val = s.run(method, f)
         if val:
             if status:
-                self.add_event("Method %s return: %s"%(method, val))
+                self.add_event("Method %s return: %s"%(method, val), "debug")
             else:
-                self.add_event("Method %s error: %s"%(method, val[1]))
+                self.add_event("Method %s error: %s"%(method, val[1]), "error")
 
     def run_script_once(self, command, f):
         if not command:
             return
-        self.add_event("Running script on flow: %s"%command)
+        self.add_event("Running script on flow: %s"%command, "debug")
 
         try:
             s = script.Script(command, self)
         except script.ScriptError, v:
             self.statusbar.message("Error loading script.")
-            self.add_event("Error loading script:\n%s"%v.args[0])
+            self.add_event("Error loading script:\n%s"%v.args[0], "error")
             return
 
         if f.request:
@@ -582,7 +582,7 @@ class ConsoleMaster(flow.FlowMaster):
         if self.options.rfile:
             ret = self.load_flows(self.options.rfile)
             if ret and self.state.flow_count():
-                self.add_event("File truncated or corrupted. Loaded as many flows as possible.")
+                self.add_event("File truncated or corrupted. Loaded as many flows as possible.","error")
             elif not self.state.flow_count():
                 self.shutdown()
                 print >> sys.stderr, "Could not load file:", ret
@@ -1001,20 +1001,20 @@ class ConsoleMaster(flow.FlowMaster):
         self.eventlist[:] = []
 
     def add_event(self, e, level="info"):
-        if level == "info":
-            e = urwid.Text(str(e))
-        elif level == "error":
+        needed = dict(error=1, info=1, debug=2).get(level, 1)
+        if self.o.verbosity < needed:
+            return
+
+        if level == "error":
             e = urwid.Text(("error", str(e)))
+        else:
+            e = urwid.Text(str(e))
         self.eventlist.append(e)
         if len(self.eventlist) > EVENTLOG_SIZE:
             self.eventlist.pop(0)
         self.eventlist.set_focus(len(self.eventlist)-1)
 
     # Handlers
-    def handle_log(self, l):
-        self.add_event(l.msg)
-        l.reply()
-
     def handle_error(self, r):
         f = flow.FlowMaster.handle_error(self, r)
         if f:
diff --git a/libmproxy/console/contentview.py b/libmproxy/console/contentview.py
index 60ca13b8..5f3e17fe 100644
--- a/libmproxy/console/contentview.py
+++ b/libmproxy/console/contentview.py
@@ -490,7 +490,7 @@ def get_content_view(viewmode, hdrItems, content, limit, logfunc):
     except Exception:
         s = traceback.format_exc()
         s = "Content viewer failed: \n"  + s
-        logfunc(s)
+        logfunc(s, "error")
         ret = None
     if not ret:
         ret = get("Raw")(hdrs, content, limit)
diff --git a/libmproxy/dump.py b/libmproxy/dump.py
index 1b8e6665..1f107241 100644
--- a/libmproxy/dump.py
+++ b/libmproxy/dump.py
@@ -140,8 +140,8 @@ class DumpMaster(flow.FlowMaster):
             raise DumpError(v.strerror)
         return flows
 
-    def add_event(self, e, level="error"):
-        needed = dict(error=1, info=2, debug=3)[level]
+    def add_event(self, e, level="info"):
+        needed = dict(error=1, info=1, debug=2).get(level, 1)
         if self.o.verbosity >= needed:
             print >> self.outfile, e
             self.outfile.flush()
@@ -196,10 +196,6 @@ class DumpMaster(flow.FlowMaster):
         if self.o.flow_detail:
             self.outfile.flush()
 
-    def handle_log(self, l):
-        self.add_event(l.msg)
-        l.reply()
-
     def handle_request(self, r):
         f = flow.FlowMaster.handle_request(self, r)
         if f:
diff --git a/libmproxy/flow.py b/libmproxy/flow.py
index 08ef0e1e..a440b850 100644
--- a/libmproxy/flow.py
+++ b/libmproxy/flow.py
@@ -478,7 +478,7 @@ class FlowMaster(controller.Master):
                 "host": host,
                 "port": port}).start()
 
-    def add_event(self, e, level="error"):
+    def add_event(self, e, level="info"):
         """
             level: debug, info, error
         """
@@ -659,6 +659,10 @@ class FlowMaster(controller.Master):
             if block:
                 rt.join()
 
+    def handle_log(self, l):
+        self.add_event(l.msg, l.level)
+        l.reply()
+
     def handle_clientconnect(self, cc):
         self.run_script_hook("clientconnect", cc)
         cc.reply()
diff --git a/libmproxy/protocol/http.py b/libmproxy/protocol/http.py
index 08dece37..ded2362e 100644
--- a/libmproxy/protocol/http.py
+++ b/libmproxy/protocol/http.py
@@ -861,7 +861,7 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
                 return HTTPResponse.from_stream(self.c.server_conn.rfile, request.method,
                                                 body_size_limit=self.c.config.body_size_limit)
             except (tcp.NetLibDisconnect, http.HttpErrorConnClosed), v:
-                self.c.log("error in server communication: %s" % str(v))
+                self.c.log("error in server communication: %s" % str(v), level="debug")
                 if i < 1:
                     # In any case, we try to reconnect at least once.
                     # This is necessary because it might be possible that we already initiated an upstream connection
@@ -881,7 +881,7 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
         try:
             req = HTTPRequest.from_stream(self.c.client_conn.rfile,
                                           body_size_limit=self.c.config.body_size_limit)
-            self.c.log("request", [req._assemble_first_line(req.form_in)])
+            self.c.log("request", "debug", [req._assemble_first_line(req.form_in)])
             send_upstream = self.process_request(flow, req)
             if not send_upstream:
                 return True
@@ -906,7 +906,7 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
             flow.server_conn = self.c.server_conn  # no further manipulation of self.c.server_conn beyond this point
             # we can safely set it as the final attribute value here.
 
-            self.c.log("response", [flow.response._assemble_first_line()])
+            self.c.log("response", "debug", [flow.response._assemble_first_line()])
             response_reply = self.c.channel.ask("response", flow.response)
             if response_reply is None or response_reply == KILL:
                 return False
@@ -946,7 +946,7 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
         else:
             err = error.__class__
 
-        self.c.log("error: %s" % err)
+        self.c.log("error: %s" % err, level="info")
 
         if flow:
             flow.error = Error(err)
@@ -985,21 +985,23 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
         Hooking code isn't particulary beautiful, but it isolates this edge-case from
         the protocol-agnostic ConnectionHandler
         """
-        self.c.log("Hook reconnect function")
+        self.c.log("Hook reconnect function", level="debug")
         original_reconnect_func = self.c.server_reconnect
 
         def reconnect_http_proxy():
-            self.c.log("Hooked reconnect function")
-            self.c.log("Hook: Run original reconnect")
+            self.c.log("Hooked reconnect function", "debug")
+            self.c.log("Hook: Run original reconnect", "debug")
             original_reconnect_func(no_ssl=True)
-            self.c.log("Hook: Write CONNECT request to upstream proxy", [upstream_request._assemble_first_line()])
+            self.c.log("Hook: Write CONNECT request to upstream proxy", "debug",
+                       [upstream_request._assemble_first_line()])
             self.c.server_conn.send(upstream_request._assemble())
-            self.c.log("Hook: Read answer to CONNECT request from proxy")
+            self.c.log("Hook: Read answer to CONNECT request from proxy", "debug")
             resp = HTTPResponse.from_stream(self.c.server_conn.rfile, upstream_request.method)
             if resp.code != 200:
                 raise proxy.ProxyError(resp.code,
-                                 "Cannot reestablish SSL connection with upstream proxy: \r\n" + str(resp.headers))
-            self.c.log("Hook: Establish SSL with upstream proxy")
+                                       "Cannot reestablish SSL "
+                                       "connection with upstream proxy: \r\n" + str(resp.headers))
+            self.c.log("Hook: Establish SSL with upstream proxy", "debug")
             self.c.establish_ssl(server=True)
 
         self.c.server_reconnect = reconnect_http_proxy
@@ -1008,11 +1010,11 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
         """
         Upgrade the connection to SSL after an authority (CONNECT) request has been made.
         """
-        self.c.log("Received CONNECT request. Upgrading to SSL...")
+        self.c.log("Received CONNECT request. Upgrading to SSL...", "debug")
         self.expected_form_in = "relative"
         self.expected_form_out = "relative"
         self.c.establish_ssl(server=True, client=True)
-        self.c.log("Upgrade to SSL completed.")
+        self.c.log("Upgrade to SSL completed.", "debug")
 
     def process_request(self, flow, request):
 
diff --git a/libmproxy/protocol/primitives.py b/libmproxy/protocol/primitives.py
index dfe6371e..8c0ea5db 100644
--- a/libmproxy/protocol/primitives.py
+++ b/libmproxy/protocol/primitives.py
@@ -172,7 +172,7 @@ class TemporaryServerChangeMixin(object):
             self.c.server_conn.address.port,
             address.host,
             address.port
-        ))
+        ), "debug")
 
         if not hasattr(self, "_backup_server_conn"):
             self._backup_server_conn = self.c.server_conn
@@ -193,7 +193,7 @@ class TemporaryServerChangeMixin(object):
             self.c.server_conn.address.port,
             self._backup_server_conn.address.host,
             self._backup_server_conn.address.port
-        ))
+        ), "debug")
 
         self.c.del_server_connection()
         self.c.server_conn = self._backup_server_conn
diff --git a/libmproxy/protocol/tcp.py b/libmproxy/protocol/tcp.py
index 3a247858..6cdc6581 100644
--- a/libmproxy/protocol/tcp.py
+++ b/libmproxy/protocol/tcp.py
@@ -45,7 +45,7 @@ class TCPHandler(ProtocolHandler):
                 data = data.getvalue()
 
                 if data == "":  # no data received, rfile is closed
-                    self.c.log("Close writing connection to %s" % dst_str)
+                    self.c.log("Close writing connection to %s" % dst_str, "debug")
                     conns.remove(rfile)
                     if dst.ssl_established:
                         dst.connection.shutdown()
@@ -55,6 +55,6 @@ class TCPHandler(ProtocolHandler):
                         self.c.close = True
                     break
 
-                self.c.log("%s %s\r\n%s" % (direction, dst_str,data))
+                self.c.log("%s %s\r\n%s" % (direction, dst_str, data), "debug")
                 dst.wfile.write(data)
                 dst.wfile.flush()
diff --git a/libmproxy/proxy/primitives.py b/libmproxy/proxy/primitives.py
index f6a02e51..cbf5b2d8 100644
--- a/libmproxy/proxy/primitives.py
+++ b/libmproxy/proxy/primitives.py
@@ -67,5 +67,6 @@ class AddressPriority(object):
 
 
 class Log:
-    def __init__(self, msg):
-        self.msg = msg
\ No newline at end of file
+    def __init__(self, msg, level):
+        self.msg = msg
+        self.level = level
\ No newline at end of file
diff --git a/libmproxy/proxy/server.py b/libmproxy/proxy/server.py
index e308d081..2252f674 100644
--- a/libmproxy/proxy/server.py
+++ b/libmproxy/proxy/server.py
@@ -66,7 +66,7 @@ class ConnectionHandler:
         self.sni = None
 
     def handle(self):
-        self.log("clientconnect")
+        self.log("clientconnect", "info")
         self.channel.ask("clientconnect", self)
 
         self.determine_conntype()
@@ -86,7 +86,7 @@ class ConnectionHandler:
                     try:
                         handle_messages(self.conntype, self)
                     except ConnectionTypeChange:
-                        self.log("Connection Type Changed: %s" % self.conntype)
+                        self.log("Connection Type Changed: %s" % self.conntype, "info")
                         continue
 
             # FIXME: Do we want to persist errors?
@@ -94,14 +94,14 @@ class ConnectionHandler:
                 handle_error(self.conntype, self, e)
         except Exception, e:
             import traceback, sys
-            self.log(traceback.format_exc())
+            self.log(traceback.format_exc(), "error")
             print >> sys.stderr, traceback.format_exc()
             print >> sys.stderr, "mitmproxy has crashed!"
             print >> sys.stderr, "Please lodge a bug report at: https://github.com/mitmproxy/mitmproxy"
             raise e
 
         self.del_server_connection()
-        self.log("clientdisconnect")
+        self.log("clientdisconnect", "info")
         self.channel.tell("clientdisconnect", self)
 
     def del_server_connection(self):
@@ -110,7 +110,8 @@ class ConnectionHandler:
         """
         if self.server_conn and self.server_conn.connection:
             self.server_conn.finish()
-            self.log("serverdisconnect", ["%s:%s" % (self.server_conn.address.host, self.server_conn.address.port)])
+            self.log("serverdisconnect", "debug", ["%s:%s" % (self.server_conn.address.host,
+                                                              self.server_conn.address.port)])
             self.channel.tell("serverdisconnect", self)
         self.server_conn = None
         self.sni = None
@@ -129,7 +130,7 @@ class ConnectionHandler:
         if self.server_conn:
             if self.server_conn.priority > priority:
                 self.log("Attempt to change server address, "
-                         "but priority is too low (is: %s, got: %s)" % (self.server_conn.priority, priority))
+                         "but priority is too low (is: %s, got: %s)" % (self.server_conn.priority, priority), "info")
                 return
             if self.server_conn.address == address:
                 self.server_conn.priority = priority  # Possibly increase priority
@@ -137,7 +138,7 @@ class ConnectionHandler:
 
             self.del_server_connection()
 
-        self.log("Set new server address: %s:%s" % (address.host, address.port))
+        self.log("Set new server address: %s:%s" % (address.host, address.port), "debug")
         self.server_conn = ServerConnection(address, priority)
 
     def establish_server_connection(self):
@@ -147,7 +148,7 @@ class ConnectionHandler:
         """
         if self.server_conn.connection:
             return
-        self.log("serverconnect", ["%s:%s" % self.server_conn.address()[:2]])
+        self.log("serverconnect", "debug", ["%s:%s" % self.server_conn.address()[:2]])
         self.channel.tell("serverconnect", self)
         try:
             self.server_conn.connect()
@@ -176,7 +177,7 @@ class ConnectionHandler:
                 subs.append("with client")
             if server:
                 subs.append("with server (sni: %s)" % self.sni)
-            self.log("Establish SSL", subs)
+            self.log("Establish SSL", "debug", subs)
 
         if server:
             if self.server_conn.ssl_established:
@@ -199,7 +200,7 @@ class ConnectionHandler:
         had_ssl = self.server_conn.ssl_established
         priority = self.server_conn.priority
         sni = self.sni
-        self.log("(server reconnect follows)")
+        self.log("(server reconnect follows)", "debug")
         self.del_server_connection()
         self.set_server_address(address, priority)
         self.establish_server_connection()
@@ -210,14 +211,14 @@ class ConnectionHandler:
     def finish(self):
         self.client_conn.finish()
 
-    def log(self, msg, subs=()):
+    def log(self, msg, level, subs=()):
         msg = [
             "%s:%s: %s" % (self.client_conn.address.host, self.client_conn.address.port, msg)
         ]
         for i in subs:
             msg.append("  -> " + i)
         msg = "\n".join(msg)
-        self.channel.tell("log", Log(msg))
+        self.channel.tell("log", Log(msg, level))
 
     def find_cert(self):
         if self.config.certforward and self.server_conn.ssl_established:
@@ -246,15 +247,17 @@ class ConnectionHandler:
             sn = connection.get_servername()
             if sn and sn != self.sni:
                 self.sni = sn.decode("utf8").encode("idna")
-                self.log("SNI received: %s" % self.sni)
+                self.log("SNI received: %s" % self.sni, "debug")
                 self.server_reconnect()  # reconnect to upstream server with SNI
                 # Now, change client context to reflect changed certificate:
                 new_context = SSL.Context(SSL.TLSv1_METHOD)
                 cert, key = self.find_cert()
-                new_context.use_privatekey_file(key)
-                new_context.use_certificate(cert.X509)
+                new_context.use_privatekey(key)
+                new_context.use_certificate(cert.x509)
                 connection.set_context(new_context)
         # An unhandled exception in this method will core dump PyOpenSSL, so
         # make dang sure it doesn't happen.
         except Exception, e:  # pragma: no cover
+            import traceback
+            self.log("Error in handle_sni:\r\n" + traceback.format_exc(), "error")
             pass
diff --git a/libmproxy/script.py b/libmproxy/script.py
index bafa8ba9..b17766e8 100644
--- a/libmproxy/script.py
+++ b/libmproxy/script.py
@@ -10,16 +10,15 @@ class ScriptContext:
     def __init__(self, master):
         self._master = master
 
-    def log(self, *args, **kwargs):
+    def log(self, message, level="info"):
         """
             Logs an event.
 
-            How this is handled depends on the front-end. mitmdump will display
-            events if the v flag ("-e") was passed. mitmproxy sends
-            output to the eventlog for display ("e" keyboard shortcut).
+            By default, only events with level "error" get displayed. This can be controlled with the "-v" switch.
+            How log messages are handled depends on the front-end. mitmdump will print them to stdout,
+            mitmproxy sends output to the eventlog for display ("e" keyboard shortcut).
         """
-        #FIXME refactor_loglevel
-        self._master.add_event(*args, **kwargs)
+        self._master.add_event(message, level)
 
     def duplicate_flow(self, f):
         """