fix(web): response_time_ms reads the same clock request_logging stamps

request_logging now stamps request.start_time from perf_counter, but
success_response still subtracted it from time.time(), so metadata
reported ~1.8e12 ms. Found testing on ledpi.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Chuck
2026-09-23 18:22:56 -04:00
co-authored by Claude Opus 5.5
parent 8eb04dcae7
commit e4d6e34add
2 changed files with 17 additions and 1 deletions
+2 -1
View File
@@ -34,7 +34,8 @@ def success_response(
# metadata block for responses that have neither.
enriched = dict(metadata) if metadata is not None else {}
if hasattr(request, 'start_time'):
enriched['response_time_ms'] = int((time.time() - request.start_time) * 1000)
# request_logging stamps start_time from perf_counter, not the wall clock.
enriched['response_time_ms'] = int((time.perf_counter() - request.start_time) * 1000)
if metadata is not None or enriched:
response_data['metadata'] = enriched
+15
View File
@@ -162,3 +162,18 @@ def test_duration_is_rounded(tiny_app, caplog):
msg = caplog.records[-1].getMessage()
duration = msg.rsplit("(", 1)[1]
assert duration.endswith("ms)") and len(duration.split(".")[1]) == len("0ms)"), msg
def test_success_response_timing_uses_the_same_clock():
# request_logging stamps request.start_time from perf_counter; a reader
# subtracting it from time.time() reported ~1.8e12 ms (found on a Pi).
from src.web_interface.api_helpers import success_response
app = Flask(__name__)
request_logging.init_app(app)
@app.route('/timed')
def timed():
return success_response(data={}, metadata={})
body = app.test_client().get('/timed').get_json()
assert 0 <= body['metadata']['response_time_ms'] < 10_000