ploneasgi.accesslog

ploneasgi.accesslog#

An access log that sits at the ASGI layer, above every route.

Replaces paste.translogger. There are three reasons the WSGI layer is the wrong place for this, and all three are structural rather than cosmetic:

  • It cannot see most of the application. TransLogger wraps the WSGI app, which this package mounts below the router. Websocket routes and anything else passed to create_app(routes=...) never reach it, so they are silently absent from the log.

  • It logs before the body exists. TransLogger emits its line from inside replacement_start_response — when headers are ready. Under this package the body is streamed on the event loop after the WSGI call returns, so the entire phase ploneasgi.wsgi exists to optimize happens after the log line is written. No amount of instrumenting the WSGI layer fixes that; it is on the wrong side of the seam.

  • Its byte count is the ``Content-Length`` header, not bytes written. The source says so outright: "Ideally we would count the bytes going by […] at least for now we'll be lazy." So it is wrong whenever the header and the body disagree — range responses, chunked replies, and any body the app truncates.

Wrapping send instead counts the bytes the application actually emitted, and splits the timing in two:

ttfb

Time to the http.response.start event — request parsing, the worker-thread hop, and Zope's render. This is what a page-speed number means.

duration

Time to the final body event — ttfb plus the transfer.

Keeping them apart is the point for this package. Worker-thread starvation shows up as ttfb climbing while duration is dominated by slow clients; a single merged number cannot distinguish "Plone is slow" from "someone is downloading a film over a bad connection".

Warning

``bytes`` is what the application emitted, not what the client received. uvicorn's send begins if self.disconnected: return — after a client goes away it discards chunks without telling the application. Measured 2026-08-03, before the adapter watched for it: a rate-limited curl killed after one second produced a normal, complete-looking 200 for the full 50 MB.

ploneasgi.wsgi.WSGIMiddleware now waits on receive while it streams, stops at http.disconnect and marks the scope with DISCONNECTED_KEY; the line then ends in incomplete=client-gone, and bytes is what was emitted up to the moment the disconnect was noticed — still an upper bound on what arrived, since the last chunks may have been sitting in a socket buffer. incomplete=truncated is the other case: the application stopped emitting early, typically an exception mid-stream. Native routes and other apps that do not watch receive still log an aborted download as complete.

Note

uvicorn has its own access log, on by default. ploneasgi.app.serve() turns it off unconditionally, so this is the only access log and PLONE_ACCESS_LOG decides whether there is one at all.

Note

Nothing here imports Zope. It is general ASGI middleware and is tested as one.

ploneasgi.accesslog.DEFAULT_FORMAT = '%(client)s - %(user)s [%(time)s] "%(method)s %(path)s %(protocol)s" %(status)s %(bytes)s %(duration)s %(ttfb)s "%(referer)s" "%(user_agent)s"%(note)s'#

Apache combined, plus the two timings and a completeness note. bytes is bytes the application emitted — see the module warning about what that does and does not tell you.

ploneasgi.accesslog.USER_KEY = 'ploneasgi.user'#

Key a downstream WSGI middleware may set on the ASGI scope to name the authenticated user. The adapter exposes the scope to WSGI as asgi.scope, so Zope-side code can reach it:

environ["asgi.scope"][USER_KEY] = environ.get("REMOTE_USER")

Without it the user column is -: authentication happens inside Zope, and this middleware runs above it.

class ploneasgi.accesslog.AccessLogMiddleware[source]#

Log every HTTP request and websocket session in one consistent format.

Written as raw ASGI middleware rather than a Starlette BaseHTTPMiddleware: the latter pumps the response through memory streams, which would buffer the very responses ploneasgi.wsgi streams. Logging the blob path must not destroy it.

Variables:

trust_forwarded -- When true, prefer X-Forwarded-For over the socket address. Off by default — the header is client-supplied and trivially spoofed, so it is only meaningful behind a proxy that overwrites it.

__init__(app, *, fmt='%(client)s - %(user)s [%(time)s] "%(method)s %(path)s %(protocol)s" %(status)s %(bytes)s %(duration)s %(ttfb)s "%(referer)s" "%(user_agent)s"%(note)s', trust_forwarded=False, level=20, log=None)[source]#
Parameters:
Return type:

None

ploneasgi.accesslog.MiddlewareFactory#

Type of a middleware factory, for callers composing their own stack.

alias of Callable[[...], AccessLogMiddleware]

Contents