Ditch the addon stdout wrapper

This results in a 30% improvement in our core request throughput.

Fixes #3102

examples/complex/nonblocking.py

@@ -1,11 +1,12 @@
 import time
 
 from mitmproxy.script import concurrent
+from mitmproxy import ctx
 
 
 @concurrent  # Remove this and see what happens
 def request(flow):
     # You don't want to use mitmproxy.ctx from a different thread
-    print("handle request: %s%s" % (flow.request.host, flow.request.path))
+    ctx.log.info("handle request: %s%s" % (flow.request.host, flow.request.path))
     time.sleep(5)
-    print("start  request: %s%s" % (flow.request.host, flow.request.path))
+    ctx.log.info("start  request: %s%s" % (flow.request.host, flow.request.path))

examples/complex/tcp_message.py

@@ -9,6 +9,7 @@ example cmdline invocation:
 mitmdump -T --host --tcp ".*" -q -s examples/tcp_message.py
 """
 from mitmproxy.utils import strutils
+from mitmproxy import ctx
 
 
 def tcp_message(tcp_msg):
@@ -17,7 +18,7 @@ def tcp_message(tcp_msg):
     is_modified = False if modified_msg == tcp_msg.message else True
     tcp_msg.message = modified_msg
 
-    print(
+    ctx.log.info(
         "[tcp_message{}] from {} {} to {} {}:\r\n{}".format(
             " (modified)" if is_modified else "",
             "client" if tcp_msg.sender == tcp_msg.client_conn else "server",

examples/simple/filter_flows.py

@@ -19,8 +19,8 @@ class Filter:
 
     def response(self, flow: http.HTTPFlow) -> None:
         if flowfilter.match(self.filter, flow):
-            print("Flow matches filter:")
-            print(flow)
+            ctx.log.info("Flow matches filter:")
+            ctx.log.info(flow)
 
 
 addons = [Filter()]

examples/simple/log_events.py

@@ -1,10 +1,7 @@
-"""
-It is recommended to use `ctx.log` for logging within a script.
-print() statements are equivalent to ctx.log.warn().
-"""
 from mitmproxy import ctx
 
 
 def load(l):
     ctx.log.info("This is some informative text.")
+    ctx.log.warn("This is a warning.")
     ctx.log.error("This is an error.")

mitmproxy/addonmanager.py

@@ -36,25 +36,10 @@ def cut_traceback(tb, func_name):
     return tb or tb_orig
 
 
-class StreamLog:
-    def __init__(self, lg):
-        self.log = lg
-
-    def write(self, buf):
-        if buf.strip():
-            self.log(buf)
-
-    def flush(self):  # pragma: no cover
-        # Click uses flush sometimes, so we dummy it up
-        pass
-
-
 @contextlib.contextmanager
 def safecall():
-    stdout_replacement = StreamLog(lambda message: ctx.log.warn(message))
     try:
-        with contextlib.redirect_stdout(stdout_replacement):
-            yield
+        yield
     except (exceptions.AddonHalt, exceptions.OptionsError):
         raise
     except Exception as e:

test/mitmproxy/addons/test_script.py

@@ -60,17 +60,6 @@ def test_load_fullname(tdata):
     assert not hasattr(ns2, "addons")
 
 
-@pytest.mark.asyncio
-async def test_script_print_stdout(tdata):
-    with taddons.context() as tctx:
-        with addonmanager.safecall():
-            ns = script.load_script(
-                tdata.path("mitmproxy/data/addonscripts/print.py")
-            )
-            ns.load(addonmanager.Loader(tctx.master))
-        assert await tctx.master.await_log("stdoutprint")
-
-
 class TestScript:
     def test_notfound(self):
         with taddons.context():

test/mitmproxy/data/addonscripts/print.py

@@ -1,2 +0,0 @@
-def load(l):
-    print("stdoutprint")

test/mitmproxy/test_addonmanager.py

@@ -196,10 +196,3 @@ class D:
 
     def log(self, x):
         self.w = x
-
-
-def test_streamlog():
-    dummy = D()
-    s = addonmanager.StreamLog(dummy.log)
-    s.write("foo")
-    assert dummy.w == "foo"