Add owner-only logging and Brickset API call tracking

LIM configured no logging at all, so the instruction fetcher had no trail to follow. Adds a rotating file handler on the root logger plus two owner-only admin pages.

- Admin > Logs: filter by level, source and text; tracebacks kept with their error; auto-refresh, raw download, rotated-file browsing and rotate-now

- Admin > Logs > Brickset API calls: every outbound call recorded with method, params, caller, duration, result count and error, plus daily quota accounting (only getSets counts) and a comparison against getKeyUsageStats

- New owner concept (services/ownership.py): a single account, distinct from is_admin, since these pages expose other admins activity. Defaults to the first admin; flask owner show/set to change

- Services now log through module loggers; retention setting and pruning for call records

- New CLI: flask owner show/set, flask logs path/prune

- New table brickset_api_calls, created automatically at boot; LOG_* env vars, /data/logs in Docker
This commit is contained in:
jessikitty committed 2026-09-27 10:42:49 +10:00
1 parent 89f65e2d74
commit f7c20de5ac
27 files changed
+1914 -35

No files matched your search

+108 -19
View File
@@ -17,10 +17,15 @@ Created by: Jess Rogerson (yelling commands at Claude.AI)
"""
import json
import logging
import time
from typing import Any, Dict, List, Optional
import requests
from flask import current_app
from flask import current_app, has_request_context, request
from flask_login import current_user
logger = logging.getLogger(__name__)
class BricksetAPI:
@@ -28,11 +33,49 @@ class BricksetAPI:
BASE_URL = 'https://brickset.com/api/v3.asmx'
def __init__(self):
def __init__(self, context: Optional[str] = None):
self.api_key = current_app.config.get('BRICKSET_API_KEY')
self.username = current_app.config.get('BRICKSET_USERNAME')
self.password = current_app.config.get('BRICKSET_PASSWORD')
self._user_hash = None
# Recorded against every call so the log shows which part of LIM
# was responsible. Falls back to the endpoint name in a request.
self.context = context or self._default_context()
@staticmethod
def _default_context() -> str:
if has_request_context() and request.endpoint:
return request.endpoint.split('.')[-1][:40]
return 'background'
def _log_call(self, method, params=None, ok=True, http_status=None,
result_count=None, started=None, message=None):
"""Record one call. Never raises."""
duration = None
if started is not None:
duration = int((time.monotonic() - started) * 1000)
if ok:
logger.info('Brickset %s (%s) -> %s result(s) in %sms',
method, params or '-',
'?' if result_count is None else result_count,
duration)
else:
logger.warning('Brickset %s (%s) failed: %s',
method, params or '-', message)
try:
from app.models.api_call import BricksetApiCall
user_id = None
if has_request_context() and getattr(current_user,
'is_authenticated', False):
user_id = current_user.id
BricksetApiCall.record(
method=method, params=params, ok=ok, http_status=http_status,
result_count=result_count, duration_ms=duration,
message=message, context=self.context, user_id=user_id)
except Exception:
logger.debug('Could not record Brickset call', exc_info=True)
@staticmethod
def is_configured() -> bool:
@@ -52,6 +95,7 @@ class BricksetAPI:
current_app.logger.warning('Brickset API credentials not configured')
return None
started = time.monotonic()
try:
response = requests.get(
f'{self.BASE_URL}/login',
@@ -67,13 +111,19 @@ class BricksetAPI:
if data.get('status') == 'success':
self._user_hash = data.get('hash')
self._log_call('login', self.username, ok=True,
http_status=response.status_code,
started=started)
return self._user_hash
else:
current_app.logger.error(f"Brickset login failed: {data.get('message')}")
return None
self._log_call('login', self.username, ok=False,
http_status=response.status_code, started=started,
message=str(data.get('message')))
return None
except Exception as e:
current_app.logger.error(f'Brickset API authentication error: {str(e)}')
self._log_call('login', self.username, ok=False, started=started,
message=f'{type(e).__name__}: {e}')
return None
def search_sets(self,
@@ -123,6 +173,9 @@ class BricksetAPI:
'params': json.dumps(search_params),
}
summary = json.dumps(search_params, separators=(',', ':'))
started = time.monotonic()
try:
response = requests.get(
f'{self.BASE_URL}/getSets',
@@ -133,10 +186,16 @@ class BricksetAPI:
data = response.json()
if data.get('status') == 'success':
return data.get('sets', [])
sets = data.get('sets', [])
self._log_call('getSets', summary, ok=True,
http_status=response.status_code,
result_count=len(sets), started=started)
return sets
message = data.get('message', 'unknown error')
current_app.logger.error(f'Brickset search failed: {message}')
self._log_call('getSets', summary, ok=False,
http_status=response.status_code, started=started,
message=message)
if 'limit exceeded' in message.lower():
raise RuntimeError('Brickset API limit exceeded')
return []
@@ -144,7 +203,8 @@ class BricksetAPI:
except RuntimeError:
raise
except Exception as e:
current_app.logger.error(f'Brickset API search error: {str(e)}')
self._log_call('getSets', summary, ok=False, started=started,
message=f'{type(e).__name__}: {e}')
return []
def get_set_by_number(self, set_number: str) -> Optional[Dict[str, Any]]:
@@ -174,6 +234,7 @@ class BricksetAPI:
if not user_hash:
return []
started = time.monotonic()
try:
response = requests.get(
f'{self.BASE_URL}/getThemes',
@@ -188,19 +249,31 @@ class BricksetAPI:
if data.get('status') == 'success':
themes = data.get('themes', [])
return [theme.get('theme') for theme in themes if theme.get('theme')]
else:
return []
names = [theme.get('theme') for theme in themes
if theme.get('theme')]
self._log_call('getThemes', ok=True,
http_status=response.status_code,
result_count=len(names), started=started)
return names
self._log_call('getThemes', ok=False,
http_status=response.status_code, started=started,
message=str(data.get('message')))
return []
except Exception as e:
current_app.logger.error(f'Brickset API themes error: {str(e)}')
self._log_call('getThemes', ok=False, started=started,
message=f'{type(e).__name__}: {e}')
return []
# -- instructions -------------------------------------------------------
def _instructions_request(self, method: str,
params: Dict[str, Any]) -> List[Dict[str, Any]]:
summary = ', '.join(f'{k}={v}' for k, v in params.items())
params = dict(params, apiKey=self.api_key)
started = time.monotonic()
try:
response = requests.get(f'{self.BASE_URL}/{method}',
params=params, timeout=20)
@@ -208,14 +281,20 @@ class BricksetAPI:
data = response.json()
if data.get('status') == 'success':
return data.get('instructions', []) or []
instructions = data.get('instructions', []) or []
self._log_call(method, summary, ok=True,
http_status=response.status_code,
result_count=len(instructions), started=started)
return instructions
current_app.logger.error(
f"Brickset {method} failed: {data.get('message')}")
self._log_call(method, summary, ok=False,
http_status=response.status_code, started=started,
message=str(data.get('message')))
return []
except Exception as e:
current_app.logger.error(f'Brickset {method} error: {str(e)}')
self._log_call(method, summary, ok=False, started=started,
message=f'{type(e).__name__}: {e}')
return []
def get_instructions(self, set_number: str) -> List[Dict[str, Any]]:
@@ -246,6 +325,7 @@ class BricksetAPI:
"""
if not self.api_key:
return []
started = time.monotonic()
try:
response = requests.get(f'{self.BASE_URL}/getKeyUsageStats',
params={'apiKey': self.api_key},
@@ -253,8 +333,17 @@ class BricksetAPI:
response.raise_for_status()
data = response.json()
if data.get('status') == 'success':
return data.get('apiKeyUsage', []) or []
usage = data.get('apiKeyUsage', []) or []
self._log_call('getKeyUsageStats', ok=True,
http_status=response.status_code,
result_count=len(usage), started=started)
return usage
self._log_call('getKeyUsageStats', ok=False,
http_status=response.status_code, started=started,
message=str(data.get('message')))
return []
except Exception as e:
current_app.logger.error(f'Brickset key usage error: {str(e)}')
self._log_call('getKeyUsageStats', ok=False, started=started,
message=f'{type(e).__name__}: {e}')
return []
+8 -4
View File
@@ -18,10 +18,13 @@ with `flask instructions run` instead.
Created by: Jess Rogerson (yelling commands at Claude.AI)
"""
import logging
import os
import sys
import threading
logger = logging.getLogger(__name__)
_thread = None
_stop = threading.Event()
_lock = threading.Lock()
@@ -38,7 +41,7 @@ def _is_cli_command():
def start(app):
"""Start the ticker unless it's disabled or already running."""
if not app.config.get('INSTRUCTION_FETCH_WORKER', True):
app.logger.info('Instruction fetch worker disabled by config')
logger.info('Instruction fetch worker disabled by config')
return False
# `flask instructions run`, `flask backup restore` and friends shouldn't
@@ -61,7 +64,8 @@ def start(app):
daemon=True)
_thread.start()
app.logger.info('Instruction fetch worker started')
logger.info('Instruction fetch worker started (tick %ss)',
app.config.get('INSTRUCTION_FETCH_TICK_SECONDS', 20))
return True
@@ -86,7 +90,7 @@ def _loop(app):
with app.app_context():
fetcher.run_one()
except Exception:
app.logger.exception('Instruction fetch worker tick failed')
logger.exception('Instruction fetch worker tick failed')
def run_once_async(app, force=False):
@@ -102,7 +106,7 @@ def run_once_async(app, force=False):
from app.services import instruction_fetcher as fetcher
fetcher.run_one(force=force)
except Exception:
app.logger.exception('Manual instruction fetch failed')
logger.exception('Manual instruction fetch failed')
thread = threading.Thread(target=_work, name='lim-fetch-once', daemon=True)
thread.start()
+15 -5
View File
@@ -21,6 +21,7 @@ Created by: Jess Rogerson (yelling commands at Claude.AI)
"""
import hashlib
import logging
import os
import re
import tempfile
@@ -30,6 +31,8 @@ from datetime import datetime, timedelta
import requests
from flask import current_app
logger = logging.getLogger(__name__)
from app import db
from app.models.instruction import Instruction
from app.models.instruction_fetch import InstructionFetchJob
@@ -375,8 +378,11 @@ def fetch_for_set(lego_set, delay_between_files=None):
pause = (file_delay_seconds() if delay_between_files is None
else delay_between_files)
api = BricksetAPI()
api = BricksetAPI(context='fetcher')
entries, source, note = _instruction_urls(api, lego_set)
logger.info('Set %s: Brickset lists %d instruction file(s)%s',
lego_set.set_number, len(entries),
f' ({note})' if note else '')
if not entries:
return 0, 0, source, note or 'no instructions listed on Brickset'
@@ -395,6 +401,8 @@ def fetch_for_set(lego_set, delay_between_files=None):
temp_path, size, sha = _download_pdf(entry['url'], max_bytes,
timeout)
except Exception as exc:
logger.warning('Set %s: download failed for %s - %s',
lego_set.set_number, entry['url'], exc)
problems.append(f'{entry["description"] or entry["url"]}: {exc}')
continue
@@ -427,6 +435,8 @@ def fetch_for_set(lego_set, delay_between_files=None):
known.add(sha)
page += 1
added += 1
logger.info('Set %s: saved %s (%d bytes)',
lego_set.set_number, filename, file_size or size)
except Exception as exc:
db.session.rollback()
@@ -519,8 +529,8 @@ def run_one(force=False):
job.status = 'empty'
except Exception as exc:
current_app.logger.exception('Instruction fetch failed for %s',
lego_set.set_number)
logger.exception('Instruction fetch failed for %s',
lego_set.set_number)
job.message = str(exc)[:500]
if job.attempts >= max_attempts():
job.status = 'failed'
@@ -533,8 +543,8 @@ def run_one(force=False):
job.finished_at = datetime.utcnow()
db.session.commit()
current_app.logger.info('Instruction fetch %s for %s: %s', job.status,
lego_set.set_number, job.message)
logger.info('Job #%s %s for %s: %s', job.id, job.status,
lego_set.set_number, job.message)
return job.to_dict()
+218
View File
@@ -0,0 +1,218 @@
"""
Logging setup and log reading.
LIM previously configured no logging at all, which left Flask's logger at
WARNING and wrote nothing to disk — so a quiet background feature like the
instruction fetcher had no trail to follow. This attaches a rotating file
handler to the root logger, so every module logger (app.services.*, and the
fetcher in particular) lands in one file, and provides the parsing the admin
log viewer needs.
Rotation is by size, not date: LOG_MAX_BYTES per file, LOG_BACKUP_COUNT old
copies, so disk use is bounded no matter how chatty things get.
Created by: Jess Rogerson (yelling commands at Claude.AI)
"""
import io
import logging
import os
import re
from logging.handlers import RotatingFileHandler
LOG_FILENAME = 'lim.log'
LEVELS = ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')
LEVEL_BADGES = {
'DEBUG': 'secondary',
'INFO': 'info',
'WARNING': 'warning',
'ERROR': 'danger',
'CRITICAL': 'danger',
}
# 2026-09-26 13:38:00 INFO app.services.instruction_fetcher | message
LINE_RE = re.compile(
r'^(?P<time>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\s+'
r'(?P<level>[A-Z]+)\s+'
r'(?P<logger>\S+)\s+\|\s'
r'(?P<message>.*)$'
)
_FORMAT = '%(asctime)s %(levelname)-8s %(name)s | %(message)s'
_DATEFMT = '%Y-%m-%d %H:%M:%S'
def log_path(app):
return os.path.join(app.config['LOG_FOLDER'], LOG_FILENAME)
def configure_logging(app):
"""
Attach the rotating file handler. Idempotent — safe on a reloader restart.
"""
folder = app.config['LOG_FOLDER']
try:
os.makedirs(folder, exist_ok=True)
except Exception as exc:
# A read-only or missing volume shouldn't stop the app booting.
app.logger.warning('Could not create log folder %s: %s', folder, exc)
return None
level = getattr(logging, str(app.config.get('LOG_LEVEL', 'INFO')).upper(),
logging.INFO)
path = log_path(app)
root = logging.getLogger()
for existing in root.handlers:
if getattr(existing, '_lim_handler', False):
existing.setLevel(level)
root.setLevel(level)
app.logger.setLevel(level)
return path
try:
handler = RotatingFileHandler(
path,
maxBytes=int(app.config.get('LOG_MAX_BYTES', 2 * 1024 * 1024)),
backupCount=int(app.config.get('LOG_BACKUP_COUNT', 5)),
encoding='utf-8',
)
except Exception as exc:
app.logger.warning('Could not open log file %s: %s', path, exc)
return None
handler.setFormatter(logging.Formatter(_FORMAT, datefmt=_DATEFMT))
handler.setLevel(level)
handler._lim_handler = True
root.addHandler(handler)
root.setLevel(level)
app.logger.setLevel(level)
# Request access logs are noisy and rarely what you're looking for.
if not app.config.get('LOG_ACCESS', False):
logging.getLogger('werkzeug').setLevel(logging.WARNING)
app.logger.info('Logging to %s at %s', path,
logging.getLevelName(level))
return path
def get_handler():
for handler in logging.getLogger().handlers:
if getattr(handler, '_lim_handler', False):
return handler
return None
def rotate_now():
"""Force a rollover. Returns True if it happened."""
handler = get_handler()
if handler is None:
return False
handler.doRollover()
return True
def available_files(app):
"""The live log plus its rotated backups, newest first."""
folder = app.config['LOG_FOLDER']
if not os.path.isdir(folder):
return []
found = []
for name in os.listdir(folder):
if name == LOG_FILENAME or name.startswith(LOG_FILENAME + '.'):
full = os.path.join(folder, name)
try:
found.append({
'name': name,
'size': os.path.getsize(full),
'current': name == LOG_FILENAME,
})
except OSError:
continue
# lim.log first, then lim.log.1, lim.log.2, ...
found.sort(key=lambda item: (not item['current'], item['name']))
return found
def resolve_file(app, name):
"""Turn a user-supplied file name into a safe path inside LOG_FOLDER."""
if not name:
name = LOG_FILENAME
if name != LOG_FILENAME and not name.startswith(LOG_FILENAME + '.'):
return None
if os.path.sep in name or '/' in name or '..' in name:
return None
path = os.path.join(app.config['LOG_FOLDER'], name)
return path if os.path.isfile(path) else None
def _tail_bytes(path, limit):
"""Last `limit` bytes of a file, decoded leniently."""
size = os.path.getsize(path)
with io.open(path, 'rb') as handle:
if size > limit:
handle.seek(size - limit)
handle.readline() # discard the partial first line
return handle.read().decode('utf-8', errors='replace')
def read_entries(path, max_entries=300, level=None, search=None,
logger_prefix=None, byte_limit=1024 * 1024):
"""
Parse the tail of a log file into entries, newest last.
Lines that don't match the format (traceback continuations) are attached
to the entry above them, so a stack trace stays with its error.
"""
if not path or not os.path.isfile(path):
return [], 0
text = _tail_bytes(path, byte_limit)
entries = []
for line in text.splitlines():
match = LINE_RE.match(line)
if match:
entries.append({
'time': match.group('time'),
'level': match.group('level'),
'logger': match.group('logger'),
'message': match.group('message'),
'extra': [],
})
elif entries:
entries[-1]['extra'].append(line)
total = len(entries)
if level:
wanted = str(level).upper()
if wanted in LEVELS:
floor = LEVELS.index(wanted)
entries = [entry for entry in entries
if entry['level'] in LEVELS
and LEVELS.index(entry['level']) >= floor]
if logger_prefix:
entries = [entry for entry in entries
if entry['logger'].startswith(logger_prefix)]
if search:
needle = search.lower()
entries = [
entry for entry in entries
if needle in entry['message'].lower()
or needle in entry['logger'].lower()
or any(needle in line.lower() for line in entry['extra'])
]
for entry in entries:
entry['badge'] = LEVEL_BADGES.get(entry['level'], 'secondary')
return entries[-max_entries:], total
+86
View File
@@ -0,0 +1,86 @@
"""
Who owns this LIM instance.
LIM only had is_admin, which is fine for day-to-day administration but too
broad for things that expose the whole instance: the log viewer shows every
request, every error and every API call, including other admins' activity.
The owner is a single account:
* whatever `owner_user_id` in site_settings points at, if that user exists;
* otherwise the lowest-numbered admin (in practice the account created by
`flask init_db`), which is then remembered.
Change it with `flask owner set <username>`.
Created by: Jess Rogerson (yelling commands at Claude.AI)
"""
from functools import wraps
from flask import flash, redirect, url_for
from flask_login import current_user
from app import db
from app.models.site_setting import SiteSetting
from app.models.user import User
OWNER_SETTING = 'owner_user_id'
def get_owner():
"""The User who owns this instance, or None on an empty database."""
raw = SiteSetting.get(OWNER_SETTING, '')
if raw and str(raw).strip().isdigit():
owner = db.session.get(User, int(str(raw).strip()))
if owner is not None:
return owner
# Nothing stored (or it points at a deleted account): fall back to the
# first admin and remember the answer.
owner = (User.query.filter_by(is_admin=True).order_by(User.id).first()
or User.query.order_by(User.id).first())
if owner is not None:
try:
SiteSetting.set(OWNER_SETTING, str(owner.id))
db.session.commit()
except Exception:
db.session.rollback()
return owner
def get_owner_id():
owner = get_owner()
return owner.id if owner else None
def set_owner(user):
"""Hand ownership to a user. Returns the user."""
SiteSetting.set(OWNER_SETTING, str(user.id))
if not user.is_admin:
user.is_admin = True
db.session.commit()
return user
def is_owner(user=None):
"""Is this user (default: the logged-in one) the owner?"""
user = user or current_user
if user is None or not getattr(user, 'is_authenticated', False):
return False
owner_id = get_owner_id()
return owner_id is not None and user.id == owner_id
def owner_required(f):
"""Stricter than admin_required: this account only."""
@wraps(f)
def decorated_function(*args, **kwargs):
if not current_user.is_authenticated:
flash('Please log in to access this page.', 'warning')
return redirect(url_for('auth.login'))
if not is_owner(current_user):
flash('That area is restricted to the instance owner.', 'danger')
return redirect(url_for('main.index'))
return f(*args, **kwargs)
return decorated_function
+4 -1
View File
@@ -34,7 +34,10 @@ ADDITIVE_COLUMNS = {
# Tables added by later versions. create_all() is not called at boot, so new
# tables need an explicit (and idempotent) nudge.
NEW_TABLES = ('app.models.instruction_fetch.InstructionFetchJob',)
NEW_TABLES = (
'app.models.instruction_fetch.InstructionFetchJob',
'app.models.api_call.BricksetApiCall',
)
def ensure_schema(app):