mirror of
https://github.com/ChuckBuilds/LEDMatrix.git
synced 2026-10-04 06:15:09 +00:00
ChuckandClaude Opus 5.5
13bbb537f3
* refactor(web): use src.logging_config in the web process; routine requests to DEBUG
The web interface had its own logging setup (web_interface/logging_config.py)
that replaced the root handlers with a plain stdout formatter. The web
service's journal lines therefore never carried a syslog priority, so
`journalctl -p err -u ledmatrix-web` returned nothing while errors were
logged, and the line shape differed from the display's (the log viewer's
prefix stripping only matched the display format). It also ran after the
module-level managers were built, so their INFO lines at import (including
"Re-removed N uninstalled plugin(s)") were dropped.
app.py now calls src.logging_config.setup_logging() first thing, the same as
run.py: journald priorities under systemd, LEDMATRIX_DEBUG honoured,
LEDMATRIX_JSON_LOGGING still selects JSON.
Per-request logging moves to web_interface/request_logging.py. Every request
used to be logged at INFO, so the UI's polling filled the journal
("GET /api/v3/errors/summary - 200" every minute per tab). Now a successful
GET/HEAD/OPTIONS is DEBUG, a successful write is INFO, 4xx WARNING, 5xx
ERROR. Durations use perf_counter and print to 0.1ms.
The duplicate module is deleted; nothing else imported it.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
* refactor(web): one thread-safe TTL cache for the web process
web_interface/cache.py becomes a small TTLCache class (lock-guarded,
monotonic clock) with the existing get_cached/set_cached/delete_cached/
invalidate_cache helpers kept on top of a shared instance, so the api_v3
callers are unchanged.
Bugs fixed:
- set_cached(ttl_seconds=...) ignored its TTL; only the reader's value
counted and get_cached defaulted to 60s. An entry now expires after the TTL
it was stored with; a reader's ttl_seconds can only shorten that. Both
current callers pass the same value on both sides (fonts_catalog 300s,
system_status 10s), so their observable TTLs are unchanged.
- get_cached deleted expired keys without a lock; two threads reading the
same expired key could raise KeyError (reproduced), which the endpoints
turned into a 500.
app.py's two hand-rolled systemctl caches (_ap_mode_cache, 30s, and
_ledmatrix_service_cache, 15s) now share one helper over a private
TTLCache, with the same TTLs. The AP-mode check used to retry on every
request after a failure (and log an ERROR each time); a failure now keeps the
last known answer for the TTL, as the display-service check already did. With
no systemctl at all (a dev machine) it answers False without forking.
Left alone as not TTL memoisation: the gzip cache (size-bounded, keyed by URL
and version), the settings search index (keyed by installed-plugin set), the
widget bundle (keyed by file fingerprint) and CacheManager (cross-process).
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
* docs(changelog): web logging and TTL cache
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
* fix(web): only ask systemctl about known units
Codacy flagged the systemctl argv built from a variable. The unit now has
to be one of two literals, and anything else raises.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
* 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>
---------
Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
63 lines
2.2 KiB
Python
63 lines
2.2 KiB
Python
"""
|
|
Per-request logging for the web interface.
|
|
|
|
Logging itself is configured by ``src.logging_config.setup_logging`` (the same
|
|
formatter and journald priorities as the display service); this module only
|
|
decides what one HTTP request is worth logging, and at which level.
|
|
|
|
The UI polls: the error summary, system status, display preview and log
|
|
streams are fetched every few seconds by every open tab. Logging each of those
|
|
at INFO buried everything else in the journal (``GET /api/v3/errors/summary -
|
|
200`` once a minute per tab, forever). So a request that only read something
|
|
and succeeded is DEBUG; one that changed something, or failed, is logged at a
|
|
level that shows up by default.
|
|
"""
|
|
import logging
|
|
import time
|
|
|
|
from flask import Flask, request
|
|
|
|
logger = logging.getLogger('web_interface.api')
|
|
|
|
#: Methods that do not change server state. A successful one is routine.
|
|
_READ_ONLY_METHODS = frozenset({'GET', 'HEAD', 'OPTIONS'})
|
|
|
|
|
|
def request_log_level(method: str, status_code: int) -> int:
|
|
"""The level a finished request is logged at."""
|
|
if status_code >= 500:
|
|
return logging.ERROR
|
|
if status_code >= 400:
|
|
return logging.WARNING
|
|
if method.upper() in _READ_ONLY_METHODS:
|
|
return logging.DEBUG
|
|
return logging.INFO
|
|
|
|
|
|
def log_request(method: str, path: str, status_code: int,
|
|
duration_ms: float) -> None:
|
|
"""Log one finished request."""
|
|
level = request_log_level(method, status_code)
|
|
if logger.isEnabledFor(level):
|
|
logger.log(level, "%s %s - %d (%.1fms)",
|
|
method, path, status_code, duration_ms)
|
|
|
|
|
|
def init_app(app: Flask) -> None:
|
|
"""Time every request and log it when its response is ready."""
|
|
|
|
@app.before_request
|
|
def _start_request_timer():
|
|
request.start_time = time.perf_counter()
|
|
|
|
@app.after_request
|
|
def _log_finished_request(response):
|
|
try:
|
|
started = getattr(request, 'start_time', None)
|
|
duration_ms = 0.0 if started is None else (time.perf_counter() - started) * 1000
|
|
log_request(request.method, request.path, response.status_code,
|
|
duration_ms)
|
|
except Exception: # nosec B110 - request logging must never interrupt a live HTTP response
|
|
pass
|
|
return response
|