From ef85a3ca427fc590f804d385a6f2b3bc55e9ee52 Mon Sep 17 00:00:00 2001 From: scheianu Date: Wed, 14 Oct 2026 23:54:48 +0300 Subject: [PATCH] Stop per-heartbeat re-auth log spam; stop logging bearer tokens Two issues found while investigating repeated "Re-authentication required for Test player (rpi-test1): token_reset" entries appearing every ~20s. 1) Log spam. The heartbeat handler logged an INFO row every time it asked a player to re-authenticate. A player heartbeats every ~15s and the request repeats until the player complies, so a pending request wrote a server_log row every few seconds (~230 rows in ~1.3h here) and buried the dashboard. The per-heartbeat log line is removed. The request is now recorded once, at the moment it is raised: the admin action already logs when the button is pressed, and the automatic interval now logs at its transition. The outstanding request stays visible in Admin -> Maintenance as "awaiting re-auth". 2) Credential leak. verify_player_auth logged the rejected value in full ("Invalid auth code attempt: "). server_log is readable in the UI and the database, so this wrote a live bearer token to a readable store. It now logs a 6-character prefix plus the client IP, which is enough to correlate failures without exposing the credential. --- app/blueprints/api.py | 28 +++++++++++++++++++++++----- 1 file changed, 23 insertions(+), 5 deletions(-) diff --git a/app/blueprints/api.py b/app/blueprints/api.py index f6836de..b626173 100644 --- a/app/blueprints/api.py +++ b/app/blueprints/api.py @@ -78,7 +78,13 @@ def verify_player_auth(f): player = Player.query.filter_by(auth_code=auth_code).first() if not player: - log_action('warning', f'Invalid auth code attempt: {auth_code}') + # Never log the whole token: server_log is readable in the UI (and + # the DB), so writing a bearer value there would leak a credential. + # A short prefix is enough to correlate repeated failures. + token_hint = f'{auth_code[:6]}…' if auth_code else '(empty)' + log_action('warning', + f'Invalid auth code attempt (token {token_hint}, ' + f'client {request.remote_addr})') return jsonify({'error': 'Invalid authentication code'}), 403 # Store player in request context @@ -143,9 +149,19 @@ def player_needs_reauth(player: Player): return False, None if datetime.utcnow() - issued >= timedelta(days=interval_days): - # Flag the player; the replacement token is issued when it re-auths. + # Raise the request and record it ONCE, at the transition. + # + # This deliberately does not log per request: a player heartbeats every + # ~15s, so logging each time it is asked would add a server_log row + # every few seconds and drown the dashboard. The pending request stays + # visible in Admin -> Maintenance as "awaiting re-auth", which is the + # place to look, and the admin-triggered path is logged where the admin + # presses the button. player.request_reauth() db.session.commit() + log_action('info', + f'Auth token interval elapsed for {player.name} ' + f'({player.hostname}) — re-authentication requested') return True, 'token_expired' return False, None @@ -570,12 +586,14 @@ def receive_player_feedback(): # # This runs before any feedback is recorded: the heartbeat is not a # meaningful status update while the client is being asked to - # re-authenticate. + # re-authenticate. Note there is intentionally NO log line here — the + # request repeats on every heartbeat (~15s) until the player complies, + # which would flood server_log. The outstanding request is visible in + # Admin -> Maintenance ("awaiting re-auth") and is logged once where it + # is raised (admin action, or the interval transition above). # ------------------------------------------------------------------ needs_reauth, reauth_reason = player_needs_reauth(player) if needs_reauth: - log_action('info', f'Re-authentication required for {player.name} ' - f'({player.hostname}): {reauth_reason}') return jsonify({ 'success': False, 'auth_required': True,