From 9d96006eae22730f542b8a52c35bf8af0c048198 Mon Sep 17 00:00:00 2001 From: cproudlock Date: Wed, 26 Aug 2026 15:05:43 -0400 Subject: [PATCH] Audit log retention: a way to purge, off by default The audit log is append-only and nothing ever removed a row, so it grows for as long as a site runs. This site reached tens of thousands of pages, which is past the point of being useful: nobody pages through that to find anything. Retention is OPT-IN and the default keeps everything. An upgrade that silently started deleting a site's audit history would be indefensible, so audit_retentiondays defaults to 0 and nothing is removed until somebody sets a number. The Site & Facility card shows the log's size and exactly how many entries a purge would delete BEFORE anything is pressed. Deleting happens in committed batches. That is not an optimisation: one DELETE over a million rows builds a single enormous transaction and holds locks across the table while it runs, which on this server means blocking the collectors posting inventory. The API caps its batch count so the request cannot outlive a proxy timeout, and a run that stops early reports how much is left rather than claiming it finished - a purge reporting success over 900k remaining rows would be the same silent half-failure this codebase keeps getting bitten by. `flask audit stats` and `flask audit purge` for the server, the latter reporting by default and deleting only with --apply, with no batch cap because it is not behind a proxy and a purge that stops halfway leaves the operator guessing. audit.purge is a separate permission from audit.view. Reading the log and destroying it are different acts, and plenty of people need only the first. Chunking selects a page of ids and deletes those rather than using DELETE ... LIMIT, which is MySQL-only while the suite runs on SQLite. --- frontend/src/views/settings/SiteSettings.vue | 107 ++++++++++++++- shopdb/__init__.py | 3 +- shopdb/cli/__init__.py | 72 ++++++++++ shopdb/core/api/auditlogs.py | 74 +++++++++- shopdb/core/api/settings.py | 7 + shopdb/core/models/user.py | 3 + shopdb/core/services/auditretention.py | 133 ++++++++++++++++++ tests/test_core/test_audit_retention.py | 135 +++++++++++++++++++ 8 files changed, 530 insertions(+), 4 deletions(-) create mode 100644 shopdb/core/services/auditretention.py create mode 100644 tests/test_core/test_audit_retention.py diff --git a/frontend/src/views/settings/SiteSettings.vue b/frontend/src/views/settings/SiteSettings.vue index 77a77221..09723667 100644 --- a/frontend/src/views/settings/SiteSettings.vue +++ b/frontend/src/views/settings/SiteSettings.vue @@ -35,12 +35,55 @@ + + +
+

Audit Log Size

+
Loading...
+
{{ audit.error }}
+ +
diff --git a/shopdb/__init__.py b/shopdb/__init__.py index 69883c03..66f3fb30 100644 --- a/shopdb/__init__.py +++ b/shopdb/__init__.py @@ -244,7 +244,7 @@ def register_cli_commands(app: Flask): """Register Flask CLI commands.""" from .plugins.cli import plugin_cli from .cli import (db_cli, seed_cli, relationships_cli, csv_cli, - catalog_cli) + catalog_cli, audit_cli) app.cli.add_command(plugin_cli) app.cli.add_command(db_cli) @@ -252,6 +252,7 @@ def register_cli_commands(app: Flask): app.cli.add_command(relationships_cli) app.cli.add_command(csv_cli) app.cli.add_command(catalog_cli) + app.cli.add_command(audit_cli) def register_error_handlers(app: Flask): diff --git a/shopdb/cli/__init__.py b/shopdb/cli/__init__.py index 460c5561..35d36cd5 100644 --- a/shopdb/cli/__init__.py +++ b/shopdb/cli/__init__.py @@ -1835,3 +1835,75 @@ def catalog_rename(table, source, target, apply_changes): {'t': target, 'k': sourcerow[0]}) click.echo(click.style(f'Renamed {source!r} to {target!r}.', fg='green')) + + +@click.group('audit') +def audit_cli(): + """Audit log maintenance.""" + pass + + +@audit_cli.command('stats') +@with_appcontext +def audit_stats(): + """Show how big the audit log is and what retention is configured.""" + from shopdb.core.services import auditretention + + days = auditretention.configureddays() + info = auditretention.stats(days or None) + + click.echo(f"Entries: {info['total']:,}") + click.echo(f"Oldest: {info['oldest'] or '-'}") + click.echo(f"Newest: {info['newest'] or '-'}") + if days: + click.echo(f"Retention: {days} days") + click.echo(f"Expired: {info['expired']:,} entry(s) older than that") + else: + click.echo('Retention: not set - nothing is ever deleted') + click.echo("Set one in Settings > Site & Facility, or pass --days here.") + + +@audit_cli.command('purge') +@click.option('--days', type=int, default=None, + help='Override the configured retention for this run.') +@click.option('--apply', 'apply_changes', is_flag=True, + help='Actually delete. Without this the command only reports.') +@with_appcontext +def audit_purge(days, apply_changes): + """Delete audit entries older than the retention window. + + Reports by default and deletes only with --apply, because this is the one + command in the app that destroys history a site may be keeping deliberately. + """ + from shopdb.core.services import auditretention + + days = days if days is not None else auditretention.configureddays() + if not days: + click.echo(click.style( + 'No retention configured, so there is nothing to purge. Set ' + 'audit_retentiondays in Settings > Site & Facility, or pass --days.', + fg='yellow')) + return + + preview = auditretention.purge(days, dryrun=True) + click.echo(f"Retention {days} days - cutoff {preview['cutoff']}") + click.echo(f"{preview['matched']:,} entry(s) are older than that.") + + if not preview['matched']: + return + if not apply_changes: + click.echo(click.style( + 'Dry run. Nothing was deleted. Re-run with --apply to write.', + fg='yellow')) + return + + # No batch cap here: unlike the API this is not behind a proxy timeout, and + # a purge that stops halfway leaves the operator wondering which half. + result = auditretention.purge(days) + click.echo(click.style( + f"Deleted {result['deleted']:,} entry(s) in {result['batches']} batch(es).", + fg='green')) + if not result['complete']: + click.echo(click.style( + f"{result['remaining']:,} still older than the cutoff - re-run.", + fg='yellow')) diff --git a/shopdb/core/api/auditlogs.py b/shopdb/core/api/auditlogs.py index fca6ec06..b8e087e6 100644 --- a/shopdb/core/api/auditlogs.py +++ b/shopdb/core/api/auditlogs.py @@ -4,7 +4,8 @@ from flask import Blueprint, request from flask_jwt_extended import jwt_required from shopdb.core.models import AuditLog -from shopdb.utils.responses import success_response +from shopdb.extensions import db +from shopdb.utils.responses import success_response, error_response, ErrorCodes from shopdb.utils.authz import require_permission auditlogs_bp = Blueprint('auditlogs', __name__) @@ -194,3 +195,74 @@ def db_func_count_by(column): ).group_by(column).all() return {r[0]: r[1] for r in results} + + +@auditlogs_bp.route('/retention', methods=['GET']) +@jwt_required() +@require_permission('audit.view') +def get_retention(): + """Size of the log and what the configured retention would remove. + + Drives the Site & Facility card: an admin should see the number of entries a + purge deletes BEFORE pressing anything. + """ + from shopdb.core.services import auditretention + days = auditretention.configureddays() + return success_response(auditretention.stats(days or None)) + + +@auditlogs_bp.route('/purge', methods=['POST']) +@jwt_required() +@require_permission('audit.purge') +def purge_auditlogs(): + """Delete entries older than the retention window. + + Separate permission from audit.view: reading the log and destroying it are + not the same act, and plenty of people need the first. + + Batch-capped, because this runs inside a request that a proxy will time out. + An incomplete purge returns complete=false and the number still to go rather + than reporting a finished job - the caller re-posts, or runs + `flask audit purge --apply` on the server, which has no cap. + """ + from flask import request as flask_request + from shopdb.core.services import auditretention + + body = flask_request.get_json(silent=True) or {} + days = body.get('days') + if days is None: + days = auditretention.configureddays() + try: + days = int(days) + except (TypeError, ValueError): + days = 0 + if days <= 0: + return error_response( + ErrorCodes.VALIDATION_ERROR, + 'No retention period is configured. Set one in Site & Facility ' + 'settings before purging.') + + dryrun = bool(body.get('dryrun')) + result = auditretention.purge( + days, dryrun=dryrun, + maxbatches=None if dryrun else auditretention.MAXBATCHES_REQUEST) + + if dryrun: + message = '{:,} entry(s) would be deleted'.format(result['matched']) + elif result['complete']: + message = 'Deleted {:,} entry(s)'.format(result['deleted']) + else: + message = ('Deleted {:,} entry(s); {:,} still older than the cutoff. ' + 'Run it again to continue.').format( + result['deleted'], result['remaining']) + + # The purge is itself an audited act, and this row postdates the cutoff so + # it survives the purge that created it. + if not dryrun and result['deleted']: + from shopdb.api import audit_log + audit_log(action='deleted', entitytype='AuditLog', + entityname='purge older than {} days'.format(days), + changes={'deleted': result['deleted'], + 'cutoff': result['cutoff']}) + + return success_response(result, message=message) diff --git a/shopdb/core/api/settings.py b/shopdb/core/api/settings.py index 66b4ad01..07ded6b1 100644 --- a/shopdb/core/api/settings.py +++ b/shopdb/core/api/settings.py @@ -522,6 +522,13 @@ def build_default_settings(): 'category': 'site', 'description': 'Public base URL of this site INCLUDING any subpath it is served under, e.g. https://shopdb.example.net or https://host/shopdb. Consumers append the in-app route to this and add nothing themselves, so a subpath left off here produces links that 404. Blank = use the browsing origin.' }, + { + 'key': 'audit_retentiondays', + 'value': '0', + 'valuetype': 'integer', + 'category': 'site', + 'description': 'Delete audit log entries older than this many days. 0 (default) keeps everything forever. The audit log is append-only and grows for as long as the site runs, so a long-lived site eventually needs a limit here; nothing is deleted until one is set, and the settings page shows how many entries a purge would remove before it runs.' + }, { 'key': 'facility_name', 'value': '', diff --git a/shopdb/core/models/user.py b/shopdb/core/models/user.py index 7e2b6351..906f45fb 100644 --- a/shopdb/core/models/user.py +++ b/shopdb/core/models/user.py @@ -62,6 +62,9 @@ class Permission(db.Model): ('users.delete', 'Delete users', 'admin'), # Audit ('audit.view', 'View audit logs', 'admin'), + # Deliberately separate from audit.view: reading the log and destroying + # history are different acts, and many people need only the first. + ('audit.purge', 'Delete audit log entries past the retention period', 'admin'), # API tokens ('apitokens.create', 'Create and manage API tokens', 'apitokens'), # Collector service tokens. A token scoped to ONLY this permission is a diff --git a/shopdb/core/services/auditretention.py b/shopdb/core/services/auditretention.py new file mode 100644 index 00000000..e6ef66ab --- /dev/null +++ b/shopdb/core/services/auditretention.py @@ -0,0 +1,133 @@ +"""Audit log retention. + +The audit log is append-only and nothing ever removed a row, so it grows for as +long as a site runs. That is fine for a year and not fine forever: this site +reached the point where the log is most of the database and the audit page is +tens of thousands of pages deep - which also makes it useless, because nobody +pages through that to find anything. + +Retention is OPT-IN, and the default keeps everything. An upgrade that silently +started deleting a site's audit history would be indefensible; a site that wants +a limit sets one, and is told exactly how many rows that will remove before it +happens. + +DELETING IN CHUNKS IS NOT AN OPTIMISATION. A single +`DELETE FROM auditlogs WHERE timestamp < ...` over a million rows builds one +enormous transaction, holds locks across the table for the duration, and on a +modest MySQL box either times out or blocks every writer while it runs - which +on this server means the collectors that are posting inventory. Deleting in +bounded batches, committing each, keeps every individual statement short. + +Chunking is done by SELECTing a page of ids and deleting those. `DELETE ... LIMIT` +would be simpler but is MySQL-only, and the test suite runs on SQLite. +""" + +from datetime import datetime, timedelta, timezone + +from shopdb.extensions import db +from shopdb.core.models import AuditLog + + +# Big enough that a large purge does not take thousands of round trips, small +# enough that one statement stays short and a kill mid-purge loses little work. +CHUNKSIZE = 5000 + +# A purge triggered from the browser must not run until a proxy gives up on it. +# The CLI has no such limit and passes None. +MAXBATCHES_REQUEST = 40 + + +def _utcnow(): + return datetime.now(timezone.utc).replace(tzinfo=None) + + +def cutofffor(days): + """The timestamp before which rows are older than the retention window.""" + return _utcnow() - timedelta(days=int(days)) + + +def stats(days=None): + """Row count, date range, and how many rows a purge at `days` would remove. + + Cheap enough to render on a settings page: three aggregates over an indexed + column. + """ + total = db.session.query(db.func.count(AuditLog.auditlogid)).scalar() or 0 + oldest, newest = db.session.query( + db.func.min(AuditLog.timestamp), db.func.max(AuditLog.timestamp)).first() + + expired = None + if days: + expired = (db.session.query(db.func.count(AuditLog.auditlogid)) + .filter(AuditLog.timestamp < cutofffor(days)).scalar() or 0) + + return { + 'total': total, + 'oldest': oldest.isoformat() if oldest else None, + 'newest': newest.isoformat() if newest else None, + 'retentiondays': int(days) if days else 0, + 'expired': expired, + } + + +def purge(days, dryrun=False, maxbatches=None, chunksize=CHUNKSIZE): + """Delete audit rows older than `days`, in committed batches. + + Returns a dict describing what happened, including `remaining`: a purge that + stopped early because it hit `maxbatches` says so rather than reporting + success over a job it did not finish. A caller that reported "purged" while + 900k rows were still there would be exactly the kind of quiet half-failure + this codebase keeps getting bitten by. + """ + days = int(days or 0) + if days <= 0: + raise ValueError('retention must be a positive number of days; ' + '0 means keep everything, which is not a purge') + + cutoff = cutofffor(days) + matched = (db.session.query(db.func.count(AuditLog.auditlogid)) + .filter(AuditLog.timestamp < cutoff).scalar() or 0) + + if dryrun or not matched: + return {'cutoff': cutoff.isoformat(), 'matched': matched, 'deleted': 0, + 'remaining': matched, 'batches': 0, 'dryrun': bool(dryrun), + 'complete': not matched} + + deleted = 0 + batches = 0 + while True: + if maxbatches is not None and batches >= maxbatches: + break + ids = [row[0] for row in + db.session.query(AuditLog.auditlogid) + .filter(AuditLog.timestamp < cutoff) + .order_by(AuditLog.auditlogid) + .limit(chunksize).all()] + if not ids: + break + (db.session.query(AuditLog) + .filter(AuditLog.auditlogid.in_(ids)) + .delete(synchronize_session=False)) + db.session.commit() + deleted += len(ids) + batches += 1 + + remaining = (db.session.query(db.func.count(AuditLog.auditlogid)) + .filter(AuditLog.timestamp < cutoff).scalar() or 0) + + return {'cutoff': cutoff.isoformat(), 'matched': matched, 'deleted': deleted, + 'remaining': remaining, 'batches': batches, 'dryrun': False, + 'complete': remaining == 0} + + +def configureddays(): + """The site's retention setting, or 0 when nothing is set (keep forever).""" + from shopdb.core.models import Setting + try: + raw = Setting.get('audit_retentiondays') + except Exception: + return 0 + try: + return max(0, int(raw or 0)) + except (TypeError, ValueError): + return 0 diff --git a/tests/test_core/test_audit_retention.py b/tests/test_core/test_audit_retention.py new file mode 100644 index 00000000..d08b6e37 --- /dev/null +++ b/tests/test_core/test_audit_retention.py @@ -0,0 +1,135 @@ +"""Audit retention: the purge, its default, and its refusal to overreach. + +The audit log is the one table in this app where deleting is the FEATURE, which +makes every guard here load-bearing. A retention bug does not corrupt data, it +destroys history nobody can get back. +""" + +from datetime import datetime, timedelta, timezone + +import pytest + +from shopdb.core.models import AuditLog +from shopdb.core.services import auditretention + + +def _utcnow(): + return datetime.now(timezone.utc).replace(tzinfo=None) + + +def _entry(db, ageindays, action='updated'): + row = AuditLog(action=action, entitytype='Machine', entityname='M-1', + timestamp=_utcnow() - timedelta(days=ageindays)) + db.session.add(row) + db.session.commit() + return row + + +def test_nothing_is_deleted_when_no_retention_is_configured(db): + """The default must keep everything. + + An upgrade that started silently deleting a site's audit history because a + setting defaulted to 90 days would be indefensible. + """ + _entry(db, 4000) + assert auditretention.configureddays() == 0 + with pytest.raises(ValueError): + auditretention.purge(0) + assert AuditLog.query.count() == 1 + + +def test_a_purge_deletes_only_what_is_older_than_the_window(db): + _entry(db, 400) + _entry(db, 100) + keeper = _entry(db, 5) + + result = auditretention.purge(90) + + assert result['deleted'] == 2 + assert result['complete'] is True + assert [row.auditlogid for row in AuditLog.query.all()] == [keeper.auditlogid] + + +def test_a_dry_run_reports_without_deleting(db): + _entry(db, 400) + _entry(db, 400) + + result = auditretention.purge(90, dryrun=True) + + assert result['matched'] == 2 + assert result['deleted'] == 0 + assert AuditLog.query.count() == 2, 'a dry run that deleted would be a trap' + + +def test_a_capped_purge_says_it_did_not_finish(db): + """A half-done purge must not report success. + + The API caps batches so the request cannot outlive a proxy timeout. If that + path reported a finished job, an admin would believe a log was trimmed while + most of it was still there. + """ + for _ in range(5): + _entry(db, 400) + + result = auditretention.purge(90, maxbatches=2, chunksize=1) + + assert result['deleted'] == 2 + assert result['remaining'] == 3 + assert result['complete'] is False + + +def test_chunking_deletes_everything_it_matched(db): + """Batching is an implementation detail; the outcome must not depend on it.""" + for _ in range(7): + _entry(db, 400) + + result = auditretention.purge(90, chunksize=2) + + assert result['deleted'] == 7 + assert result['complete'] is True + assert AuditLog.query.count() == 0 + + +def test_stats_report_the_backlog_a_purge_would_remove(db): + _entry(db, 400) + _entry(db, 5) + + info = auditretention.stats(90) + + assert info['total'] == 2 + assert info['expired'] == 1 + assert info['oldest'] is not None + + +def test_purging_requires_its_own_permission(client, db, auth_headers): + """audit.view is not permission to destroy the log.""" + from werkzeug.security import generate_password_hash + from shopdb.core.models import User, Role, Permission + + perm = Permission(name='audit.view', description='View audit logs', + category='admin') + role = Role(rolename='auditreader', description='Reads the audit log') + role.permissions.append(perm) + db.session.add_all([perm, role]) + db.session.flush() + user = User(username='auditreader', email='ar@test.local', + passwordhash=generate_password_hash('testpass')) + user.roles.append(role) + db.session.add(user) + db.session.commit() + + login = client.post('/api/auth/login', + json={'username': 'auditreader', 'password': 'testpass'}) + headers = {'Authorization': + 'Bearer ' + login.get_json()['data']['access_token']} + + assert client.get('/api/auditlogs/retention', + headers=headers).status_code == 200 + assert client.post('/api/auditlogs/purge', json={'days': 90}, + headers=headers).status_code == 403 + + +def test_the_purge_route_refuses_when_no_retention_is_set(client, db, auth_headers): + response = client.post('/api/auditlogs/purge', json={}, headers=auth_headers) + assert response.status_code == 400 + assert 'retention' in response.get_json()['data']['error']['message'].lower()