Merge pull request #1362 from cortesi/errors

Some work on errors and logs

mitmproxy/builtins/script.py

@@ -131,6 +131,7 @@ class Script:
             self.should_reload.clear()
             ctx.log.info("Reloading script: %s" % self.name)
             self.ns = load_script(self.path, self.args)
+            self.start()
             self.configure(self.last_options)
         else:
             self.run("tick")

mitmproxy/cmdline.py

@@ -284,8 +284,8 @@ def basic_options(parser):
     )
     parser.add_argument(
         "-v", "--verbose",
-        action="store_const", dest="verbose", default=1, const=2,
+        action="store_const", dest="verbose", default=2, const=3,
-        help="Increase event log verbosity."
+        help="Increase log verbosity."
     )
     outfile = parser.add_mutually_exclusive_group()
     outfile.add_argument(
@@ -384,7 +384,7 @@ def proxy_options(parser):
         help="""
             Generic TCP SSL proxy mode for all hosts that match the pattern.
             Similar to --ignore, but SSL connections are intercepted. The
-            communication contents are printed to the event log in verbose mode.
+            communication contents are printed to the log in verbose mode.
         """
     )
     group.add_argument(

mitmproxy/console/flowlist.py

@@ -44,11 +44,11 @@ footer = [
 ]
 
 
-class EventListBox(urwid.ListBox):
+class LogBufferBox(urwid.ListBox):
 
     def __init__(self, master):
         self.master = master
-        urwid.ListBox.__init__(self, master.eventlist)
+        urwid.ListBox.__init__(self, master.logbuffer)
 
     def keypress(self, size, key):
         key = common.shortcuts(key)
@@ -56,7 +56,7 @@ class EventListBox(urwid.ListBox):
             self.master.clear_events()
             key = None
         elif key == "G":
-            self.set_focus(len(self.master.eventlist) - 1)
+            self.set_focus(len(self.master.logbuffer) - 1)
         elif key == "g":
             self.set_focus(0)
         return urwid.ListBox.keypress(self, size, key)
@@ -76,7 +76,7 @@ class BodyPile(urwid.Pile):
             [
                 FlowListBox(master),
                 urwid.Frame(
-                    EventListBox(master),
+                    LogBufferBox(master),
                     header = self.inactive_header
                 )
             ]

mitmproxy/console/flowview.py

@@ -208,7 +208,7 @@ class FlowView(tabs.Tabs):
             )
         except exceptions.ContentViewException:
             s = "Content viewer failed: \n" + traceback.format_exc()
-            signals.add_event(s, "error")
+            signals.add_log(s, "error")
             description, lines = contentviews.get_content_view(
                 contentviews.get("Raw"), message.content, headers=message.headers
             )

mitmproxy/console/master.py

@@ -22,6 +22,7 @@ from mitmproxy import controller
 from mitmproxy import exceptions
 from mitmproxy import flow
 from mitmproxy import script
+from mitmproxy import utils
 from mitmproxy.console import flowlist
 from mitmproxy.console import flowview
 from mitmproxy.console import grideditor
@@ -204,8 +205,6 @@ class ConsoleMaster(flow.FlowMaster):
 
     def __init__(self, server, options):
         flow.FlowMaster.__init__(self, options, server, ConsoleState())
-        self.addons.add(*builtins.default_addons())
-
         self.stream_path = None
         # This line is just for type hinting
         self.options = self.options  # type: Options
@@ -238,8 +237,7 @@ class ConsoleMaster(flow.FlowMaster):
         self.palette = options.palette
         self.palette_transparent = options.palette_transparent
 
-        self.eventlog = options.eventlog
+        self.logbuffer = urwid.SimpleListWalker([])
-        self.eventlist = urwid.SimpleListWalker([])
         self.follow = options.follow
 
         if options.client_replay:
@@ -252,10 +250,12 @@ class ConsoleMaster(flow.FlowMaster):
 
         if options.app:
             self.start_app(self.options.app_host, self.options.app_port)
+
         signals.call_in.connect(self.sig_call_in)
         signals.pop_view_state.connect(self.sig_pop_view_state)
         signals.push_view_state.connect(self.sig_push_view_state)
-        signals.sig_add_event.connect(self.sig_add_event)
+        signals.sig_add_log.connect(self.sig_add_log)
+        self.addons.add(*builtins.default_addons())
 
     def __setattr__(self, name, value):
         self.__dict__[name] = value
@@ -271,22 +271,24 @@ class ConsoleMaster(flow.FlowMaster):
         # We default to using the reloader in the console ui.
         return super(ConsoleMaster, self).load_script(command, use_reloader)
 
-    def sig_add_event(self, sender, e, level):
+    def sig_add_log(self, sender, e, level):
-        needed = dict(error=0, info=1, debug=2).get(level, 1)
+        if self.options.verbosity < utils.log_tier(level):
-        if self.options.verbosity < needed:
             return
 
         if level == "error":
+            signals.status_message.send(
+                message = "Error: %s" % str(e)
+            )
             e = urwid.Text(("error", str(e)))
         else:
             e = urwid.Text(str(e))
-        self.eventlist.append(e)
+        self.logbuffer.append(e)
-        if len(self.eventlist) > EVENTLOG_SIZE:
+        if len(self.logbuffer) > EVENTLOG_SIZE:
-            self.eventlist.pop(0)
+            self.logbuffer.pop(0)
-        self.eventlist.set_focus(len(self.eventlist) - 1)
+        self.logbuffer.set_focus(len(self.logbuffer) - 1)
 
-    def add_event(self, e, level):
+    def add_log(self, e, level):
-        signals.add_event(e, level)
+        signals.add_log(e, level)
 
     def sig_call_in(self, sender, seconds, callback, args=()):
         def cb(*_):
@@ -317,16 +319,16 @@ class ConsoleMaster(flow.FlowMaster):
         status, val = s.run(method, f)
         if val:
             if status:
-                signals.add_event("Method %s return: %s" % (method, val), "debug")
+                signals.add_log("Method %s return: %s" % (method, val), "debug")
             else:
-                signals.add_event(
+                signals.add_log(
                     "Method %s error: %s" %
                     (method, val[1]), "error")
 
     def run_script_once(self, command, f):
         if not command:
             return
-        signals.add_event("Running script on flow: %s" % command, "debug")
+        signals.add_log("Running script on flow: %s" % command, "debug")
 
         try:
             s = script.Script(command)
@@ -335,7 +337,7 @@ class ConsoleMaster(flow.FlowMaster):
             signals.status_message.send(
                 message='Error loading "{}".'.format(command)
             )
-            signals.add_event('Error loading "{}":\n{}'.format(command, e), "error")
+            signals.add_log('Error loading "{}":\n{}'.format(command, e), "error")
             return
 
         if f.request:
@@ -348,7 +350,7 @@ class ConsoleMaster(flow.FlowMaster):
         signals.flow_change.send(self, flow = f)
 
     def toggle_eventlog(self):
-        self.eventlog = not self.eventlog
+        self.options.eventlog = not self.options.eventlog
         signals.pop_view_state.send(self)
         self.view_flowlist()
 
@@ -475,7 +477,7 @@ class ConsoleMaster(flow.FlowMaster):
         if self.options.rfile:
             ret = self.load_flows_path(self.options.rfile)
             if ret and self.state.flow_count():
-                signals.add_event(
+                signals.add_log(
                     "File truncated or corrupted. "
                     "Loaded as many flows as possible.",
                     "error"
@@ -578,7 +580,7 @@ class ConsoleMaster(flow.FlowMaster):
         if self.state.follow_focus:
             self.state.set_focus(self.state.flow_count())
 
-        if self.eventlog:
+        if self.options.eventlog:
             body = flowlist.BodyPile(self)
         else:
             body = flowlist.FlowListBox(self)
@@ -723,7 +725,7 @@ class ConsoleMaster(flow.FlowMaster):
         signals.flow_change.send(self, flow = f)
 
     def clear_events(self):
-        self.eventlist[:] = []
+        self.logbuffer[:] = []
 
     # Handlers
     @controller.handler
@@ -752,12 +754,12 @@ class ConsoleMaster(flow.FlowMaster):
         super(ConsoleMaster, self).tcp_message(f)
         message = f.messages[-1]
         direction = "->" if message.from_client else "<-"
-        self.add_event("{client} {direction} tcp {direction} {server}".format(
+        self.add_log("{client} {direction} tcp {direction} {server}".format(
             client=repr(f.client_conn.address),
             server=repr(f.server_conn.address),
             direction=direction,
         ), "info")
-        self.add_event(strutils.bytes_to_escaped_str(message.content), "debug")
+        self.add_log(strutils.bytes_to_escaped_str(message.content), "debug")
 
     @controller.handler
     def script_change(self, script):

mitmproxy/console/palettes.py

@@ -24,7 +24,7 @@ class Palette:
         # List and Connections
         'method', 'focus',
         'code_200', 'code_300', 'code_400', 'code_500', 'code_other',
-        'error',
+        'error', "warn",
         'header', 'highlight', 'intercept', 'replay', 'mark',
 
         # Hex view
@@ -100,6 +100,7 @@ class LowDark(Palette):
         code_500 = ('light red', 'default'),
         code_other = ('dark red', 'default'),
 
+        warn = ('brown', 'default'),
         error = ('light red', 'default'),
 
         header = ('dark cyan', 'default'),
@@ -166,6 +167,7 @@ class LowLight(Palette):
         code_other = ('light red', 'default'),
 
         error = ('light red', 'default'),
+        warn = ('brown', 'default'),
 
         header = ('dark blue', 'default'),
         highlight = ('black,bold', 'default'),
@@ -250,6 +252,7 @@ class SolarizedLight(LowLight):
         code_other = (sol_magenta, 'default'),
 
         error = (sol_red, 'default'),
+        warn = (sol_orange, 'default'),
 
         header = (sol_blue, 'default'),
         highlight = (sol_base01, 'default'),
@@ -299,6 +302,7 @@ class SolarizedDark(LowDark):
         code_other = (sol_magenta, 'default'),
 
         error = (sol_red, 'default'),
+        warn = (sol_orange, 'default'),
 
         header = (sol_blue, 'default'),
         highlight = (sol_base01, 'default'),

mitmproxy/console/signals.py

@@ -3,11 +3,11 @@ from __future__ import absolute_import, print_function, division
 import blinker
 
 # Show a status message in the action bar
-sig_add_event = blinker.Signal()
+sig_add_log = blinker.Signal()
 
 
-def add_event(e, level):
+def add_log(e, level):
-    sig_add_event.send(
+    sig_add_log.send(
         None,
         e=e,
         level=level

mitmproxy/controller.py

@@ -47,7 +47,7 @@ class Log(object):
         self.master = master
 
     def __call__(self, text, level="info"):
-        self.master.add_event(text, level)
+        self.master.add_log(text, level)
 
     def debug(self, txt):
         self(txt, "debug")
@@ -89,6 +89,11 @@ class Master(object):
             mitmproxy_ctx.master = None
             mitmproxy_ctx.log = None
 
+    def add_log(self, e, level="info"):
+        """
+            level: debug, info, warn, error
+        """
+
     def add_server(self, server):
         # We give a Channel to the server which can be used to communicate with the master
         channel = Channel(self.event_queue, self.should_exit)

mitmproxy/dump.py

@@ -15,6 +15,7 @@ from mitmproxy import exceptions
 from mitmproxy import filt
 from mitmproxy import flow
 from mitmproxy import builtins
+from mitmproxy import utils
 from netlib import human
 from netlib import tcp
 from netlib import strutils
@@ -44,6 +45,7 @@ class DumpMaster(flow.FlowMaster):
 
     def __init__(self, server, options):
         flow.FlowMaster.__init__(self, options, server, flow.State())
+        self.has_errored = False
         self.addons.add(*builtins.default_addons())
         # This line is just for type hinting
         self.options = self.options  # type: Options
@@ -97,7 +99,7 @@ class DumpMaster(flow.FlowMaster):
             try:
                 self.load_flows_file(options.rfile)
             except exceptions.FlowReadException as v:
-                self.add_event("Flow file corrupted.", "error")
+                self.add_log("Flow file corrupted.", "error")
                 raise DumpError(v)
 
         if self.options.app:
@@ -113,9 +115,10 @@ class DumpMaster(flow.FlowMaster):
         except exceptions.FlowReadException as e:
             raise DumpError(str(e))
 
-    def add_event(self, e, level="info"):
+    def add_log(self, e, level="info"):
-        needed = dict(error=0, info=1, debug=2).get(level, 1)
+        if level == "error":
-        if self.options.verbosity >= needed:
+            self.has_errored = True
+        if self.options.verbosity >= utils.log_tier(level):
             self.echo(
                 e,
                 fg="red" if level == "error" else None,
@@ -157,7 +160,7 @@ class DumpMaster(flow.FlowMaster):
                     )
                 except exceptions.ContentViewException:
                     s = "Content viewer failed: \n" + traceback.format_exc()
-                    self.add_event(s, "debug")
+                    self.add_log(s, "debug")
                     type, lines = contentviews.get_content_view(
                         contentviews.get("Raw"),
                         message.content,

mitmproxy/flow/master.py

@@ -52,11 +52,6 @@ class FlowMaster(controller.Master):
             port
         )
 
-    def add_event(self, e, level="info"):
-        """
-            level: debug, info, error
-        """
-
     def get_ignore_filter(self):
         return self.server.config.check_ignore.patterns
 
@@ -287,7 +282,7 @@ class FlowMaster(controller.Master):
 
     @controller.handler
     def log(self, l):
-        self.add_event(l.msg, l.level)
+        self.add_log(l.msg, l.level)
 
     @controller.handler
     def clientconnect(self, root_layer):
@@ -327,7 +322,7 @@ class FlowMaster(controller.Master):
                     **{"mitmproxy.master": self}
                 )
                 if err:
-                    self.add_event("Error in wsgi app. %s" % err, "error")
+                    self.add_log("Error in wsgi app. %s" % err, "error")
                 f.reply.kill()
                 return
         if f not in self.state.flows:  # don't add again on replay
@@ -382,7 +377,7 @@ class FlowMaster(controller.Master):
 
     @controller.handler
     def tcp_error(self, flow):
-        self.add_event("Error in TCP connection to {}: {}".format(
+        self.add_log("Error in TCP connection to {}: {}".format(
             repr(flow.server_conn.address),
             flow.error
         ), "info")

mitmproxy/flow/options.py

@@ -30,7 +30,7 @@ class Options(options.Options):
             stickycookie=None,  # type: Optional[str]
             stickyauth=None,  # type: Optional[str]
             stream_large_bodies=None,  # type: Optional[str]
-            verbosity=1,  # type: int
+            verbosity=2,  # type: int
             outfile=None,  # type: Tuple[str, str]
             replay_ignore_content=False,  # type: bool
             replay_ignore_params=(),  # type: Sequence[str]

mitmproxy/main.py

@@ -118,6 +118,9 @@ def mitmdump(args=None):  # pragma: no cover
         sys.exit(1)
     except (KeyboardInterrupt, _thread.error):
         pass
+    if master.has_errored:
+        print("mitmdump: errors occurred during run", file=sys.stderr)
+        sys.exit(1)
 
 
 def mitmweb(args=None):  # pragma: no cover

mitmproxy/utils.py

@@ -36,3 +36,7 @@ class LRUCache:
                 d = self.cacheList.pop()
                 self.cache.pop(d)
             return ret
+
+
+def log_tier(level):
+    return dict(error=0, warn=1, info=2, debug=3).get(level)

mitmproxy/web/master.py

@@ -67,7 +67,7 @@ class WebState(flow.State):
         self._last_event_id = 0
         self.events = collections.deque(maxlen=1000)
 
-    def add_event(self, e, level):
+    def add_log(self, e, level):
         self._last_event_id += 1
         entry = {
             "id": self._last_event_id,
@@ -145,7 +145,7 @@ class WebMaster(flow.FlowMaster):
             try:
                 self.load_flows_file(options.rfile)
             except exceptions.FlowReadException as v:
-                self.add_event(
+                self.add_log(
                     "Could not read flow file: %s" % v,
                     "error"
                 )
@@ -200,6 +200,6 @@ class WebMaster(flow.FlowMaster):
         super(WebMaster, self).error(f)
         return self._process_flow(f)
 
-    def add_event(self, e, level="info"):
+    def add_log(self, e, level="info"):
-        super(WebMaster, self).add_event(e, level)
+        super(WebMaster, self).add_log(e, level)
-        return self.state.add_event(e, level)
+        return self.state.add_log(e, level)

test/mitmproxy/mastertest.py

@@ -47,5 +47,5 @@ class RecordingMaster(master.FlowMaster):
         master.FlowMaster.__init__(self, *args, **kwargs)
         self.event_log = []
 
-    def add_event(self, e, level):
+    def add_log(self, e, level):
         self.event_log.append((level, e))

test/mitmproxy/test_dump.py

@@ -235,7 +235,8 @@ class TestDumpMaster(mastertest.MasterTest):
         ret = self.dummy_cycle(
             self.mkmaster(
                 None,
-                scripts=[tutils.test_data.path("data/scripts/all.py")], verbosity=1
+                scripts=[tutils.test_data.path("data/scripts/all.py")],
+                verbosity=2
             ),
             1, b"",
         )

test/mitmproxy/test_examples.py

@@ -21,7 +21,7 @@ class ScriptError(Exception):
 
 
 class RaiseMaster(master.FlowMaster):
-    def add_event(self, e, level):
+    def add_log(self, e, level):
         if level in ("warn", "error"):
             raise ScriptError(e)
 

test/mitmproxy/tservers.py

@@ -42,7 +42,7 @@ class TestMaster(flow.FlowMaster):
     def clear_log(self):
         self.tlog = []
 
-    def add_event(self, message, level=None):
+    def add_log(self, message, level=None):
         self.tlog.append(message)