Log each request once

[krokicki]

Logged twice

AccessLogMiddleware logs every request with the authenticated username and duration; Uvicorn's own uvicorn.access logger logged it again without them. --no-access-log suppresses the second copy, but it has to be repeated on every launch command, and three of six were missing it: dev-launch-remote, prod-launch-remote, and dev_launch.py. prod-launch-remote is the one that serves data, so every chunk a viewer pulled was logged twice.

The app now silences the logger it replaces, next to where the middleware is installed, so no launcher has to remember. That runs the same two lines Uvicorn's own access_log=False does (config.py:396-398: clear handlers, stop propagation), and both HTTP protocol implementations gate on access_logger.hasHandlers() before building a record (httptools_impl.py:59, h11_impl.py:54) — so this takes the identical fast path, with no LogRecord constructed per request.

That makes the remaining --no-access-log flags and access_log=False kwargs exactly redundant, so they're gone: one mechanism instead of a flag that was already unevenly applied. I checked the gate before deleting them — had Uvicorn tested config.access_log rather than hasHandlers(), the flags would have been the cheaper option on a per-chunk path and this would have gone the other way.

Uvicorn configures logging before importing the app, in --reload and --workers subprocesses too, so the app-side call always wins.

Logged decoded

The middleware used request.url.path, which Starlette builds from scope["path"] — percent-decoded per the ASGI spec. A filename containing a literal % is sent as %25 and was logged as %, so the line didn't round-trip to the request that was actually made. That's the difference visible above.

Now logs raw_path (the encoded target, which is what Uvicorn's own access log reports), falling back to the decoded path since ASGI marks raw_path optional, and escapes control characters in both the path and the query string.

On the escaping, stated precisely rather than as a scare: Starlette's URL goes through urlsplit, which strips CR/LF, so forged log lines were already impossible by accident. What survives is ESC and |:

path='/a/x\n\x1b[2Jy|z'  ->  newline survives: False | ESC survives: True | pipe survives: True

Both are client-controlled text landing in a log line: ESC can recolour a terminal tailing it, and | is loguru's own field separator, so a decoded | in a path corrupts field parsing. So the change stands on fidelity, with the escaping as real but narrow hardening.

Validation

• pixi run -e test test-backend — 770 passed (768 on main, plus the two new tests in tests/test_log.py)
• reproduced the double logging first on a launcher that lacked the flag (2 lines), then confirmed 1 line after, with zero lines in Uvicorn's format and its lifecycle logs (startup/shutdown) untouched — only uvicorn.access is silenced
• end-to-end against a real Uvicorn with curl --path-as-is: the reported path logs as ..._1%25_0.2%25_1hr_..., and %1B%5B2Jy%7Cz logs inert with no ESC byte reaching the file
• the injection test drives a hand-built ASGI scope, not TestClient — httpx normalizes control characters away, so it cannot express the request being defended against, and a first version of the test passed for the wrong reason

@StephanPreibisch @JaneliaSciComp/fileglancer