Console Freezes on Incorrect Timestamps in Flows

[owlux]

Problem Description

I'm using mitmproxy in WireGuard mode for iOS/Android devices. Sometimes, DNS flows are recorded with the request timestamp being later than the response, which causes the console to freeze when these flows are displayed.

Upon encountering this issue, manually rendering the screen using a debugger revealed the following error:

Traceback (most recent call last):
  File "c:\Users\x\Documents\code\y\.venv\lib\site-packages\mitmproxy\tools\console\common.py", line 352, in format_duration
    99 - 100 * min(math.log2(1 + 1000 * duration) / 12, 0.99)
ValueError: math domain error

The problem seems to be from a negative duration value calculated as f.response.timestamp - f.request.timestamp. I suspect this causes the faux_idle_callback() in urwid/main_loop.py not to be called anymore, stopping the screen rendering.

Although format_duration is invoked from various layers, the issue only occurs with DNS flows in my environment. Adjusting a single line in the format_dns_flow() function within mitmproxy\tools\console\common.py resolved the issue.

- if duration:
+ if duration and duration > 0:

The UI freezing during exceptions made it difficult to pinpoint the problem. It would be helpful if there was a way to output errors to a file.

Steps to Reproduce:

1. Load invalid_timestamp_dns.flow in mitmproxy.
2. Notice the screen does not render.

invalid_timestamp_dns.zip

System Info

Mitmproxy: 10.2.2
Python: 3.11.7
OpenSSL: OpenSSL 3.1.4 24 Oct 2023
Platform: Windows-10-10.0.22631-SP0

WireGuard for iOS: 1.0.16 (27)

[owlux]

I have not looked into why such timestamps are logged.

[mhils]

Thanks for filing this! We should fix the root cause here (negative durations) and not apply bandaids.

[mhils]

More concretely: We currently seem to use client/server-provided timestamps. We shouldn't do that at all, but use local (trusted) timestamps.