json access-log formatter crashes when request.client is None

[vinismarques]

Summary

When enable_json_logging is on, the request access-log formatter crashes on any request where request.client is None, losing that log line and printing a traceback to stderr:

--- Logging error ---
Traceback (most recent call last):
  File ".../logging/__init__.py", line 1100, in emit
    msg = self.format(record)
  ...
  File ".../json_logging/framework/fastapi/implementation.py", line 108, in get_remote_ip
    return request.client.host
AttributeError: 'NoneType' object has no attribute 'host'

Cosmetic, not functional. The access log is emitted after call_next returns, and logging.Handler.emit routes formatter exceptions to handleError, so the request itself completes normally. The cost is stderr noise plus a missing access-log line.

Cause

serve.py installs the instrumentation unconditionally:

if settings.enable_json_logging:
    json_logging.init_fastapi(enable_json=True)
    json_logging.init_request_instrument(app)   # installs FastAPIRequestInfoExtractor
    json_logging.config_root_logger()

json_logging 1.5.1 dereferences a documented-Optional without a guard:

# json_logging/framework/fastapi/implementation.py
def get_remote_ip(self, request):
    return request.client.host    # also get_remote_port -> request.client.port

Starlette types Request.client as Optional[Address], returning None when scope["client"] is absent. Uvicorn sets that to None when getpeername() raises OSError on an already-reset socket (uvicorn/protocols/utils.py, get_remote_addr).

Observed on GPU workers against the /health readiness probe (periodSeconds: 2, timeoutSeconds: 1). Frequency is a small fraction of total probes and arrives in bursts. Unconfirmed hypothesis for the bursts: inference saturates the event loop, accept() lands after the probe timeout, kubelet resets, and uvicorn then reads getpeername() on a dead socket. Not correlated against inference spans, so treat the mechanism above as established and the burst trigger as likely.

Affected versions

Every release. The init_request_instrument call is byte-identical across 3.5.1, 4.0.0, 4.1.0, 5.0.0, 5.1.0, 5.1.1 and main — only line numbers move. Upgrading does not help.

Upstream status

Already fixed, but unreleased. bobbui/json-logging-python#116 ("fix: handle missing FastAPI request client", fixes #90) merged 2026-06-17 and guards both accessors with json_logging.EMPTY_VALUE. The latest PyPI release 1.5.1 predates that merge, and prior release gaps have run to years, so waiting on a release is not a plan.

Suggested fix

Our pin is json-logging>=1.3,<2, so a released upstream fix would be picked up automatically and any local workaround becomes a harmless no-op. Options:

1. Subclass FastAPIRequestInfoExtractor, override get_remote_ip / get_remote_port to return EMPTY_VALUE when request.client is None, and pass it to init_request_instrument.
2. Drop init_request_instrument(app) if these access-log lines are not consumed downstream.

Worth considering separately: the probe's timeoutSeconds: 1 against a GPU worker is aggressive, and relaxing it would reduce the resets that trigger this.

Optionally, open an upstream issue asking for a 1.5.2 cut so the merged fix reaches PyPI.