don't remove add_log but deprecate it.

This commit is contained in:
Maximilian Hils 2022-09-18 12:44:18 +02:00
parent c69239bb90
commit dc8ff24685
17 changed files with 104 additions and 54 deletions

View File

@ -31,9 +31,9 @@
([#5507](https://github.com/mitmproxy/mitmproxy/pull/5507), @LIU-shuyi)
* Add HTTP/3 binary frame content view.
([#5582](https://github.com/mitmproxy/mitmproxy/pull/5582), @mhils)
* Remove `add_log` event hook. Users should use the builtin `logging` module instead.
* Deprecate `add_log` event hook. Users should use the builtin `logging` module instead.
([#5590](https://github.com/mitmproxy/mitmproxy/pull/5590), @mhils)
* Deprecated `mitmproxy.ctx.log` in favor of Python's builtin `logging` module.
* Deprecate `mitmproxy.ctx.log` in favor of Python's builtin `logging` module.
([#5590](https://github.com/mitmproxy/mitmproxy/pull/5590), @mhils)
## 28 June 2022: mitmproxy 8.1.1

View File

@ -13,7 +13,7 @@ known = set()
def category(name: str, desc: str, hooks: list[type[hooks.Hook]]) -> None:
all_params = [
list(inspect.signature(hook.__init__).parameters.values())[1:] for hook in hooks
list(inspect.signature(hook.__init__, eval_str=True).parameters.values())[1:] for hook in hooks
]
# slightly overengineered, but this was fun to write. ¯\_(ツ)_/¯

View File

@ -28,7 +28,7 @@ logging.info("hello world")
```
Accordingly, the `add_log` event has been removed. Developers who rely on log entries need to register their own
Accordingly, the `add_log` event has been deprecated. Developers who rely on log entries should register their own
`logging.Handler` instead. An example for this can be found in the `EventStore` addon.
## mitmproxy 7.0

View File

@ -163,23 +163,18 @@ class AddonManager:
"""
api_changes = {
# mitmproxy 6 -> mitmproxy 7
"clientconnect": "client_connected",
"clientdisconnect": "client_disconnected",
"serverconnect": "server_connect and server_connected",
"serverdisconnect": "server_disconnected",
"clientconnect": f"The clientconnect event has been removed, use client_connected instead",
"clientdisconnect": f"The clientdisconnect event has been removed, use client_disconnected instead",
"serverconnect": "The serverconnect event has been removed, use server_connect and server_connected instead",
"serverdisconnect": f"The serverdisconnect event has been removed, use server_disconnected instead",
# mitmproxy 8 -> mitmproxy 9
"add_log": None,
"add_log": "The add_log event has been deprecated, use Python's builtin logging module instead",
}
for a in traverse([addon]):
for old, new in api_changes.items():
for old, msg in api_changes.items():
if hasattr(a, old):
if new:
msg = f"The {old} event has been removed, use {new} instead. "
else:
msg = f"The {old} event has been removed. "
logger.warning(
f"{msg}"
f"For more details, see https://docs.mitmproxy.org/dev/addons-api-changelog/."
f"{msg}. For more details, see https://docs.mitmproxy.org/dev/addons-api-changelog/."
)
name = _get_name(a)
if name in self.lookup:

View File

@ -38,15 +38,6 @@ class EventStore:
self.sig_refresh.send()
LOGGING_LEVELS_TO_LOGENTRY = {
logging.ERROR: "error",
logging.WARNING: "warn",
logging.INFO: "info",
log.ALERT: "alert",
logging.DEBUG: "debug",
}
class CallbackLogger(log.MitmLogHandler):
def __init__(
self,
@ -60,6 +51,6 @@ class CallbackLogger(log.MitmLogHandler):
def emit(self, record: logging.LogRecord) -> None:
entry = LogEntry(
msg=self.format(record),
level=LOGGING_LEVELS_TO_LOGENTRY.get(record.levelno, "error"),
level=log.LOGGING_LEVELS_TO_LOGENTRY.get(record.levelno, "error"),
)
self.event_loop.call_soon_threadsafe(self.callback, entry)

View File

@ -1,3 +1,4 @@
from __future__ import annotations
import asyncio
import logging
from typing import IO

View File

@ -1,7 +1,10 @@
from __future__ import annotations
import logging
import os
import warnings
from dataclasses import dataclass
from mitmproxy import hooks, master
from mitmproxy.contrib import click as miniclick
from mitmproxy.utils import human
@ -180,6 +183,50 @@ class Log:
logging.getLogger().log(level=logging.getLevelName(level.upper()), msg=text)
LOGGING_LEVELS_TO_LOGENTRY = {
logging.ERROR: "error",
logging.WARNING: "warn",
logging.INFO: "info",
ALERT: "alert",
logging.DEBUG: "debug",
}
class LegacyLogEvents(MitmLogHandler):
"""Emit deprecated `add_log` events from stdlib logging."""
def __init__(
self,
master: master.Master,
):
super().__init__()
self.master = master
self.formatter = MitmFormatter(colorize=False)
def emit(self, record: logging.LogRecord) -> None:
entry = LogEntry(
msg=self.format(record),
level=LOGGING_LEVELS_TO_LOGENTRY.get(record.levelno, "error"),
)
self.master.event_loop.call_soon_threadsafe(
self.master.addons.trigger,
AddLogHook(entry),
)
@dataclass
class AddLogHook(hooks.Hook):
"""
**Deprecated:** Starting with mitmproxy 9, users should use the standard Python logging module instead, for example
by calling `logging.getLogger().addHandler()`.
Called whenever a new log entry is created through the mitmproxy
context. Be careful not to log from this event, which will cause an
infinite loop!
"""
entry: LogEntry
def log_tier(level):
"""
Comparison method for "old" LogEntry log tiers.

View File

@ -26,7 +26,10 @@ class Master:
self.options: options.Options = opts or options.Options()
self.commands = command.CommandManager(self)
self.addons = addonmanager.AddonManager(self)
self.log = log.Log(self)
self.log = log.Log(self) # deprecated, do not use.
self._legacy_log_events = log.LegacyLogEvents(self)
self._legacy_log_events.install()
# We expect an active event loop here already because some addons
# may want to spawn tasks during the initial configuration phase,
@ -34,10 +37,10 @@ class Master:
self.event_loop = event_loop or asyncio.get_running_loop()
try:
self.should_exit = asyncio.Event()
except RuntimeError:
except RuntimeError: # python 3.9 and below
self.should_exit = asyncio.Event(loop=self.event_loop)
mitmproxy_ctx.master = self
mitmproxy_ctx.log = self.log
mitmproxy_ctx.log = self.log # deprecated, do not use.
mitmproxy_ctx.options = self.options
async def run(self) -> None:
@ -74,6 +77,7 @@ class Master:
async def done(self) -> None:
await self.addons.trigger_event(hooks.DoneHook())
self._legacy_log_events.uninstall()
def _asyncio_exception_handler(self, loop, context):
try:

View File

@ -52,6 +52,7 @@ def run(
async def main() -> T:
logging.getLogger().setLevel(logging.DEBUG)
logging.getLogger("tornado").setLevel(logging.WARNING)
logging.getLogger("asyncio").setLevel(logging.WARNING)
debug.register_info_dumpers()
opts = options.Options()

View File

@ -1,3 +1,4 @@
from __future__ import annotations
import asyncio
import os
import socket
@ -35,6 +36,9 @@ class AsyncLogCaptureFixture:
def __init__(self, caplog: pytest.LogCaptureFixture):
self.caplog = caplog
def set_level(self, level: int | str, logger: str | None = None) -> None:
self.caplog.set_level(level, logger)
async def await_log(self, text, timeout=2):
await asyncio.sleep(0)
for i in range(int(timeout / 0.01)):
@ -44,6 +48,9 @@ class AsyncLogCaptureFixture:
await asyncio.sleep(0.01)
raise AssertionError(f"Did not find {text!r} in log:\n{self.caplog.text}.")
def clear(self) -> None:
self.caplog.clear()
@pytest.fixture
def caplog_async(caplog):

View File

@ -48,7 +48,7 @@ async def tcp_server(handle_conn) -> Address:
async def test_start_stop(caplog_async):
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
async def server_handler(
reader: asyncio.StreamReader, writer: asyncio.StreamWriter
@ -218,7 +218,7 @@ async def test_startup_err(monkeypatch, caplog) -> None:
async def test_shutdown_err(caplog_async) -> None:
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
async def _raise(*_):
raise OSError("cannot close")
@ -248,7 +248,7 @@ class DummyResolver:
async def test_dns(caplog_async) -> None:
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
ps = Proxyserver()
with taddons.context(ps, DummyResolver()) as tctx:
tctx.configure(
@ -313,7 +313,7 @@ async def udp_server(handle_conn) -> Address:
async def test_dtls(monkeypatch, caplog_async) -> None:
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
def server_handler(
transport: asyncio.DatagramTransport,

View File

@ -73,7 +73,7 @@ class TestReadFile:
with pytest.raises(exceptions.FlowReadException):
await rf.load_flows(io.BytesIO(b"qibble"))
caplog_async.caplog.clear()
caplog_async.clear()
with pytest.raises(exceptions.FlowReadException):
await rf.load_flows(corrupt_data)
await caplog_async.await_log("file corrupted")

View File

@ -64,7 +64,7 @@ class TestScript:
assert '"' not in s.fullpath
async def test_simple(self, tdata, caplog_async):
caplog_async.caplog.set_level("DEBUG")
caplog_async.set_level("DEBUG")
sc = script.Script(
tdata.path("mitmproxy/data/addonscripts/recorder/recorder.py"),
True,
@ -84,21 +84,28 @@ class TestScript:
sc.done()
async def test_reload(self, tmp_path, caplog_async):
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
with taddons.context() as tctx:
f = tmp_path / "foo.py"
f.write_text("\n")
sc = script.Script(str(f), True)
tctx.configure(sc)
await caplog_async.await_log("Loading")
caplog_async.clear()
caplog_async.caplog.clear()
f.write_text("\n\n")
await caplog_async.await_log("Loading")
for i in range(20):
# Some filesystems only have second-level granularity,
# so just writing once again is not good enough.
f.write_text("\n")
if "Loading" in caplog_async.caplog.text:
break
await asyncio.sleep(0.1)
else:
raise AssertionError("No reload seen")
sc.done()
async def test_exception(self, tdata, caplog_async):
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
with taddons.context() as tctx:
sc = script.Script(
tdata.path("mitmproxy/data/addonscripts/error.py"),
@ -127,7 +134,7 @@ class TestScript:
sc.done()
async def test_addon(self, tdata, caplog_async):
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
with taddons.context() as tctx:
sc = script.Script(tdata.path("mitmproxy/data/addonscripts/addon.py"), True)
tctx.master.addons.add(sc)
@ -161,7 +168,7 @@ class TestCutTraceback:
class TestScriptLoader:
async def test_script_run(self, tdata, caplog_async):
caplog_async.caplog.set_level("DEBUG")
caplog_async.set_level("DEBUG")
rp = tdata.path("mitmproxy/data/addonscripts/recorder/recorder.py")
sc = script.ScriptLoader()
with taddons.context(sc):
@ -204,7 +211,7 @@ class TestScriptLoader:
tctx.configure(sc, scripts=["one", "one"])
async def test_script_deletion(self, tdata, caplog_async):
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
tdir = tdata.path("mitmproxy/data/addonscripts/")
with open(tdir + "/dummy.py", "w") as f:
f.write("\n")
@ -237,7 +244,7 @@ class TestScriptLoader:
assert "NoneType" in caplog.text
async def test_order(self, tdata, caplog_async):
caplog_async.caplog.set_level("DEBUG")
caplog_async.set_level("DEBUG")
rec = tdata.path("mitmproxy/data/addonscripts/recorder")
sc = script.ScriptLoader()
sc.is_running = True
@ -264,7 +271,7 @@ class TestScriptLoader:
"c running",
]
caplog_async.caplog.clear()
caplog_async.clear()
tctx.configure(
sc,
scripts=[
@ -282,7 +289,7 @@ class TestScriptLoader:
"b configure",
]
caplog_async.caplog.clear()
caplog_async.clear()
tctx.configure(
sc,
scripts=[

View File

@ -10,7 +10,7 @@ class Recorder:
self.name = name
def __getattr__(self, attr):
if attr in hooks.all_hooks:
if attr in hooks.all_hooks and attr != "add_log":
def prox(*args, **kwargs):
lg = (self.name, attr, args, kwargs)

View File

@ -57,7 +57,7 @@ async def test_client_server():
async def test_reader(caplog_async):
caplog_async.caplog.set_level("DEBUG")
caplog_async.set_level("DEBUG")
reader = DatagramReader()
addr = ("8.8.8.8", 53)
reader.feed_data(b"First message", addr)

View File

@ -53,7 +53,7 @@ async def test_last_exception_and_running(monkeypatch):
async def test_tcp_start_stop(caplog_async):
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
manager = MagicMock()
with taddons.context():
@ -76,7 +76,7 @@ async def test_tcp_start_stop(caplog_async):
@pytest.mark.parametrize("failure", [True, False])
async def test_transparent(failure, monkeypatch, caplog_async):
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
manager = MagicMock()
if failure:
@ -135,7 +135,7 @@ async def test_invalid_protocol(monkeypatch):
async def test_udp_start_stop(caplog_async):
caplog_async.caplog.set_level("INFO")
caplog_async.set_level("INFO")
manager = MagicMock()
manager.connections = {}

View File

@ -61,9 +61,6 @@ class AOldAPI:
def clientconnect(self):
pass
def add_log(self):
pass
def test_command():
with taddons.context() as tctx: