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: <token>"). 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.
This commit is contained in:
+23
-5
@@ -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,
|
||||
|
||||
Reference in New Issue
Block a user