From af1a4ffdcd4c98afefd4228bbc2bc276cfd8436f Mon Sep 17 00:00:00 2001 From: Aldo Cortesi Date: Tue, 8 May 2018 11:23:52 +1200 Subject: [PATCH] Ditch the addon stdout wrapper This results in a 30% improvement in our core request throughput. Fixes #3102 --- examples/complex/nonblocking.py | 5 +++-- examples/complex/tcp_message.py | 3 ++- examples/simple/filter_flows.py | 4 ++-- examples/simple/log_events.py | 5 +---- mitmproxy/addonmanager.py | 17 +---------------- test/mitmproxy/addons/test_script.py | 11 ----------- test/mitmproxy/data/addonscripts/print.py | 2 -- test/mitmproxy/test_addonmanager.py | 7 ------- 8 files changed, 9 insertions(+), 45 deletions(-) delete mode 100644 test/mitmproxy/data/addonscripts/print.py diff --git a/examples/complex/nonblocking.py b/examples/complex/nonblocking.py index 264a1fdbb..72c9c0abf 100644 --- a/examples/complex/nonblocking.py +++ b/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)) diff --git a/examples/complex/tcp_message.py b/examples/complex/tcp_message.py index d7c9c42e5..634e2a9f1 100644 --- a/examples/complex/tcp_message.py +++ b/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", diff --git a/examples/simple/filter_flows.py b/examples/simple/filter_flows.py index d252089cc..aba240de2 100644 --- a/examples/simple/filter_flows.py +++ b/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()] diff --git a/examples/simple/log_events.py b/examples/simple/log_events.py index b9aa2c1f0..4f70e340d 100644 --- a/examples/simple/log_events.py +++ b/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.") diff --git a/mitmproxy/addonmanager.py b/mitmproxy/addonmanager.py index 64c957ba2..0b5592939 100644 --- a/mitmproxy/addonmanager.py +++ b/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: diff --git a/test/mitmproxy/addons/test_script.py b/test/mitmproxy/addons/test_script.py index 627628095..573b36e76 100644 --- a/test/mitmproxy/addons/test_script.py +++ b/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(): diff --git a/test/mitmproxy/data/addonscripts/print.py b/test/mitmproxy/data/addonscripts/print.py deleted file mode 100644 index 93b65a64d..000000000 --- a/test/mitmproxy/data/addonscripts/print.py +++ /dev/null @@ -1,2 +0,0 @@ -def load(l): - print("stdoutprint") diff --git a/test/mitmproxy/test_addonmanager.py b/test/mitmproxy/test_addonmanager.py index a1f0a9436..660db549d 100644 --- a/test/mitmproxy/test_addonmanager.py +++ b/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"