From a0553b643570014cb0af9c3f57cb42982bbb1e26 Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Wed, 21 Oct 2026 18:33:53 -0400 Subject: [PATCH 01/15] feat(logs): add asynchronous global purge endpoint Move global log deletion out of the request path so the API can acknowledge scheduling without implying that deletion is complete. - Add a superuser-only global purge endpoint returning HTTP 202 with a job ID and no synchronous deleted count. - Validate retention durations before queueing. Keep CLI --date, default omitted retention to zero, and reject API before_date. - Run purges through purge_log_records. Keep the generic management-command worker for internal callers, while fixing API submissions to the purge command. - Delete logs globally in bounded batches using an initial highest-ID snapshot and report the actual deleted count. - Make audit creation opt-in. Activation IDs and names select audit targets without limiting which logs are deleted. - Use the default queue, a purge-specific timeout, and an advisory lock. Record outcomes and counts in worker results and logs. - Document the API contract, retention and audit behavior, CLI options, and operator guidance for checking job outcomes. Validation: - task lint - Focused purge tests: 50 passed, 6 skipped, 191 warnings. Assisted by: GPT-6 --- docs/development.md | 40 ++ pyproject.toml | 1 + src/aap_eda/api/serializers/__init__.py | 4 + src/aap_eda/api/serializers/activation.py | 43 ++ src/aap_eda/api/urls.py | 1 + src/aap_eda/api/views/__init__.py | 7 +- src/aap_eda/api/views/activation.py | 43 ++ .../management/commands/purge_log_records.py | 176 ++++---- src/aap_eda/core/utils/delete_log_util.py | 125 ++++++ src/aap_eda/core/utils/log_retention.py | 44 ++ src/aap_eda/settings/defaults.py | 3 + src/aap_eda/tasks/management.py | 139 +++++++ tests/integration/api/test_log_purge.py | 107 +++++ tests/integration/api/test_openapi.py | 35 ++ tests/integration/api/test_root.py | 2 + .../commands/test_purge_log_records.py | 387 ++++++++++++++++-- tests/integration/tasks/test_management.py | 199 +++++++++ tests/integration/test_advisory_lock.py | 9 +- 18 files changed, 1252 insertions(+), 113 deletions(-) create mode 100644 src/aap_eda/core/utils/delete_log_util.py create mode 100644 src/aap_eda/core/utils/log_retention.py create mode 100644 src/aap_eda/tasks/management.py create mode 100644 tests/integration/api/test_log_purge.py create mode 100644 tests/integration/tasks/test_management.py diff --git a/docs/development.md b/docs/development.md index d76c991e4..bfef6da29 100644 --- a/docs/development.md +++ b/docs/development.md @@ -461,6 +461,46 @@ task docker:purge && EDA_SECRET_KEY=insecure task docker:up Do **not** confuse the two — see the command docstring in `src/aap_eda/core/management/commands/rotate_db_encryption_key.py`. +## Global log purge + +The global log purge endpoint is `POST /api/eda/v1/logs/purge/`. Only a +superuser can submit it. A successful request returns HTTP 202 with a `job_id`; +this confirms that dispatcherd accepted the job, not that deletion has +completed. The endpoint deletes qualifying log rows across all activations. +Optional `activation_ids` and `activation_names` select audit-trail targets +only; they never limit deletion. Audit entries are disabled by default for +both API and CLI requests. + +```http +POST /api/eda/v1/logs/purge/ +Content-Type: application/json + +{"retention_duration": "P30D", "audit_trail": true, + "activation_names": ["production-rules"]} +``` + +`retention_duration` is an optional ISO 8601 duration such as `P30D` or +`P1M`. If omitted, the worker reads +`ACTIVATION_DB_LOG_RETENTION_DAYS`; its default is `0`, which disables +deletion. Calendar months and years are subtracted in UTC, clamping a day that +does not exist in the target month to that month's final day. The CLI also +supports `--date YYYY-MM-DD` (interpreted as midnight UTC) and +`--retention-duration P30D`; those options are mutually exclusive. The API +does not accept `before_date`. + +Inspect default-worker logs by the returned job ID to see started, completed, +skipped, and failed outcomes, including `deleted_count`: + +```shell +JOB_ID= +kubectl logs -n "${NAMESPACE:-aap-eda}" \ + -l app=eda,comp=default-worker --all-containers=true --since=24h \ + | grep "job_id=${JOB_ID}" +``` + +The dispatcherd `running` view only reports in-flight work; the structured +worker log lines are the supported completion and deletion-count record. + ### Running linters The project uses `flake8` with a set of plugins, `black`, `isort` and `ruff` (experimental), diff --git a/pyproject.toml b/pyproject.toml index 01a6095af..e17dde605 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -68,6 +68,7 @@ pyjwt = { version = ">=2.13.0,<3", extras = ["crypto"] } ecdsa = "0.18.*" validators = "^0.34.0" django-flags = "^5.0.13" +isodate = "^0.7.2" insights-analytics-collector = "^0.3.2" distro = "^1.9.0" dispatcherd = { version = "v2026.05.27", extras = ["pg_notify"] } diff --git a/src/aap_eda/api/serializers/__init__.py b/src/aap_eda/api/serializers/__init__.py index 9c072c486..ae760392b 100644 --- a/src/aap_eda/api/serializers/__init__.py +++ b/src/aap_eda/api/serializers/__init__.py @@ -21,6 +21,8 @@ ActivationReadSerializer, ActivationSerializer, ActivationUpdateSerializer, + LogPurgeRequestSerializer, + LogPurgeResponseSerializer, PostActivationSerializer, ) from .auth import JWTTokenSerializer, LoginSerializer, RefreshTokenSerializer @@ -114,6 +116,8 @@ "ActivationListSerializer", "ActivationCreateSerializer", "ActivationUpdateSerializer", + "LogPurgeRequestSerializer", + "LogPurgeResponseSerializer", "ActivationReadSerializer", "ActivationCopySerializer", "ActivationInstanceSerializer", diff --git a/src/aap_eda/api/serializers/activation.py b/src/aap_eda/api/serializers/activation.py index 069018994..8781c96ce 100644 --- a/src/aap_eda/api/serializers/activation.py +++ b/src/aap_eda/api/serializers/activation.py @@ -55,6 +55,7 @@ get_secret_fields, ) from aap_eda.core.utils.k8s_service_name import create_k8s_service_name +from aap_eda.core.utils.log_retention import retention_cutoff from aap_eda.core.utils.rulebook import ( build_rulebook_with_event_streams, build_source_list, @@ -89,6 +90,48 @@ def _update_event_stream_source(validated_data: dict) -> str: raise InvalidEventStreamSource(e) from e +class LogPurgeRequestSerializer(serializers.Serializer): + """Validate a global log purge request.""" + + retention_duration = serializers.CharField(required=False) + audit_trail = serializers.BooleanField(required=False, default=False) + activation_ids = serializers.ListField( + child=serializers.IntegerField(min_value=1), + required=False, + allow_empty=False, + ) + activation_names = serializers.ListField( + child=serializers.CharField(allow_blank=False), + required=False, + allow_empty=False, + ) + + def validate(self, attrs): + if "before_date" in self.initial_data: + raise serializers.ValidationError( + {"before_date": "This field is not supported."} + ) + if any(not name.strip() for name in attrs.get("activation_names", [])): + raise serializers.ValidationError( + {"activation_names": "Names cannot be blank."} + ) + duration = attrs.get("retention_duration") + if duration is not None: + try: + retention_cutoff(duration) + except ValueError as exc: + raise serializers.ValidationError( + {"retention_duration": str(exc)} + ) from exc + return attrs + + +class LogPurgeResponseSerializer(serializers.Serializer): + """Acknowledgement returned after a purge task is queued.""" + + job_id = serializers.UUIDField() + + def _update_k8s_service_name(validated_data: dict) -> str: service_name = validated_data.get("k8s_service_name") return service_name or create_k8s_service_name(validated_data["name"]) diff --git a/src/aap_eda/api/urls.py b/src/aap_eda/api/urls.py index 83c673d29..555104de6 100644 --- a/src/aap_eda/api/urls.py +++ b/src/aap_eda/api/urls.py @@ -37,6 +37,7 @@ router.register("projects", views.ProjectViewSet) router.register("rulebooks", views.RulebookViewSet) router.register("activations", views.ActivationViewSet) +router.register("logs", views.LogPurgeViewSet, basename="logs") router.register( "activation-instances", views.ActivationInstanceViewSet, diff --git a/src/aap_eda/api/views/__init__.py b/src/aap_eda/api/views/__init__.py index 3b61fdf77..ab76d81d2 100644 --- a/src/aap_eda/api/views/__init__.py +++ b/src/aap_eda/api/views/__init__.py @@ -12,7 +12,11 @@ # See the License for the specific language governing permissions and # limitations under the License. -from .activation import ActivationInstanceViewSet, ActivationViewSet +from .activation import ( + ActivationInstanceViewSet, + ActivationViewSet, + LogPurgeViewSet, +) from .auth import SessionLoginView, SessionLogoutView, TokenRefreshView from .config import ConfigView from .credential_input_source import CredentialInputSourceViewSet @@ -40,6 +44,7 @@ # activations "ActivationViewSet", "ActivationInstanceViewSet", + "LogPurgeViewSet", # user "CurrentUserView", "CurrentUserAwxTokenViewSet", diff --git a/src/aap_eda/api/views/activation.py b/src/aap_eda/api/views/activation.py index 357f7580e..da65e2d89 100644 --- a/src/aap_eda/api/views/activation.py +++ b/src/aap_eda/api/views/activation.py @@ -31,11 +31,13 @@ from rest_framework.response import Response from aap_eda.api import exceptions as api_exc, filters, serializers +from aap_eda.api.permissions import IsSystemAdmin from aap_eda.api.serializers.activation import is_activation_valid from aap_eda.core import models from aap_eda.core.enums import Action, ActivationStatus, ProcessParentType from aap_eda.core.health import check_dispatcherd_workers_health from aap_eda.core.utils import logging_utils +from aap_eda.tasks.management import submit_log_purge from aap_eda.tasks.orchestrator import ( delete_rulebook_process, restart_rulebook_process, @@ -868,3 +870,44 @@ def logs(self, request, id): results, many=True ) return self.get_paginated_response(serializer.data) + + +class LogPurgeViewSet(viewsets.GenericViewSet): + """Global, superuser-only log purge scheduling endpoint.""" + + permission_classes = (IsSystemAdmin,) + serializer_class = serializers.LogPurgeRequestSerializer + + @extend_schema( + description=( + "Queue a global deletion of old activation logs. The activation " + "IDs and names select audit-trail targets only. The returned job " + "ID acknowledges scheduling; it does not mean deletion is done." + ), + request=serializers.LogPurgeRequestSerializer, + responses={ + status.HTTP_202_ACCEPTED: serializers.LogPurgeResponseSerializer, + status.HTTP_400_BAD_REQUEST: OpenApiResponse( + description="The request contains invalid purge options." + ), + status.HTTP_403_FORBIDDEN: OpenApiResponse( + description="Only superusers can queue a log purge." + ), + status.HTTP_500_INTERNAL_SERVER_ERROR: OpenApiResponse( + description="The purge task could not be queued." + ), + }, + ) + @action(methods=["post"], detail=False, url_path="purge") + def purge(self, request): + serializer = self.get_serializer(data=request.data) + serializer.is_valid(raise_exception=True) + try: + job_id = submit_log_purge(**serializer.validated_data) + except Exception: + logger.exception("Unable to queue global log purge") + return Response( + {"detail": "Unable to queue log purge job."}, + status=status.HTTP_500_INTERNAL_SERVER_ERROR, + ) + return Response({"job_id": job_id}, status=status.HTTP_202_ACCEPTED) diff --git a/src/aap_eda/core/management/commands/purge_log_records.py b/src/aap_eda/core/management/commands/purge_log_records.py index deb5d8173..dd02881f1 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -12,21 +12,25 @@ # See the License for the specific language governing permissions and # limitations under the License. -from datetime import datetime +from datetime import datetime, time, timedelta, timezone +from django.conf import settings from django.core.management.base import ( BaseCommand, CommandError, CommandParser, ) -from django.db import transaction -from django.db.models import Q -from aap_eda.core import models +from aap_eda.core.utils.delete_log_util import ( + LogPurgeError, + create_audit_trail, + delete_logs_older_than, +) +from aap_eda.core.utils.log_retention import retention_cutoff class Command(BaseCommand): - """Purge the logs from a rulebook process.""" + """Purge old logs globally, optionally writing audit trail entries.""" help = ( "Purge log records from rulebook processes. " @@ -63,100 +67,100 @@ def add_arguments(self, parser: CommandParser) -> None: "--date", dest="date", action="store", - required=True, help=( "Purge records older than this date from the database. " - "The cutoff date in YYYY-MM-DD format" + "The UTC cutoff date in YYYY-MM-DD format. Mutually exclusive " + "with --retention-duration." ), ) - def purge_log_records( - self, ids: list[int], names: list[str], cutoff_timestamp: datetime - ) -> None: - # Global purge of all old logs (regardless of activation) - cutoff_ts = int(cutoff_timestamp.timestamp()) - old_logs = models.RulebookProcessLog.objects.filter( - log_timestamp__lt=cutoff_ts + parser.add_argument( + "--retention-duration", + dest="retention_duration", + help=( + "Purge records older than this ISO 8601 duration, for " + "example P30D or P1M. Mutually exclusive with --date." + ), ) - deleted_count = old_logs.count() - - if deleted_count == 0: - self.stdout.write( - self.style.SUCCESS( - f"No log records found older than " - f"{cutoff_timestamp.strftime('%Y-%m-%d')}." - ) - ) - return - - # Delete all old logs globally - old_logs.delete() - - self.stdout.write( - self.style.SUCCESS( - f"Purged {deleted_count} log records older than " - f"{cutoff_timestamp.strftime('%Y-%m-%d')} globally." - ) + parser.add_argument( + "--audit-trail", + dest="audit_trail", + action="store_true", + help="Create audit log entries for affected processes.", ) - # Create audit trail logs for reporting - audit_logs = [] - - if not bool(ids) and not bool(names): - # No filters: Create audit logs for all instances that might - # have been affected - instances = models.RulebookProcess.objects.all() - else: - # Filters provided: Create audit logs only for specified - # activations and orphaned records - instances = models.RulebookProcess.objects.filter( - Q(activation__id__in=ids) - | Q(activation__name__in=names) - | Q(activation__isnull=True), - ) - - # Report on orphaned records for user visibility - orphaned_count = models.RulebookProcess.objects.filter( - activation__isnull=True - ).count() - if orphaned_count > 0: - self.stdout.write( - f"Audit trail will include {orphaned_count} orphaned " - f"RulebookProcess records (with NULL activation)." - ) - - # Create audit trail logs for instances - dt = datetime.now().strftime("%Y-%m-%d %H:%M:%S") - for instance in instances: - audit_logs.append( - models.RulebookProcessLog( - log=( - f"All log records older than " - f"{cutoff_timestamp.strftime('%Y-%m-%d')} " - f"were purged at {dt}." - ), - activation_instance_id=instance.id, - log_timestamp=cutoff_ts, - ) + @staticmethod + def _cutoff(options: dict) -> datetime | None: + cutoff_date = options.get("date") + retention_duration = options.get("retention_duration") + if cutoff_date is not None and retention_duration is not None: + raise CommandError( + "--date and --retention-duration are mutually exclusive." ) - if audit_logs: - models.RulebookProcessLog.objects.bulk_create(audit_logs) - self.stdout.write( - f"Created {len(audit_logs)} audit trail log entries." - ) + if cutoff_date is not None: + try: + parsed_date = datetime.strptime(cutoff_date, "%Y-%m-%d").date() + except (TypeError, ValueError) as exc: + raise CommandError( + "--date must use YYYY-MM-DD format." + ) from exc + if parsed_date.strftime("%Y-%m-%d") != cutoff_date: + raise CommandError("--date must use YYYY-MM-DD format.") + return datetime.combine(parsed_date, time.min, tzinfo=timezone.utc) + + if retention_duration is not None: + try: + return retention_cutoff(retention_duration) + except ValueError as exc: + raise CommandError(str(exc)) from exc + + retention_days = settings.ACTIVATION_DB_LOG_RETENTION_DAYS + if retention_days <= 0: + return None + return datetime.now(timezone.utc) - timedelta(days=retention_days) - @transaction.atomic def handle(self, *args, **options): - input_ids = options.get("activation-ids") or [] - input_names = options.get("activation-names") or [] - cutoff_date = options.get("date") + ids = options.get("activation-ids") or [] + names = options.get("activation-names") or [] + if any(activation_id <= 0 for activation_id in ids): + raise CommandError("Activation IDs must be positive integers.") + if any(not name.strip() for name in names): + raise CommandError("Activation names cannot be blank.") + + cutoff = self._cutoff(options) + if cutoff is None: + return self.style.WARNING( + "No logs purged: configured retention is not positive." + ) try: - ts = datetime.strptime(cutoff_date, "%Y-%m-%d") - except ValueError as e: - raise CommandError(f"{e}") from e + deleted_count = delete_logs_older_than(cutoff) + except LogPurgeError as exc: + raise CommandError(str(exc)) from exc + + if deleted_count == 0: + return self.style.SUCCESS( + f"No log records found older than " + f"{cutoff.strftime('%Y-%m-%d %H:%M:%S UTC')}; 0 rows " + "deleted." + ) - self.purge_log_records( - ids=input_ids, names=input_names, cutoff_timestamp=ts + output = ( + f"Purged {deleted_count} log records older than " + f"{cutoff.strftime('%Y-%m-%d %H:%M:%S UTC')} globally." ) + if options.get("audit_trail"): + try: + audit_count = create_audit_trail( + cutoff, + activation_ids=ids, + activation_names=names, + ) + except Exception as exc: + raise CommandError( + f"Deleted {deleted_count} logs, but audit trail failed: " + f"{exc}" + ) from exc + output += f" Created {audit_count} audit trail entries." + return self.style.SUCCESS(output) diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py new file mode 100644 index 000000000..840be3460 --- /dev/null +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -0,0 +1,125 @@ +# Copyright 2026 Red Hat, Inc. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +from datetime import datetime + +from django.db import transaction +from django.db.models import Max, Q +from django.utils import timezone + +from aap_eda.core import models + +DELETE_BATCH_SIZE = 1000 + + +class LogPurgeError(Exception): + """A purge failure that includes the number of committed deletions.""" + + def __init__(self, message: str, deleted_count: int): + self.deleted_count = deleted_count + super().__init__(message) + + +def delete_logs_older_than(cutoff: datetime) -> int: + """Delete old logs globally in committed batches up to a fixed ID.""" + cutoff_timestamp = cutoff.timestamp() + qualifying = models.RulebookProcessLog.objects.filter( + log_timestamp__lt=cutoff_timestamp + ) + max_id = qualifying.aggregate(max_id=Max("id"))["max_id"] + if max_id is None: + return 0 + + deleted_count = 0 + last_id = 0 + model_label = models.RulebookProcessLog._meta.label + try: + while last_id < max_id: + batch_ids = list( + qualifying.filter(id__gt=last_id, id__lte=max_id) + .order_by("id") + .values_list("id", flat=True)[:DELETE_BATCH_SIZE] + ) + if not batch_ids: + break + with transaction.atomic(): + _, deleted_by_model = models.RulebookProcessLog.objects.filter( + id__in=batch_ids, + log_timestamp__lt=cutoff_timestamp, + ).delete() + deleted_count += deleted_by_model.get(model_label, 0) + last_id = batch_ids[-1] + except Exception as exc: + raise LogPurgeError( + f"Log deletion failed after {deleted_count} committed rows: {exc}", + deleted_count, + ) from exc + return deleted_count + + +def create_audit_trail( + cutoff: datetime, + *, + activation_ids: list[int] | None = None, + activation_names: list[str] | None = None, +) -> int: + """Create opt-in audit logs for all or selected activation processes.""" + instances = models.RulebookProcess.objects.all() + if activation_ids or activation_names: + instances = instances.filter( + Q(activation_id__in=activation_ids or []) + | Q(activation__name__in=activation_names or []) + | Q(activation__isnull=True) + ) + + max_id = instances.aggregate(max_id=Max("id"))["max_id"] + if max_id is None: + return 0 + + now = timezone.now() + cutoff_text = cutoff.strftime("%Y-%m-%d %H:%M:%S UTC") + audit_text = ( + f"All log records older than {cutoff_text} were purged at " + f"{now.strftime('%Y-%m-%d %H:%M:%S UTC')}." + ) + created = 0 + last_id = 0 + while last_id < max_id: + ids = list( + instances.filter(id__gt=last_id, id__lte=max_id) + .order_by("id") + .values_list("id", flat=True)[:DELETE_BATCH_SIZE] + ) + if not ids: + break + try: + with transaction.atomic(): + batch = [ + models.RulebookProcessLog( + log=audit_text, + activation_instance_id=instance_id, + log_timestamp=int(now.timestamp()), + ) + for instance_id in ids + ] + models.RulebookProcessLog.objects.bulk_create(batch) + created += len(batch) + last_id = ids[-1] + except Exception as exc: + raise LogPurgeError( + f"Audit trail creation failed after deleting logs; " + f"{created} audit rows were committed: {exc}", + 0, + ) from exc + return created diff --git a/src/aap_eda/core/utils/log_retention.py b/src/aap_eda/core/utils/log_retention.py new file mode 100644 index 000000000..e49a4bd17 --- /dev/null +++ b/src/aap_eda/core/utils/log_retention.py @@ -0,0 +1,44 @@ +# Copyright 2026 Red Hat, Inc. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +from datetime import datetime, timezone as datetime_timezone + +import isodate + + +def retention_cutoff( + duration: str, *, now: datetime | None = None +) -> datetime: + """Return the UTC cutoff for a positive ISO 8601 duration. + + Calendar months and years use ``isodate.Duration`` subtraction semantics: + the month is shifted and the day is clamped to that month's last day. + Other duration components are subtracted as elapsed time. + """ + now = now or datetime.now(datetime_timezone.utc) + if now.tzinfo is None or now.utcoffset() is None: + raise ValueError("The current time must be timezone-aware.") + now = now.astimezone(datetime_timezone.utc) + + try: + parsed = isodate.parse_duration(duration) + cutoff = now - parsed + except (TypeError, ValueError, OverflowError) as exc: + raise ValueError( + "retention_duration must be a valid ISO 8601 duration." + ) from exc + + if cutoff >= now: + raise ValueError("retention_duration must produce a past cutoff.") + return cutoff diff --git a/src/aap_eda/settings/defaults.py b/src/aap_eda/settings/defaults.py index b3c1a44fb..478fe6c4b 100644 --- a/src/aap_eda/settings/defaults.py +++ b/src/aap_eda/settings/defaults.py @@ -161,6 +161,9 @@ RULEBOOK_QUEUE_NAME: str = "activation" +# Nonpositive values disable scheduled/default log deletion. +ACTIVATION_DB_LOG_RETENTION_DAYS: int = 0 + API_PREFIX: str = "api/eda" APP_LOG_LEVEL: str = "INFO" diff --git a/src/aap_eda/tasks/management.py b/src/aap_eda/tasks/management.py new file mode 100644 index 000000000..eb4f52008 --- /dev/null +++ b/src/aap_eda/tasks/management.py @@ -0,0 +1,139 @@ +# Copyright 2026 Red Hat, Inc. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import logging +import re +from uuid import uuid4 + +from ansible_base.lib.utils.db import advisory_lock +from dispatcherd.publish import submit_task +from django.conf import settings +from django.core.management import call_command + +from aap_eda import utils + +logger = logging.getLogger(__name__) + +MANAGEMENT_TASKS_QUEUE = "default" +LOG_PURGE_TASK_TIMEOUT_SECONDS = 3600 +_DELETED_COUNT = re.compile(r"^Purged (\d+) log records") + + +def submit_log_purge( + *, + retention_duration: str | None = None, + audit_trail: bool = False, + activation_ids: list[int] | None = None, + activation_names: list[str] | None = None, +) -> str: + """Submit a fixed-purpose global log purge task.""" + command_options = {} + if retention_duration is not None: + command_options["retention_duration"] = retention_duration + if audit_trail: + command_options["audit_trail"] = True + if activation_ids: + command_options["activation-ids"] = activation_ids + if activation_names: + command_options["activation-names"] = activation_names + + return aap_eda_manage_commands( + "purge_log_records", + timeout=LOG_PURGE_TASK_TIMEOUT_SECONDS, + **command_options, + ) + + +def aap_eda_manage_commands( + command: str, *, timeout: int | None = None, **command_options +) -> str: + """Submit a Django management command to the default worker queue. + + The API uses ``submit_log_purge`` so its request cannot choose a command. + This generic entry point remains available to internal callers. + """ + job_id = str(uuid4()) + job_data, _ = submit_task( + _aap_eda_manage, + args=(job_id, command, command_options), + queue=utils.sanitize_postgres_identifier(MANAGEMENT_TASKS_QUEUE), + timeout=( + settings.DISPATCHERD_PROJECT_TASK_TIMEOUT + if timeout is None + else timeout + ), + uuid=job_id, + ) + return str(job_data["uuid"]) + + +def _aap_eda_manage(job_id: str, command: str, command_options: dict) -> dict: + """Run a management command under an advisory lock.""" + logger.info( + "Management command started job_id=%s command=%s", job_id, command + ) + with advisory_lock(command, wait=False) as acquired: + if not acquired: + reason = f"another task holds the advisory lock for {command}" + logger.warning( + "Management command skipped job_id=%s command=%s " + "status=skipped reason=%s", + job_id, + command, + reason, + ) + return { + "job_id": job_id, + "command": command, + "status": "skipped", + "reason": reason, + } + + try: + command_output = call_command( + command, no_color=True, **command_options + ) + except Exception: + logger.exception( + "Management command failed job_id=%s command=%s " + "status=failed", + job_id, + command, + ) + raise + + result = { + "job_id": job_id, + "command": command, + "status": "completed", + } + if command == "purge_log_records": + match = _DELETED_COUNT.match(command_output or "") + deleted_count = int(match.group(1)) if match else 0 + result["deleted"] = deleted_count + result["status"] = "completed" if deleted_count else "no-op" + logger.info( + "Log purge finished job_id=%s status=%s deleted_count=%d", + job_id, + result["status"], + deleted_count, + ) + else: + logger.info( + "Management command finished job_id=%s command=%s " + "status=completed", + job_id, + command, + ) + return result diff --git a/tests/integration/api/test_log_purge.py b/tests/integration/api/test_log_purge.py new file mode 100644 index 000000000..5d7cb76c9 --- /dev/null +++ b/tests/integration/api/test_log_purge.py @@ -0,0 +1,107 @@ +# Copyright 2026 Red Hat, Inc. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 + +from unittest import mock +from uuid import UUID + +import pytest +from rest_framework import status + +from aap_eda.tasks.management import LOG_PURGE_TASK_TIMEOUT_SECONDS +from tests.integration.constants import api_url_v1 + +PURGE_URL = f"{api_url_v1}/logs/purge/" +JOB_ID = UUID("c3dd8dd8-b1d5-49e0-86e9-216cb2c942a8") + + +@pytest.mark.django_db +def test_superuser_queues_global_purge_on_default_queue(superuser_client): + with mock.patch( + "aap_eda.tasks.management.uuid4", return_value=JOB_ID + ), mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": str(JOB_ID)}, "default"), + ) as submit_task: + response = superuser_client.post( + PURGE_URL, + { + "retention_duration": "P30D", + "audit_trail": True, + "activation_ids": [12, 13], + "activation_names": ["production"], + }, + format="json", + ) + + assert response.status_code == status.HTTP_202_ACCEPTED + assert response.data == {"job_id": str(JOB_ID)} + submit_task.assert_called_once() + (task,) = submit_task.call_args.args + options = submit_task.call_args.kwargs + assert task.__name__ == "_aap_eda_manage" + assert options["queue"] == "default" + assert options["timeout"] == LOG_PURGE_TASK_TIMEOUT_SECONDS + assert options["uuid"] == str(JOB_ID) + assert options["args"] == ( + str(JOB_ID), + "purge_log_records", + { + "retention_duration": "P30D", + "audit_trail": True, + "activation-ids": [12, 13], + "activation-names": ["production"], + }, + ) + + +@pytest.mark.django_db +def test_purge_requires_superuser(admin_client): + response = admin_client.post(PURGE_URL, {}, format="json") + assert response.status_code == status.HTTP_403_FORBIDDEN + + +@pytest.mark.django_db +def test_anonymous_purge_uses_api_permission_denial(base_client): + response = base_client.post(PURGE_URL, {}, format="json") + assert response.status_code == status.HTTP_401_UNAUTHORIZED + + +@pytest.mark.django_db +@pytest.mark.parametrize( + "payload", + [ + {"retention_duration": "not-a-duration"}, + {"retention_duration": "P0D"}, + {"retention_duration": "-P1D"}, + {"before_date": "2026-01-01"}, + {"activation_ids": [0]}, + {"activation_ids": []}, + {"activation_names": [""]}, + {"activation_names": [" "]}, + ], +) +def test_invalid_purge_request_is_rejected_before_enqueue( + superuser_client, payload +): + with mock.patch("aap_eda.tasks.management.submit_task") as submit_task: + response = superuser_client.post(PURGE_URL, payload, format="json") + + assert response.status_code == status.HTTP_400_BAD_REQUEST + submit_task.assert_not_called() + + +@pytest.mark.django_db +def test_enqueue_failure_is_not_reported_as_accepted(superuser_client): + with mock.patch( + "aap_eda.tasks.management.submit_task", + side_effect=RuntimeError("queue unavailable"), + ): + response = superuser_client.post(PURGE_URL, {}, format="json") + + assert response.status_code == status.HTTP_500_INTERNAL_SERVER_ERROR + assert response.data == {"detail": "Unable to queue log purge job."} diff --git a/tests/integration/api/test_openapi.py b/tests/integration/api/test_openapi.py index 2250d8880..a7950f2e5 100644 --- a/tests/integration/api/test_openapi.py +++ b/tests/integration/api/test_openapi.py @@ -87,3 +87,38 @@ def test_v1_openapi_credential_type_inputs_schema(admin_client): assert "properties" not in request_inputs assert request_inputs["additionalProperties"] is True assert request_inputs["example"]["required"] == ["username"] + + +@pytest.mark.django_db +def test_log_purge_openapi_contract(admin_client): + response = admin_client.get(f"{api_url_v1}/openapi.json") + assert response.status_code == status.HTTP_200_OK + + spec = response.json() + purge_path = next( + path for path in spec["paths"] if path.endswith("/logs/purge/") + ) + operation = spec["paths"][purge_path]["post"] + request_ref = operation["requestBody"]["content"]["application/json"][ + "schema" + ]["$ref"] + request_schema = spec["components"]["schemas"][ + request_ref.rsplit("/", 1)[1] + ] + request_properties = request_schema["properties"] + assert set(request_properties) == { + "retention_duration", + "audit_trail", + "activation_ids", + "activation_names", + } + + responses = operation["responses"] + assert {"202", "400", "403"}.issubset(responses) + response_ref = responses["202"]["content"]["application/json"]["schema"][ + "$ref" + ] + response_schema = spec["components"]["schemas"][ + response_ref.rsplit("/", 1)[1] + ] + assert set(response_schema["properties"]) == {"job_id"} diff --git a/tests/integration/api/test_root.py b/tests/integration/api/test_root.py index 416fe1e73..99ee27419 100644 --- a/tests/integration/api/test_root.py +++ b/tests/integration/api/test_root.py @@ -35,6 +35,7 @@ "/projects/", "/rulebooks/", "/activations/", + "/logs/", "/activation-instances/", "/audit-rules/", "/users/", @@ -91,6 +92,7 @@ "/projects/", "/rulebooks/", "/activations/", + "/logs/", "/activation-instances/", "/audit-rules/", "/users/", diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index 376aaa69e..58d982c1f 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -12,15 +12,20 @@ # See the License for the specific language governing permissions and # limitations under the License. -from datetime import timedelta +from datetime import datetime, timedelta, timezone as datetime_timezone +from unittest import mock import pytest from django.core.management import call_command from django.core.management.base import CommandError from django.db import connection, transaction +from django.db.models.query import QuerySet +from django.test import override_settings from django.utils import timezone from aap_eda.core import enums, models +from aap_eda.core.utils import delete_log_util +from aap_eda.core.utils.log_retention import retention_cutoff @pytest.fixture @@ -158,12 +163,11 @@ def prepare_log_records( @pytest.mark.django_db -def test_purge_log_records_missing_required_params(): - with pytest.raises( - CommandError, - match="Error: the following arguments are required: --date", - ): - call_command("purge_log_records") +def test_purge_log_records_default_retention_is_disabled(capsys): + with override_settings(ACTIVATION_DB_LOG_RETENTION_DAYS=0): + output = call_command("purge_log_records") + assert output.startswith("No logs purged") + assert "No logs purged" in capsys.readouterr().out @pytest.mark.django_db @@ -171,7 +175,7 @@ def test_purge_log_records_with_nonexist_activation(capsys): # With global purging, even non-existent activation filters will # still purge old logs globally (if any exist) args = ("--activation-ids", "42", "--date", "2024-10-01") - call_command("purge_log_records", args) + call_command("purge_log_records", *args) captured = capsys.readouterr() # Should report either no old logs found, or global purge count @@ -181,7 +185,7 @@ def test_purge_log_records_with_nonexist_activation(capsys): ) args = ("--activation-names", "na", "--date", "2024-10-01") - call_command("purge_log_records", args) + call_command("purge_log_records", *args) captured = capsys.readouterr() assert ( @@ -214,6 +218,7 @@ def test_purge_log_records( activations[1].id, "--date", date_str, + "--audit-trail", ) elif identifiers == "names": args = ( @@ -222,14 +227,16 @@ def test_purge_log_records( activations[1].name, "--date", date_str, + "--audit-trail", ) else: args = ( "--date", date_str, + "--audit-trail", ) - call_command(command, args) + call_command(command, *args) captured = capsys.readouterr() @@ -239,10 +246,7 @@ def test_purge_log_records( assert models.RulebookProcessLog.objects.count() == 4 for log_record in models.RulebookProcessLog.objects.all(): - assert ( - f"All log records older than {date_str} were purged at" - in log_record.log - ) + assert f"All log records older than {date_str}" in log_record.log else: # Global purge: only 30-day logs deleted, 10-day logs remain, # audit logs created for all 4 RulebookProcess instances @@ -250,7 +254,7 @@ def test_purge_log_records( # Check audit logs exist for all instances audit_logs = models.RulebookProcessLog.objects.filter( - log__contains=f"All log records older than {date_str} were purged" + log__contains=f"All log records older than {date_str}" ) assert audit_logs.count() == 4 @@ -376,7 +380,13 @@ def test_purge_without_activation_filter_handles_null_correctly( # Test purge without activation filtering (customer's command scenario) cutoff_date = (timezone.now() - timedelta(days=10)).strftime("%Y-%m-%d") - call_command("purge_log_records", "--date", cutoff_date, verbosity=3) + call_command( + "purge_log_records", + "--date", + cutoff_date, + "--audit-trail", + verbosity=3, + ) captured = capsys.readouterr() @@ -416,6 +426,7 @@ def test_purge_with_activation_filter_now_includes_null_fix( str(activation_id), "--date", cutoff_date, + "--audit-trail", verbosity=3, ) @@ -450,11 +461,7 @@ def test_purge_with_activation_filter_now_includes_null_fix( len(normal_activation_logs) == 0 ), "Normal activation logs should have been purged" - # Verify that the command output mentions orphaned records - assert "Audit trail will include" in captured.out - assert ( - "orphaned" in captured.out - ), "Should mention orphaned records in output" + assert "Created 2 audit trail entries." in captured.out @pytest.mark.django_db @@ -480,6 +487,7 @@ def test_purge_with_activation_name_filter_also_includes_null_fix( activation_name, "--date", cutoff_date, + "--audit-trail", verbosity=3, ) @@ -504,8 +512,337 @@ def test_purge_with_activation_name_filter_also_includes_null_fix( "when using --activation-names filter" ) - # Verify that the command output mentions orphaned records - assert "Audit trail will include" in captured.out + assert "Created 2 audit trail entries." in captured.out + + +@pytest.mark.django_db +def test_purge_without_audit_trail_does_not_create_audit_logs( + prepare_log_records, capsys +): + cutoff = (timezone.now() - timedelta(days=15)).strftime("%Y-%m-%d") + output = call_command("purge_log_records", "--date", cutoff) + + assert output.startswith("Purged 4 log records") + assert models.RulebookProcessLog.objects.count() == 4 + assert not models.RulebookProcessLog.objects.filter( + log__contains="were purged at" + ).exists() + assert "Purged 4 log records" in capsys.readouterr().out + + +@pytest.mark.django_db +def test_purge_retention_setting_deletes_globally(prepare_log_records): + with override_settings(ACTIVATION_DB_LOG_RETENTION_DAYS=15): + output = call_command("purge_log_records") + + assert output.startswith("Purged 4 log records") + assert models.RulebookProcessLog.objects.count() == 4 + + +@pytest.mark.django_db +@pytest.mark.parametrize( + "args", + [ + ("--date", "2026-01-01", "--retention-duration", "P1D"), + ("--retention-duration", "P0D"), + ("--retention-duration", "-P1D"), + ("--retention-duration", "not-a-duration"), + ], +) +def test_purge_rejects_invalid_retention_arguments(args): + with pytest.raises(CommandError): + call_command("purge_log_records", *args) + + +@pytest.mark.parametrize( + "now, duration, expected", + [ + ( + datetime(2026, 3, 31, 12, tzinfo=datetime_timezone.utc), + "P1M", + datetime(2026, 2, 28, 12, tzinfo=datetime_timezone.utc), + ), + ( + datetime(2024, 3, 31, 12, tzinfo=datetime_timezone.utc), + "P1M", + datetime(2024, 2, 29, 12, tzinfo=datetime_timezone.utc), + ), + ( + datetime(2024, 2, 29, 12, tzinfo=datetime_timezone.utc), + "P1Y", + datetime(2023, 2, 28, 12, tzinfo=datetime_timezone.utc), + ), + ( + datetime( + 2026, + 10, + 1, + 0, + 30, + tzinfo=timezone.get_fixed_timezone(120), + ), + "P1D", + datetime(2026, 9, 29, 22, 30, tzinfo=datetime_timezone.utc), + ), + ( + datetime(2026, 10, 21, 12, tzinfo=datetime_timezone.utc), + "PT30S", + datetime(2026, 10, 21, 11, 59, 30, tzinfo=datetime_timezone.utc), + ), + ( + datetime(2026, 10, 21, 12, tzinfo=datetime_timezone.utc), + "PT5M", + datetime(2026, 10, 21, 11, 55, tzinfo=datetime_timezone.utc), + ), + ( + datetime(2026, 10, 21, 12, tzinfo=datetime_timezone.utc), + "PT2H", + datetime(2026, 10, 21, 10, tzinfo=datetime_timezone.utc), + ), + ( + datetime(2026, 10, 21, 12, tzinfo=datetime_timezone.utc), + "P2W", + datetime(2026, 10, 7, 12, tzinfo=datetime_timezone.utc), + ), + ], +) +def test_retention_cutoff_calendar_and_timezone_policy( + now, duration, expected +): + assert retention_cutoff(duration, now=now) == expected + + +@pytest.mark.parametrize("filter_by", ["ids", "names"]) +@pytest.mark.django_db +def test_activation_filter_selects_audit_targets_only( + prepare_log_records, filter_by +): + selected_activation = prepare_log_records[0] + cutoff = (timezone.now() - timedelta(days=5)).strftime("%Y-%m-%d") + option = "--activation-ids" if filter_by == "ids" else "--activation-names" + value = ( + str(selected_activation.id) + if filter_by == "ids" + else selected_activation.name + ) + + output = call_command( + "purge_log_records", + option, + value, + "--date", + cutoff, + "--audit-trail", + ) + + audit_logs = models.RulebookProcessLog.objects.filter( + log__contains="were purged at" + ) + assert output.startswith("Purged 8 log records") + assert audit_logs.count() == 2 + assert set( + audit_logs.values_list("activation_instance__activation_id", flat=True) + ) == {selected_activation.id} + cutoff_timestamp = ( + datetime.strptime(cutoff, "%Y-%m-%d") + .replace(tzinfo=datetime_timezone.utc) + .timestamp() + ) + assert all( + log_timestamp > cutoff_timestamp + for log_timestamp in audit_logs.values_list("log_timestamp", flat=True) + ) + + +@pytest.mark.django_db +def test_retention_duration_deletes_strictly_older_rows_across_activations( + default_activation_instances, +): + cutoff = datetime(2026, 1, 1, tzinfo=datetime_timezone.utc) + older, equal, newer = [ + models.RulebookProcessLog.objects.create( + log=f"boundary-{timestamp}", + activation_instance=default_activation_instances[index % 2], + log_timestamp=timestamp, + ) + for index, timestamp in enumerate( + ( + cutoff.timestamp() - 1, + cutoff.timestamp(), + cutoff.timestamp() + 1, + ) + ) + ] + + deleted = delete_log_util.delete_logs_older_than(cutoff) + + assert deleted == 1 + assert not models.RulebookProcessLog.objects.filter(pk=older.pk).exists() assert ( - "orphaned" in captured.out - ), "Should mention orphaned records in output" + models.RulebookProcessLog.objects.filter( + pk__in=[equal.pk, newer.pk] + ).count() + == 2 + ) + + +@pytest.mark.django_db +def test_retention_batches_continue_after_more_than_one_batch( + default_activation_instance, monkeypatch +): + monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 2) + logs = models.RulebookProcessLog.objects.bulk_create( + [ + models.RulebookProcessLog( + log=f"batch-{index}", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + for index in range(5) + ] + ) + + assert ( + delete_log_util.delete_logs_older_than( + datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) + ) + == 5 + ) + assert not models.RulebookProcessLog.objects.filter( + pk__in=[log.pk for log in logs] + ).exists() + + +@pytest.mark.django_db +def test_retention_stops_at_initial_highest_qualifying_id( + default_activation_instance, monkeypatch +): + monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 1) + models.RulebookProcessLog.objects.bulk_create( + [ + models.RulebookProcessLog( + log=f"snapshot-{index}", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + for index in range(2) + ] + ) + original_delete = QuerySet.delete + new_log = [] + calls = 0 + + def insert_after_first_batch(queryset): + nonlocal calls + result = original_delete(queryset) + calls += 1 + if calls == 1: + new_log.append( + models.RulebookProcessLog.objects.create( + log="arrived-during-purge", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + ) + return result + + monkeypatch.setattr(QuerySet, "delete", insert_after_first_batch) + deleted = delete_log_util.delete_logs_older_than( + datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) + ) + + assert deleted == 2 + assert models.RulebookProcessLog.objects.filter(pk=new_log[0].pk).exists() + + +@pytest.mark.django_db +def test_retention_with_no_matching_rows_returns_zero( + default_activation_instance, +): + models.RulebookProcessLog.objects.create( + log="new", + activation_instance=default_activation_instance, + log_timestamp=2, + ) + assert ( + delete_log_util.delete_logs_older_than( + datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) + ) + == 0 + ) + + +@pytest.mark.django_db +def test_retention_failure_reports_committed_batch_count( + default_activation_instance, monkeypatch +): + monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 1) + models.RulebookProcessLog.objects.bulk_create( + [ + models.RulebookProcessLog( + log=f"partial-{index}", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + for index in range(3) + ] + ) + original_delete = QuerySet.delete + calls = 0 + + def fail_second_delete(queryset): + nonlocal calls + calls += 1 + if calls == 2: + raise RuntimeError("injected batch failure") + return original_delete(queryset) + + monkeypatch.setattr(QuerySet, "delete", fail_second_delete) + with pytest.raises(delete_log_util.LogPurgeError) as error: + delete_log_util.delete_logs_older_than( + datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) + ) + + assert error.value.deleted_count == 1 + assert models.RulebookProcessLog.objects.count() == 2 + + +@pytest.mark.django_db +def test_retention_duration_cli_uses_execution_time_cutoff( + default_activation_instance, +): + cutoff_epoch = datetime( + 2026, 10, 20, tzinfo=datetime_timezone.utc + ).timestamp() + logs = models.RulebookProcessLog.objects.bulk_create( + [ + models.RulebookProcessLog( + log=f"duration-{index}", + activation_instance=default_activation_instance, + log_timestamp=timestamp, + ) + for index, timestamp in enumerate( + (cutoff_epoch - 1, cutoff_epoch, cutoff_epoch + 1) + ) + ] + ) + + with mock.patch( + "aap_eda.core.utils.log_retention.datetime" + ) as mocked_datetime: + mocked_datetime.now.return_value = datetime( + 2026, 10, 21, tzinfo=datetime_timezone.utc + ) + mocked_datetime.timezone = datetime_timezone + output = call_command( + "purge_log_records", "--retention-duration", "P1D" + ) + + assert output.startswith("Purged 1 log records") + assert not models.RulebookProcessLog.objects.filter(pk=logs[0].pk).exists() + assert ( + models.RulebookProcessLog.objects.filter( + pk__in=[logs[1].pk, logs[2].pk] + ).count() + == 2 + ) diff --git a/tests/integration/tasks/test_management.py b/tests/integration/tasks/test_management.py new file mode 100644 index 000000000..b40a4b39a --- /dev/null +++ b/tests/integration/tasks/test_management.py @@ -0,0 +1,199 @@ +# Copyright 2026 Red Hat, Inc. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 + +from unittest import mock + +import pytest +from dispatcherd.worker.exceptions import DispatcherCancel +from django.core.management.base import CommandError +from django.test import override_settings + +from aap_eda.core import models +from aap_eda.tasks.management import ( + LOG_PURGE_TASK_TIMEOUT_SECONDS, + _aap_eda_manage, + submit_log_purge, +) + + +@pytest.mark.django_db +def test_submit_log_purge_uses_default_queue_uuid_and_purge_timeout(): + job_id = "712beb16-b7dd-40c9-aa29-a7f734376c7a" + with mock.patch( + "aap_eda.tasks.management.uuid4", return_value=job_id + ), mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": job_id}, "default"), + ) as submit_task: + assert ( + submit_log_purge( + retention_duration="P1M", + audit_trail=True, + activation_ids=[9], + ) + == job_id + ) + + (task,) = submit_task.call_args.args + assert task is _aap_eda_manage + assert submit_task.call_args.kwargs == { + "args": ( + job_id, + "purge_log_records", + { + "retention_duration": "P1M", + "audit_trail": True, + "activation-ids": [9], + }, + ), + "queue": "default", + "timeout": LOG_PURGE_TASK_TIMEOUT_SECONDS, + "uuid": job_id, + } + + +@pytest.mark.django_db +def test_worker_invokes_purge_command_and_returns_deleted_count( + default_activation_instances, +): + logs = [ + models.RulebookProcessLog.objects.create( + log=f"worker-log-{index}", + activation_instance=instance, + log_timestamp=1, + ) + for index, instance in enumerate(default_activation_instances) + ] + job_id = "worker-job-17" + + with mock.patch("aap_eda.tasks.management.logger.info") as log_info: + result = _aap_eda_manage( + job_id, + "purge_log_records", + { + "date": "1970-01-02", + "audit_trail": True, + "activation-ids": [ + default_activation_instances[0].activation_id + ], + }, + ) + + assert result == { + "job_id": job_id, + "command": "purge_log_records", + "status": "completed", + "deleted": 2, + } + assert not models.RulebookProcessLog.objects.filter( + pk__in=[log.pk for log in logs] + ).exists() + assert ( + models.RulebookProcessLog.objects.filter( + log__contains="were purged at" + ).count() + == 2 + ) + assert any( + call.args[0].startswith("Log purge finished") + and call.args[1:] == (job_id, "completed", 2) + for call in log_info.call_args_list + ) + + +@pytest.mark.django_db +def test_worker_empty_options_obey_zero_retention_setting( + default_activation_instance, +): + models.RulebookProcessLog.objects.create( + log="retained", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + with override_settings(ACTIVATION_DB_LOG_RETENTION_DAYS=0), mock.patch( + "aap_eda.tasks.management.logger.info" + ) as log_info: + result = _aap_eda_manage("no-op-job", "purge_log_records", {}) + + assert result == { + "job_id": "no-op-job", + "command": "purge_log_records", + "status": "no-op", + "deleted": 0, + } + assert models.RulebookProcessLog.objects.filter(log="retained").exists() + assert any( + call.args[0].startswith("Log purge finished") + and call.args[1:] == ("no-op-job", "no-op", 0) + for call in log_info.call_args_list + ) + + +@pytest.mark.django_db +def test_worker_lock_contention_is_an_observable_skip(): + class NotAcquired: + def __enter__(self): + return False + + def __exit__(self, exc_type, exc, traceback): + return False + + with mock.patch( + "aap_eda.tasks.management.advisory_lock", return_value=NotAcquired() + ), mock.patch( + "aap_eda.tasks.management.call_command" + ) as call_command, mock.patch( + "aap_eda.tasks.management.logger.warning" + ) as log_warning: + result = _aap_eda_manage("locked-job", "purge_log_records", {}) + + assert result["status"] == "skipped" + assert "advisory lock" in result["reason"] + call_command.assert_not_called() + log_warning.assert_called_once() + assert log_warning.call_args.args[1:] == ( + "locked-job", + "purge_log_records", + "another task holds the advisory lock for purge_log_records", + ) + + +@pytest.mark.django_db +@pytest.mark.parametrize( + "failure", [CommandError("partial failure"), DispatcherCancel()] +) +def test_worker_propagates_command_and_timeout_failures(failure): + with mock.patch( + "aap_eda.tasks.management.call_command", side_effect=failure + ), mock.patch( + "aap_eda.tasks.management.logger.exception" + ) as log_exception, pytest.raises( + type(failure) + ): + _aap_eda_manage("failed-job", "purge_log_records", {}) + + log_exception.assert_called_once() + assert log_exception.call_args.args[0].startswith( + "Management command failed" + ) + assert log_exception.call_args.args[1] == "failed-job" + + +@pytest.mark.django_db +def test_worker_keeps_generic_management_command_scope(): + with mock.patch( + "aap_eda.tasks.management.call_command", return_value="finished" + ) as call_command: + result = _aap_eda_manage("generic-job", "check", {"deploy": True}) + + assert result == { + "job_id": "generic-job", + "command": "check", + "status": "completed", + } + call_command.assert_called_once_with("check", no_color=True, deploy=True) diff --git a/tests/integration/test_advisory_lock.py b/tests/integration/test_advisory_lock.py index aa5be6bf7..cc8cab51f 100644 --- a/tests/integration/test_advisory_lock.py +++ b/tests/integration/test_advisory_lock.py @@ -42,6 +42,12 @@ "fn_call": "_sync_project", "fn_args": [1], }, + { + "module_path": "aap_eda.tasks.management", + "fn_mock": "call_command", + "fn_call": "_aap_eda_manage", + "fn_args": ["parallel-job", "test_management_command", {}], + }, ], ids=[ "gather_analytics", @@ -49,6 +55,7 @@ "monitor_project_tasks", "_import_project", "_sync_project", + "_aap_eda_manage", ], ) @pytest.mark.django_db @@ -84,7 +91,7 @@ def _wrapper_call(shared_list): mocks = [stack.enter_context(patch) for patch in patches] fn_mock = mocks[0] - def record_call(void=None): + def record_call(void=None, **kwargs): time.sleep(1) shared_list.append("called") From d3b94c2c712b5dfdfc726305049a20b5837ded05 Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Thu, 22 Oct 2026 12:16:45 -0400 Subject: [PATCH 02/15] fix sonar cloud --- tests/integration/commands/test_purge_log_records.py | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index 58d982c1f..c0a04d9f1 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -798,10 +798,9 @@ def fail_second_delete(queryset): return original_delete(queryset) monkeypatch.setattr(QuerySet, "delete", fail_second_delete) + cutoff = datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) with pytest.raises(delete_log_util.LogPurgeError) as error: - delete_log_util.delete_logs_older_than( - datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) - ) + delete_log_util.delete_logs_older_than(cutoff) assert error.value.deleted_count == 1 assert models.RulebookProcessLog.objects.count() == 2 From 7162643d1b1429aafa88ae206c980428d3d77a11 Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Fri, 23 Oct 2026 13:58:29 -0400 Subject: [PATCH 03/15] feat(logs): add scoped, bounded log purges Allow operators to remove old logs for selected activations without affecting unrelated processes. Bound deletion work and record per-process counts so partial failures remain traceable. Validate requests before queueing or deleting, and link audit markers to the EDA purge job. Assisted by: GPT-6 --- docs/development.md | 72 ++- src/aap_eda/api/serializers/activation.py | 51 +- src/aap_eda/api/views/activation.py | 13 +- .../management/commands/purge_log_records.py | 128 +++-- src/aap_eda/core/utils/delete_log_util.py | 289 +++++++--- src/aap_eda/tasks/management.py | 48 +- tests/integration/api/test_log_purge.py | 107 +++- tests/integration/api/test_openapi.py | 3 + .../commands/test_purge_log_records.py | 541 ++++++++++++------ tests/integration/tasks/test_management.py | 129 ++++- 10 files changed, 968 insertions(+), 413 deletions(-) diff --git a/docs/development.md b/docs/development.md index bfef6da29..cc42c7e16 100644 --- a/docs/development.md +++ b/docs/development.md @@ -461,15 +461,23 @@ task docker:purge && EDA_SECRET_KEY=insecure task docker:up Do **not** confuse the two — see the command docstring in `src/aap_eda/core/management/commands/rotate_db_encryption_key.py`. -## Global log purge - -The global log purge endpoint is `POST /api/eda/v1/logs/purge/`. Only a -superuser can submit it. A successful request returns HTTP 202 with a `job_id`; -this confirms that dispatcherd accepted the job, not that deletion has -completed. The endpoint deletes qualifying log rows across all activations. -Optional `activation_ids` and `activation_names` select audit-trail targets -only; they never limit deletion. Audit entries are disabled by default for -both API and CLI requests. +## Log purge + +- **Submit a job:** A superuser sends `POST /api/eda/v1/logs/purge/`. HTTP 202 + with a `job_id` means dispatcherd accepted the job; deletion may still be + running. +- **Choose a cutoff:** Supply exactly one of `before_date` (midnight UTC in + `YYYY-MM-DD` format) or a positive ISO 8601 `retention_duration`. Only rows + with `log_timestamp` strictly before the cutoff qualify. Future UTC cutoffs + are rejected. +- **Choose the scope:** With no selectors, qualifying ordinary logs from every + process are included, including processes without an activation. + `activation_ids` and `activation_names` select the union of matching + activations. Empty or unknown selectors are rejected before queueing. +- **Choose audit behavior:** Audit markers are enabled by default. Set API + `audit_trail` to `false` to disable them. + +For example, this request queues a purge for the named activation: ```http POST /api/eda/v1/logs/purge/ @@ -479,17 +487,39 @@ Content-Type: application/json "activation_names": ["production-rules"]} ``` -`retention_duration` is an optional ISO 8601 duration such as `P30D` or -`P1M`. If omitted, the worker reads -`ACTIVATION_DB_LOG_RETENTION_DAYS`; its default is `0`, which disables -deletion. Calendar months and years are subtracted in UTC, clamping a day that -does not exist in the target month to that month's final day. The CLI also -supports `--date YYYY-MM-DD` (interpreted as midnight UTC) and -`--retention-duration P30D`; those options are mutually exclusive. The API -does not accept `before_date`. +**CLI options** + +- Use either `--date YYYY-MM-DD` or `--retention-duration P30D`. Calendar + months and years in a duration are subtracted in UTC. If the target month + lacks the original day, the cutoff uses that month's final day. +- Use `--activation-ids 123 456`, `--activation-names name1 name2`, or both to + limit deletion to the selected activations. Omit both for a global purge. +- Use `--audit-trail=true` or `--audit-trail=false`. A bare `--audit-trail` is + invalid. +- The optional `--internal-job-uuid` adds the EDA purge task UUID to markers. + The API supplies this UUID automatically. + +**Deletion and audit markers** + +- Deletion commits in batches. If a later batch fails, worker logs record the + count already deleted, and the job reports failure. Audit markers record the + partial count when audit is enabled. +- When audit is enabled, each process that loses ordinary log rows gets one + marker with its count for this invocation. +- This change makes no schema or data migration. New markers use a reserved + `log_created_at` value to exclude them from later purges. Earlier markers + with `log_created_at` set to null are excluded by an exact regular expression + matching the old fixed message format. No broad update of existing logs is + run. +- An ordinary log with that exact legacy text or the reserved timestamp is + indistinguishable from a marker and will also be retained. The regular + expression adds work to candidate and DELETE queries; measure performance + on a representative PostgreSQL database before drawing conclusions. + +**Check the outcome** -Inspect default-worker logs by the returned job ID to see started, completed, -skipped, and failed outcomes, including `deleted_count`: +- Inspect default-worker logs by the returned job ID for started, completed, + skipped, and failed outcomes, including `deleted_count`: ```shell JOB_ID= @@ -498,8 +528,8 @@ kubectl logs -n "${NAMESPACE:-aap-eda}" \ | grep "job_id=${JOB_ID}" ``` -The dispatcherd `running` view only reports in-flight work; the structured -worker log lines are the supported completion and deletion-count record. +- The dispatcherd `running` view reports only in-flight work. Structured + worker log lines are the completion and deletion-count record. ### Running linters diff --git a/src/aap_eda/api/serializers/activation.py b/src/aap_eda/api/serializers/activation.py index 8781c96ce..fe0279e40 100644 --- a/src/aap_eda/api/serializers/activation.py +++ b/src/aap_eda/api/serializers/activation.py @@ -16,6 +16,7 @@ import secrets import uuid from dataclasses import dataclass, field +from datetime import datetime, time, timezone as datetime_timezone from typing import Optional import yaml @@ -54,6 +55,7 @@ get_resolved_secrets, get_secret_fields, ) +from aap_eda.core.utils.delete_log_util import resolve_activation_ids from aap_eda.core.utils.k8s_service_name import create_k8s_service_name from aap_eda.core.utils.log_retention import retention_cutoff from aap_eda.core.utils.rulebook import ( @@ -91,38 +93,65 @@ def _update_event_stream_source(validated_data: dict) -> str: class LogPurgeRequestSerializer(serializers.Serializer): - """Validate a global log purge request.""" + """Validate cutoff and activation scope before scheduling a purge.""" - retention_duration = serializers.CharField(required=False) - audit_trail = serializers.BooleanField(required=False, default=False) + before_date = serializers.DateField( + required=False, + help_text="Exclusive UTC midnight cutoff (YYYY-MM-DD).", + ) + retention_duration = serializers.CharField( + required=False, + help_text="Exclusive cutoff as a positive ISO 8601 duration.", + ) + audit_trail = serializers.BooleanField( + required=False, + default=True, + help_text="Write one audit marker per process that loses logs.", + ) activation_ids = serializers.ListField( child=serializers.IntegerField(min_value=1), required=False, allow_empty=False, + help_text="Limit deletion to these activation IDs.", ) activation_names = serializers.ListField( - child=serializers.CharField(allow_blank=False), + child=serializers.CharField(allow_blank=False, trim_whitespace=False), required=False, allow_empty=False, + help_text="Limit deletion to these activation names.", ) def validate(self, attrs): - if "before_date" in self.initial_data: + before_date = attrs.get("before_date") + duration = attrs.get("retention_duration") + if (before_date is None) == (duration is None): raise serializers.ValidationError( - {"before_date": "This field is not supported."} + "Exactly one of before_date or retention_duration is required." ) - if any(not name.strip() for name in attrs.get("activation_names", [])): - raise serializers.ValidationError( - {"activation_names": "Names cannot be blank."} + if before_date is not None: + cutoff = datetime.combine( + before_date, time.min, tzinfo=datetime_timezone.utc ) - duration = attrs.get("retention_duration") - if duration is not None: + if cutoff > datetime.now(datetime_timezone.utc): + raise serializers.ValidationError( + {"before_date": "The UTC cutoff must not be future."} + ) + attrs["before_date"] = before_date.isoformat() + else: try: retention_cutoff(duration) except ValueError as exc: raise serializers.ValidationError( {"retention_duration": str(exc)} ) from exc + if "activation_ids" in attrs or "activation_names" in attrs: + try: + resolve_activation_ids( + attrs.get("activation_ids"), + attrs.get("activation_names"), + ) + except ValueError as exc: + raise serializers.ValidationError(str(exc)) from exc return attrs diff --git a/src/aap_eda/api/views/activation.py b/src/aap_eda/api/views/activation.py index da65e2d89..900541e31 100644 --- a/src/aap_eda/api/views/activation.py +++ b/src/aap_eda/api/views/activation.py @@ -873,16 +873,19 @@ def logs(self, request, id): class LogPurgeViewSet(viewsets.GenericViewSet): - """Global, superuser-only log purge scheduling endpoint.""" + """Superuser-only log purge scheduling endpoint.""" permission_classes = (IsSystemAdmin,) serializer_class = serializers.LogPurgeRequestSerializer @extend_schema( description=( - "Queue a global deletion of old activation logs. The activation " - "IDs and names select audit-trail targets only. The returned job " - "ID acknowledges scheduling; it does not mean deletion is done." + "Queue deletion of process logs older than one UTC cutoff: " + "before_date (YYYY-MM-DD) or retention_duration (positive ISO " + "8601). Without activation selectors, all processes, including " + "orphaned ones, are included. Activation IDs and names limit " + "deletion to their union. Audit markers default to enabled. " + "The returned job ID acknowledges scheduling only." ), request=serializers.LogPurgeRequestSerializer, responses={ @@ -905,7 +908,7 @@ def purge(self, request): try: job_id = submit_log_purge(**serializer.validated_data) except Exception: - logger.exception("Unable to queue global log purge") + logger.exception("Unable to queue log purge") return Response( {"detail": "Unable to queue log purge job."}, status=status.HTTP_500_INTERNAL_SERVER_ERROR, diff --git a/src/aap_eda/core/management/commands/purge_log_records.py b/src/aap_eda/core/management/commands/purge_log_records.py index dd02881f1..ac48eac5e 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -12,9 +12,10 @@ # See the License for the specific language governing permissions and # limitations under the License. -from datetime import datetime, time, timedelta, timezone +from argparse import ArgumentTypeError +from datetime import datetime, time, timezone +from uuid import UUID -from django.conf import settings from django.core.management.base import ( BaseCommand, CommandError, @@ -23,20 +24,19 @@ from aap_eda.core.utils.delete_log_util import ( LogPurgeError, - create_audit_trail, delete_logs_older_than, ) from aap_eda.core.utils.log_retention import retention_cutoff class Command(BaseCommand): - """Purge old logs globally, optionally writing audit trail entries.""" + """Purge old logs globally or for selected activations.""" help = ( - "Purge log records from rulebook processes. " - "Always purges all log records older than --date globally. " - "Activation ids or names only control detailed reporting for those " - "activations and orphaned records; they do not limit deletion." + "Purge log records older than exactly one cutoff. Without activation " + "selectors, include every process (including orphaned processes). " + "Activation IDs and names limit deletion to their union. " + "One audit marker per affected process is enabled by default." ) def add_arguments(self, parser: CommandParser) -> None: @@ -45,11 +45,7 @@ def add_arguments(self, parser: CommandParser) -> None: nargs="+", type=int, dest="activation-ids", - help=( - "Activation ids to include in detailed reporting only. " - "This does not limit deletion: all log records older than " - "--date are purged globally (e.g., 123 456)." - ), + help=("Limit deletion to these activation IDs (e.g., 123 456)."), ) parser.add_argument( "--activation-names", @@ -57,10 +53,8 @@ def add_arguments(self, parser: CommandParser) -> None: type=str, dest="activation-names", help=( - "Activation names to include in detailed reporting only. " - "This does not limit deletion: all log records older than " - "--date are purged globally (e.g., ActivationName1 " - "ActivationName2)." + "Limit deletion to these activation names (e.g., " + "ActivationName1 ActivationName2)." ), ) parser.add_argument( @@ -85,12 +79,28 @@ def add_arguments(self, parser: CommandParser) -> None: parser.add_argument( "--audit-trail", dest="audit_trail", - action="store_true", - help="Create audit log entries for affected processes.", + type=self._audit_trail_value, + default=True, + metavar="true|false", + help="Create a marker for each affected process (default: true).", + ) + parser.add_argument( + "--internal-job-uuid", + dest="internal-job-uuid", + default=None, + help="EDA purge task UUID to include in audit markers.", ) @staticmethod - def _cutoff(options: dict) -> datetime | None: + def _audit_trail_value(value: str) -> bool: + if value == "true": + return True + if value == "false": + return False + raise ArgumentTypeError("--audit-trail must be true or false.") + + @staticmethod + def _cutoff(options: dict) -> datetime: cutoff_date = options.get("date") retention_duration = options.get("retention_duration") if cutoff_date is not None and retention_duration is not None: @@ -115,52 +125,50 @@ def _cutoff(options: dict) -> datetime | None: except ValueError as exc: raise CommandError(str(exc)) from exc - retention_days = settings.ACTIVATION_DB_LOG_RETENTION_DAYS - if retention_days <= 0: - return None - return datetime.now(timezone.utc) - timedelta(days=retention_days) + raise CommandError( + "Exactly one of --date or --retention-duration is required." + ) def handle(self, *args, **options): - ids = options.get("activation-ids") or [] - names = options.get("activation-names") or [] - if any(activation_id <= 0 for activation_id in ids): - raise CommandError("Activation IDs must be positive integers.") - if any(not name.strip() for name in names): - raise CommandError("Activation names cannot be blank.") - + ids = options.get("activation-ids") + names = options.get("activation-names") cutoff = self._cutoff(options) - if cutoff is None: - return self.style.WARNING( - "No logs purged: configured retention is not positive." - ) + if cutoff > datetime.now(timezone.utc): + raise CommandError("--date must not be in the future.") + job_uuid = options.get("internal-job-uuid") + if job_uuid is not None: + try: + job_uuid = str(UUID(str(job_uuid))) + except (TypeError, ValueError, AttributeError) as exc: + raise CommandError( + "--internal-job-uuid must be a UUID." + ) from exc + audit_trail = options["audit_trail"] + if isinstance(audit_trail, str): + try: + audit_trail = self._audit_trail_value(audit_trail) + except ArgumentTypeError as exc: + raise CommandError(str(exc)) from exc + elif not isinstance(audit_trail, bool): + raise CommandError("--audit-trail must be true or false.") try: - deleted_count = delete_logs_older_than(cutoff) - except LogPurgeError as exc: - raise CommandError(str(exc)) from exc - - if deleted_count == 0: - return self.style.SUCCESS( - f"No log records found older than " - f"{cutoff.strftime('%Y-%m-%d %H:%M:%S UTC')}; 0 rows " - "deleted." + deleted_count = delete_logs_older_than( + cutoff, + activation_ids=ids, + activation_names=names, + audit_trail=audit_trail, + internal_job_uuid=job_uuid, ) + except (LogPurgeError, ValueError) as exc: + raise CommandError(str(exc)) from exc - output = ( + scope = ( + "globally" + if ids is None and names is None + else "for selected activations" + ) + return self.style.SUCCESS( f"Purged {deleted_count} log records older than " - f"{cutoff.strftime('%Y-%m-%d %H:%M:%S UTC')} globally." + f"{cutoff.strftime('%Y-%m-%d %H:%M:%S UTC')} {scope}." ) - if options.get("audit_trail"): - try: - audit_count = create_audit_trail( - cutoff, - activation_ids=ids, - activation_names=names, - ) - except Exception as exc: - raise CommandError( - f"Deleted {deleted_count} logs, but audit trail failed: " - f"{exc}" - ) from exc - output += f" Created {audit_count} audit trail entries." - return self.style.SUCCESS(output) diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index 840be3460..271612825 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -12,16 +12,36 @@ # See the License for the specific language governing permissions and # limitations under the License. -from datetime import datetime +from datetime import datetime, timezone +from math import ceil from django.db import transaction -from django.db.models import Max, Q -from django.utils import timezone +from django.db.models import Max from aap_eda.core import models DELETE_BATCH_SIZE = 1000 +# This reserved value identifies new markers without a schema change. +PURGE_MARKER_CREATED_AT = datetime(9999, 12, 31, tzinfo=timezone.utc) + +# Older versions wrote this fixed message with NULL log_created_at. Text +# matching cannot distinguish an ordinary log with identical content. +LEGACY_MARKER_PATTERN = ( + r"^All log records older than [0-9]{4}-[0-9]{2}-[0-9]{2} " + r"[0-9]{2}:[0-9]{2}:[0-9]{2} UTC were purged at " + r"[0-9]{4}-[0-9]{2}-[0-9]{2} " + r"[0-9]{2}:[0-9]{2}:[0-9]{2} UTC\.$" +) + + +def _utc_text(value: datetime) -> str: + value = value.astimezone(timezone.utc) + time_format = "%Y-%m-%d %H:%M:%S" + if value.microsecond: + time_format += ".%f" + return value.strftime(time_format + " UTC") + class LogPurgeError(Exception): """A purge failure that includes the number of committed deletions.""" @@ -31,95 +51,202 @@ def __init__(self, message: str, deleted_count: int): super().__init__(message) -def delete_logs_older_than(cutoff: datetime) -> int: - """Delete old logs globally in committed batches up to a fixed ID.""" - cutoff_timestamp = cutoff.timestamp() - qualifying = models.RulebookProcessLog.objects.filter( - log_timestamp__lt=cutoff_timestamp +def resolve_activation_ids( + activation_ids: list[int] | None, + activation_names: list[str] | None, +) -> set[int] | None: + """Validate every selector and return its union, or None for global.""" + if activation_ids is None and activation_names is None: + return None + if activation_ids is not None and ( + not activation_ids + or any( + not isinstance(value, int) or isinstance(value, bool) or value <= 0 + for value in activation_ids + ) + ): + raise ValueError("Activation IDs must be positive integers.") + if activation_names is not None and ( + not activation_names + or any( + not isinstance(value, str) or not value.strip() + for value in activation_names + ) + ): + raise ValueError("Activation names cannot be blank.") + + requested_ids = set(activation_ids or []) + requested_names = set(activation_names or []) + existing_ids = set( + models.Activation.objects.filter(id__in=requested_ids).values_list( + "id", flat=True + ) ) - max_id = qualifying.aggregate(max_id=Max("id"))["max_id"] - if max_id is None: + if missing := requested_ids - existing_ids: + raise ValueError(f"Unknown activation IDs: {sorted(missing)}.") + + named_activations = models.Activation.objects.filter( + name__in=requested_names + ).values_list("id", "name") + found_names = set() + for activation_id, name in named_activations: + existing_ids.add(activation_id) + found_names.add(name) + if missing := requested_names - found_names: + raise ValueError(f"Unknown activation names: {sorted(missing)}.") + return existing_ids + + +def _ordinary_logs( + process_id: int, + cutoff_timestamp: float, + selected_ids: set[int] | None, +): + logs = models.RulebookProcessLog.objects.filter( + activation_instance_id=process_id, + log_timestamp__lt=cutoff_timestamp, + ) + if selected_ids is not None: + logs = logs.filter(activation_instance__activation_id__in=selected_ids) + return logs.exclude(log_created_at=PURGE_MARKER_CREATED_AT).exclude( + log_created_at__isnull=True, + log__regex=LEGACY_MARKER_PATTERN, + ) + + +def _marker_text( + cutoff: datetime, + purge_time: datetime, + count: int, + tracking_id: str | None, + orphaned: bool, + internal_job_uuid: str | None, +) -> str: + cutoff_text = _utc_text(cutoff) + purge_text = _utc_text(purge_time) + text = ( + f"All log records older than {cutoff_text} were purged at " + f"{purge_text}. Deleted {count} log rows." + ) + if internal_job_uuid is not None: + text += f" Job ID: {internal_job_uuid}." + if tracking_id and tracking_id.strip(): + text += f" Log Tracking id {tracking_id.strip()}." + elif orphaned: + text += " Log Tracking id unavailable (orphaned process)." + return text + + +def delete_logs_older_than( + cutoff: datetime, + *, + activation_ids: list[int] | None = None, + activation_names: list[str] | None = None, + audit_trail: bool = True, + internal_job_uuid: str | None = None, +) -> int: + """Purge ordinary logs per process in committed, bounded ID batches.""" + selected_ids = resolve_activation_ids(activation_ids, activation_names) + cutoff_timestamp = cutoff.timestamp() + processes = models.RulebookProcess.objects.all() + if selected_ids is not None: + processes = processes.filter(activation_id__in=selected_ids) + highest_process_id = processes.aggregate(max_id=Max("id"))["max_id"] + if highest_process_id is None: return 0 deleted_count = 0 - last_id = 0 + last_process_id = 0 model_label = models.RulebookProcessLog._meta.label try: - while last_id < max_id: - batch_ids = list( - qualifying.filter(id__gt=last_id, id__lte=max_id) + while last_process_id < highest_process_id: + process_batch = list( + processes.filter( + id__gt=last_process_id, id__lte=highest_process_id + ) .order_by("id") - .values_list("id", flat=True)[:DELETE_BATCH_SIZE] + .values_list( + "id", "activation_id", "activation__log_tracking_id" + )[:DELETE_BATCH_SIZE] ) - if not batch_ids: + if not process_batch: break - with transaction.atomic(): - _, deleted_by_model = models.RulebookProcessLog.objects.filter( - id__in=batch_ids, - log_timestamp__lt=cutoff_timestamp, - ).delete() - deleted_count += deleted_by_model.get(model_label, 0) - last_id = batch_ids[-1] + for process_id, activation_id, tracking_id in process_batch: + qualifying = _ordinary_logs( + process_id, cutoff_timestamp, selected_ids + ) + highest_log_id = qualifying.aggregate(max_id=Max("id"))[ + "max_id" + ] + if highest_log_id is None: + continue + + last_log_id = 0 + process_deleted = 0 + marker_id = None + while last_log_id < highest_log_id: + batch_ids = list( + qualifying.filter( + id__gt=last_log_id, id__lte=highest_log_id + ) + .order_by("id") + .values_list("id", flat=True)[:DELETE_BATCH_SIZE] + ) + if not batch_ids: + break + with transaction.atomic(): + _, per_model_counts = ( + _ordinary_logs( + process_id, cutoff_timestamp, selected_ids + ) + .filter(id__in=batch_ids) + .delete() + ) + batch_deleted = per_model_counts.get(model_label, 0) + if audit_trail and batch_deleted: + purge_time = datetime.now(timezone.utc) + marker_timestamp = max( + ceil(purge_time.timestamp()), + ceil(cutoff_timestamp), + ) + marker_text = _marker_text( + cutoff, + purge_time, + process_deleted + batch_deleted, + tracking_id, + activation_id is None, + internal_job_uuid, + ) + if marker_id is None: + marker = ( + models.RulebookProcessLog.objects.create( + activation_instance_id=process_id, + log=marker_text, + log_timestamp=marker_timestamp, + log_created_at=PURGE_MARKER_CREATED_AT, + ) + ) + marker_id = marker.id + else: + updated = ( + models.RulebookProcessLog.objects.filter( + pk=marker_id + ).update( + log=marker_text, + log_timestamp=marker_timestamp, + ) + ) + if updated != 1: + raise RuntimeError( + "The current purge marker disappeared." + ) + process_deleted += batch_deleted + deleted_count += batch_deleted + last_log_id = batch_ids[-1] + last_process_id = process_batch[-1][0] except Exception as exc: raise LogPurgeError( - f"Log deletion failed after {deleted_count} committed rows: {exc}", + f"Log purge failed after {deleted_count} committed rows: {exc}", deleted_count, ) from exc return deleted_count - - -def create_audit_trail( - cutoff: datetime, - *, - activation_ids: list[int] | None = None, - activation_names: list[str] | None = None, -) -> int: - """Create opt-in audit logs for all or selected activation processes.""" - instances = models.RulebookProcess.objects.all() - if activation_ids or activation_names: - instances = instances.filter( - Q(activation_id__in=activation_ids or []) - | Q(activation__name__in=activation_names or []) - | Q(activation__isnull=True) - ) - - max_id = instances.aggregate(max_id=Max("id"))["max_id"] - if max_id is None: - return 0 - - now = timezone.now() - cutoff_text = cutoff.strftime("%Y-%m-%d %H:%M:%S UTC") - audit_text = ( - f"All log records older than {cutoff_text} were purged at " - f"{now.strftime('%Y-%m-%d %H:%M:%S UTC')}." - ) - created = 0 - last_id = 0 - while last_id < max_id: - ids = list( - instances.filter(id__gt=last_id, id__lte=max_id) - .order_by("id") - .values_list("id", flat=True)[:DELETE_BATCH_SIZE] - ) - if not ids: - break - try: - with transaction.atomic(): - batch = [ - models.RulebookProcessLog( - log=audit_text, - activation_instance_id=instance_id, - log_timestamp=int(now.timestamp()), - ) - for instance_id in ids - ] - models.RulebookProcessLog.objects.bulk_create(batch) - created += len(batch) - last_id = ids[-1] - except Exception as exc: - raise LogPurgeError( - f"Audit trail creation failed after deleting logs; " - f"{created} audit rows were committed: {exc}", - 0, - ) from exc - return created diff --git a/src/aap_eda/tasks/management.py b/src/aap_eda/tasks/management.py index eb4f52008..9602b1220 100644 --- a/src/aap_eda/tasks/management.py +++ b/src/aap_eda/tasks/management.py @@ -22,6 +22,7 @@ from django.core.management import call_command from aap_eda import utils +from aap_eda.core.utils.delete_log_util import LogPurgeError logger = logging.getLogger(__name__) @@ -32,21 +33,22 @@ def submit_log_purge( *, + before_date: str | None = None, retention_duration: str | None = None, - audit_trail: bool = False, + audit_trail: bool = True, activation_ids: list[int] | None = None, activation_names: list[str] | None = None, ) -> str: - """Submit a fixed-purpose global log purge task.""" - command_options = {} + """Submit a fixed-purpose log purge task.""" + command_options = {"audit_trail": audit_trail} + if before_date is not None: + command_options["date"] = before_date if retention_duration is not None: command_options["retention_duration"] = retention_duration - if audit_trail: - command_options["audit_trail"] = True - if activation_ids: - command_options["activation-ids"] = activation_ids - if activation_names: - command_options["activation-names"] = activation_names + if activation_ids is not None: + command_options["activation-ids"] = activation_ids + if activation_names is not None: + command_options["activation-names"] = activation_names return aap_eda_manage_commands( "purge_log_records", @@ -64,6 +66,8 @@ def aap_eda_manage_commands( This generic entry point remains available to internal callers. """ job_id = str(uuid4()) + if command == "purge_log_records": + command_options["internal-job-uuid"] = job_id job_data, _ = submit_task( _aap_eda_manage, args=(job_id, command, command_options), @@ -104,13 +108,25 @@ def _aap_eda_manage(job_id: str, command: str, command_options: dict) -> dict: command_output = call_command( command, no_color=True, **command_options ) - except Exception: - logger.exception( - "Management command failed job_id=%s command=%s " - "status=failed", - job_id, - command, - ) + except Exception as exc: + cause = exc.__cause__ + if command == "purge_log_records" and isinstance( + cause, LogPurgeError + ): + logger.exception( + "Management command failed job_id=%s command=%s " + "status=failed deleted_count=%d", + job_id, + command, + cause.deleted_count, + ) + else: + logger.exception( + "Management command failed job_id=%s command=%s " + "status=failed", + job_id, + command, + ) raise result = { diff --git a/tests/integration/api/test_log_purge.py b/tests/integration/api/test_log_purge.py index 5d7cb76c9..599739d1d 100644 --- a/tests/integration/api/test_log_purge.py +++ b/tests/integration/api/test_log_purge.py @@ -20,7 +20,9 @@ @pytest.mark.django_db -def test_superuser_queues_global_purge_on_default_queue(superuser_client): +def test_superuser_queues_scoped_purge_with_one_eda_job_id( + superuser_client, default_activation, new_activation +): with mock.patch( "aap_eda.tasks.management.uuid4", return_value=JOB_ID ), mock.patch( @@ -31,9 +33,8 @@ def test_superuser_queues_global_purge_on_default_queue(superuser_client): PURGE_URL, { "retention_duration": "P30D", - "audit_trail": True, - "activation_ids": [12, 13], - "activation_names": ["production"], + "activation_ids": [default_activation.id], + "activation_names": [new_activation.name], }, format="json", ) @@ -53,12 +54,63 @@ def test_superuser_queues_global_purge_on_default_queue(superuser_client): { "retention_duration": "P30D", "audit_trail": True, - "activation-ids": [12, 13], - "activation-names": ["production"], + "activation-ids": [default_activation.id], + "activation-names": [new_activation.name], + "internal-job-uuid": str(JOB_ID), }, ) +@pytest.mark.django_db +def test_superuser_queues_global_purge_with_absolute_date(superuser_client): + with mock.patch( + "aap_eda.tasks.management.uuid4", return_value=JOB_ID + ), mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": str(JOB_ID)}, "default"), + ) as submit_task: + response = superuser_client.post( + PURGE_URL, {"before_date": "2020-01-01"}, format="json" + ) + + assert response.status_code == status.HTTP_202_ACCEPTED + assert response.data == {"job_id": str(JOB_ID)} + assert submit_task.call_args.kwargs["args"][2] == { + "date": "2020-01-01", + "audit_trail": True, + "internal-job-uuid": str(JOB_ID), + } + + +@pytest.mark.django_db +def test_api_keeps_activation_scope_when_audit_is_disabled( + superuser_client, default_activation +): + with mock.patch( + "aap_eda.tasks.management.uuid4", return_value=JOB_ID + ), mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": str(JOB_ID)}, "default"), + ) as submit_task: + response = superuser_client.post( + PURGE_URL, + { + "before_date": "2020-01-01", + "activation_ids": [default_activation.id], + "audit_trail": False, + }, + format="json", + ) + + assert response.status_code == status.HTTP_202_ACCEPTED + assert submit_task.call_args.kwargs["args"][2] == { + "date": "2020-01-01", + "audit_trail": False, + "activation-ids": [default_activation.id], + "internal-job-uuid": str(JOB_ID), + } + + @pytest.mark.django_db def test_purge_requires_superuser(admin_client): response = admin_client.post(PURGE_URL, {}, format="json") @@ -75,14 +127,22 @@ def test_anonymous_purge_uses_api_permission_denial(base_client): @pytest.mark.parametrize( "payload", [ + {}, + {"before_date": "2999-01-01"}, + {"before_date": "not-a-date"}, + {"before_date": "2020-01-01", "retention_duration": "P30D"}, {"retention_duration": "not-a-duration"}, {"retention_duration": "P0D"}, {"retention_duration": "-P1D"}, - {"before_date": "2026-01-01"}, - {"activation_ids": [0]}, - {"activation_ids": []}, - {"activation_names": [""]}, - {"activation_names": [" "]}, + {"before_date": "2020-01-01", "activation_ids": [0]}, + {"before_date": "2020-01-01", "activation_ids": []}, + {"before_date": "2020-01-01", "activation_names": [""]}, + {"before_date": "2020-01-01", "activation_names": [" "]}, + {"before_date": "2020-01-01", "activation_ids": [99999999]}, + { + "before_date": "2020-01-01", + "activation_names": ["missing-activation"], + }, ], ) def test_invalid_purge_request_is_rejected_before_enqueue( @@ -95,13 +155,36 @@ def test_invalid_purge_request_is_rejected_before_enqueue( submit_task.assert_not_called() +@pytest.mark.django_db +@pytest.mark.parametrize("invalid_kind", ["id", "name"]) +def test_mixed_valid_and_unknown_scope_never_queues( + superuser_client, default_activation, invalid_kind +): + payload = { + "before_date": "2020-01-01", + "activation_ids": [default_activation.id], + } + if invalid_kind == "id": + payload["activation_ids"].append(default_activation.id + 99999999) + else: + payload["activation_names"] = ["missing-activation"] + + with mock.patch("aap_eda.tasks.management.submit_task") as submit_task: + response = superuser_client.post(PURGE_URL, payload, format="json") + + assert response.status_code == status.HTTP_400_BAD_REQUEST + submit_task.assert_not_called() + + @pytest.mark.django_db def test_enqueue_failure_is_not_reported_as_accepted(superuser_client): with mock.patch( "aap_eda.tasks.management.submit_task", side_effect=RuntimeError("queue unavailable"), ): - response = superuser_client.post(PURGE_URL, {}, format="json") + response = superuser_client.post( + PURGE_URL, {"before_date": "2020-01-01"}, format="json" + ) assert response.status_code == status.HTTP_500_INTERNAL_SERVER_ERROR assert response.data == {"detail": "Unable to queue log purge job."} diff --git a/tests/integration/api/test_openapi.py b/tests/integration/api/test_openapi.py index a7950f2e5..4857a1101 100644 --- a/tests/integration/api/test_openapi.py +++ b/tests/integration/api/test_openapi.py @@ -107,11 +107,14 @@ def test_log_purge_openapi_contract(admin_client): ] request_properties = request_schema["properties"] assert set(request_properties) == { + "before_date", "retention_duration", "audit_trail", "activation_ids", "activation_names", } + assert request_properties["audit_trail"]["default"] is True + assert "internal_job_uuid" not in request_properties responses = operation["responses"] assert {"202", "400", "403"}.issubset(responses) diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index c0a04d9f1..161ac8bfe 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -13,7 +13,9 @@ # limitations under the License. from datetime import datetime, timedelta, timezone as datetime_timezone +from math import ceil from unittest import mock +from uuid import uuid4 import pytest from django.core.management import call_command @@ -163,35 +165,33 @@ def prepare_log_records( @pytest.mark.django_db -def test_purge_log_records_default_retention_is_disabled(capsys): +def test_purge_log_records_requires_explicit_cutoff_even_with_setting(): with override_settings(ACTIVATION_DB_LOG_RETENTION_DAYS=0): - output = call_command("purge_log_records") - assert output.startswith("No logs purged") - assert "No logs purged" in capsys.readouterr().out + with pytest.raises(CommandError, match="Exactly one"): + call_command("purge_log_records") @pytest.mark.django_db -def test_purge_log_records_with_nonexist_activation(capsys): - # With global purging, even non-existent activation filters will - # still purge old logs globally (if any exist) - args = ("--activation-ids", "42", "--date", "2024-10-01") - call_command("purge_log_records", *args) - captured = capsys.readouterr() - - # Should report either no old logs found, or global purge count - assert ( - "No log records found older than 2024-10-01" in captured.out - or "Purged" in captured.out +@pytest.mark.parametrize( + "selector, expected", + [ + (("--activation-ids", "999999999"), "Unknown activation IDs"), + (("--activation-names", "missing-name"), "Unknown activation names"), + ], +) +def test_unknown_selector_rejects_before_deleting( + prepare_log_records, selector, expected +): + original_ids = set( + models.RulebookProcessLog.objects.values_list("id", flat=True) ) - args = ("--activation-names", "na", "--date", "2024-10-01") - call_command("purge_log_records", *args) - captured = capsys.readouterr() + with pytest.raises(CommandError, match=expected): + call_command("purge_log_records", *selector, "--date", "2024-10-01") - assert ( - "No log records found older than 2024-10-01" in captured.out - or "Purged" in captured.out - ) + assert set( + models.RulebookProcessLog.objects.values_list("id", flat=True) + ) == (original_ids) @pytest.mark.parametrize( @@ -214,11 +214,10 @@ def test_purge_log_records( if identifiers == "ids": args = ( "--activation-ids", - activations[0].id, - activations[1].id, + str(activations[0].id), + str(activations[1].id), "--date", date_str, - "--audit-trail", ) elif identifiers == "names": args = ( @@ -227,13 +226,11 @@ def test_purge_log_records( activations[1].name, "--date", date_str, - "--audit-trail", ) else: args = ( "--date", date_str, - "--audit-trail", ) call_command(command, *args) @@ -241,22 +238,21 @@ def test_purge_log_records( captured = capsys.readouterr() if cutoff_days < 10: - # Global purge: all original logs deleted, audit logs created for - # all 4 RulebookProcess instances + # All four processes lose rows and receive their own marker. assert models.RulebookProcessLog.objects.count() == 4 for log_record in models.RulebookProcessLog.objects.all(): assert f"All log records older than {date_str}" in log_record.log + assert "Deleted 2 log rows." in log_record.log else: - # Global purge: only 30-day logs deleted, 10-day logs remain, - # audit logs created for all 4 RulebookProcess instances - assert models.RulebookProcessLog.objects.count() == 8 + # Only the two older processes lose rows and receive markers. + assert models.RulebookProcessLog.objects.count() == 6 - # Check audit logs exist for all instances audit_logs = models.RulebookProcessLog.objects.filter( log__contains=f"All log records older than {date_str}" ) - assert audit_logs.count() == 4 + assert audit_logs.count() == 2 + assert all("Deleted 2 log rows." in row.log for row in audit_logs) # Check that 10-day logs still exist (not purged) original_logs = models.RulebookProcessLog.objects.exclude( @@ -265,7 +261,9 @@ def test_purge_log_records( assert original_logs.count() == 4 assert "Purged" in captured.out - assert "globally" in captured.out + assert ( + "globally" if identifiers == "none" else "for selected activations" + ) in captured.out @pytest.fixture @@ -365,154 +363,58 @@ def null_activation_test_data( @pytest.mark.django_db -def test_purge_without_activation_filter_handles_null_correctly( - null_activation_test_data, capsys +def test_global_purge_includes_orphan_and_marks_each_process( + null_activation_test_data, ): - """Test purge without activation filter includes NULL records. - This tests the customer scenario.""" - - # Get initial counts - initial_log_count = models.RulebookProcessLog.objects.filter( - log__contains="for null test" - ).count() - assert initial_log_count == 4, "Should have 4 test log records" - - # Test purge without activation filtering (customer's command scenario) cutoff_date = (timezone.now() - timedelta(days=10)).strftime("%Y-%m-%d") + output = call_command("purge_log_records", "--date", cutoff_date) - call_command( - "purge_log_records", - "--date", - cutoff_date, - "--audit-trail", - verbosity=3, - ) - - captured = capsys.readouterr() - - # Check that logs were purged - remaining_test_logs = models.RulebookProcessLog.objects.filter( - log__contains="for null test" - ).exclude(log__contains="purged") - - # Both NULL and normal activation logs should be purged in this scenario - assert ( - remaining_test_logs.count() == 0 - ), "All test logs should be purged when no activation filter is used" - assert "Purged" in captured.out - assert "globally" in captured.out - - -@pytest.mark.django_db -def test_purge_with_activation_filter_now_includes_null_fix( - null_activation_test_data, capsys -): - """Purge includes NULL records with filters.""" - - # Get initial counts - initial_log_count = models.RulebookProcessLog.objects.filter( + assert output.startswith("Purged 4 log records") + assert "globally" in output + assert not models.RulebookProcessLog.objects.filter( log__contains="for null test" - ).count() - assert initial_log_count == 4, "Should have 4 test log records" - - # Test purge WITH activation filtering - this should now include - # NULL records - cutoff_date = (timezone.now() - timedelta(days=10)).strftime("%Y-%m-%d") - activation_id = null_activation_test_data["activation"].id - - call_command( - "purge_log_records", - "--activation-ids", - str(activation_id), - "--date", - cutoff_date, - "--audit-trail", - verbosity=3, + ).exists() + markers = models.RulebookProcessLog.objects.filter( + log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT ) - - captured = capsys.readouterr() - - # Check what logs remain - remaining_test_logs = models.RulebookProcessLog.objects.filter( - log__contains="for null test" - ).exclude(log__contains="purged") - - # Verify the fix: NULL activation logs should now be purged - null_activation_logs = [ - log - for log in remaining_test_logs - if log.activation_instance.activation_id is None - ] - - # This validates the fix: NULL activation logs should now be - # included in purge - assert len(null_activation_logs) == 0, ( - "All NULL activation logs should be purged " - "when using --activation-ids filter" + assert markers.count() == 2 + orphan_marker = markers.get( + activation_instance=null_activation_test_data["null_process"] + ) + assert "Deleted 2 log rows." in orphan_marker.log + assert "Log Tracking id unavailable (orphaned process)." in ( + orphan_marker.log ) - - # Also verify that normal activation logs WERE purged - normal_activation_logs = [ - log - for log in remaining_test_logs - if log.activation_instance.activation_id is not None - ] - assert ( - len(normal_activation_logs) == 0 - ), "Normal activation logs should have been purged" - - assert "Created 2 audit trail entries." in captured.out @pytest.mark.django_db -def test_purge_with_activation_name_filter_also_includes_null_fix( - null_activation_test_data, capsys -): - """Test that the fix also works when using --activation-names parameter.""" - - # Get initial counts - initial_log_count = models.RulebookProcessLog.objects.filter( - log__contains="for null test" - ).count() - assert initial_log_count == 4, "Should have 4 test log records" - - # Test purge with activation NAME filtering - should now include - # NULL records (fix) +@pytest.mark.parametrize("selector", ["id", "name"]) +def test_scoped_purge_preserves_orphan(null_activation_test_data, selector): cutoff_date = (timezone.now() - timedelta(days=10)).strftime("%Y-%m-%d") - activation_name = null_activation_test_data["activation"].name - - call_command( - "purge_log_records", - "--activation-names", - activation_name, - "--date", - cutoff_date, - "--audit-trail", - verbosity=3, + activation = null_activation_test_data["activation"] + option, value = ( + ("--activation-ids", str(activation.id)) + if selector == "id" + else ("--activation-names", activation.name) ) - captured = capsys.readouterr() - - # Check what logs remain - remaining_test_logs = models.RulebookProcessLog.objects.filter( - log__contains="for null test" - ).exclude(log__contains="purged") - - # Verify the fix: NULL activation logs should now be purged - # with name filtering too - null_activation_logs = [ - log - for log in remaining_test_logs - if log.activation_instance.activation_id is None - ] - - # This validates the fix works with activation name filtering - assert len(null_activation_logs) == 0, ( - "All NULL activation logs should be purged " - "when using --activation-names filter" + output = call_command( + "purge_log_records", option, value, "--date", cutoff_date ) - assert "Created 2 audit trail entries." in captured.out + assert output.startswith("Purged 2 log records") + assert "for selected activations" in output + assert ( + models.RulebookProcessLog.objects.filter( + activation_instance=null_activation_test_data["null_process"], + log__contains="for null test", + ).count() + == 2 + ) + assert not models.RulebookProcessLog.objects.filter( + activation_instance=null_activation_test_data["normal_process"], + log__contains="for null test", + ).exists() @pytest.mark.django_db @@ -520,7 +422,9 @@ def test_purge_without_audit_trail_does_not_create_audit_logs( prepare_log_records, capsys ): cutoff = (timezone.now() - timedelta(days=15)).strftime("%Y-%m-%d") - output = call_command("purge_log_records", "--date", cutoff) + output = call_command( + "purge_log_records", "--date", cutoff, "--audit-trail=false" + ) assert output.startswith("Purged 4 log records") assert models.RulebookProcessLog.objects.count() == 4 @@ -531,12 +435,12 @@ def test_purge_without_audit_trail_does_not_create_audit_logs( @pytest.mark.django_db -def test_purge_retention_setting_deletes_globally(prepare_log_records): +def test_purge_retention_setting_does_not_supply_cutoff(prepare_log_records): with override_settings(ACTIVATION_DB_LOG_RETENTION_DAYS=15): - output = call_command("purge_log_records") + with pytest.raises(CommandError, match="Exactly one"): + call_command("purge_log_records") - assert output.startswith("Purged 4 log records") - assert models.RulebookProcessLog.objects.count() == 4 + assert models.RulebookProcessLog.objects.count() == 8 @pytest.mark.django_db @@ -547,6 +451,8 @@ def test_purge_retention_setting_deletes_globally(prepare_log_records): ("--retention-duration", "P0D"), ("--retention-duration", "-P1D"), ("--retention-duration", "not-a-duration"), + ("--date", "not-a-date"), + ("--date", "2999-01-01"), ], ) def test_purge_rejects_invalid_retention_arguments(args): @@ -614,7 +520,7 @@ def test_retention_cutoff_calendar_and_timezone_policy( @pytest.mark.parametrize("filter_by", ["ids", "names"]) @pytest.mark.django_db -def test_activation_filter_selects_audit_targets_only( +def test_activation_filter_limits_deletion_and_markers( prepare_log_records, filter_by ): selected_activation = prepare_log_records[0] @@ -632,13 +538,12 @@ def test_activation_filter_selects_audit_targets_only( value, "--date", cutoff, - "--audit-trail", ) audit_logs = models.RulebookProcessLog.objects.filter( log__contains="were purged at" ) - assert output.startswith("Purged 8 log records") + assert output.startswith("Purged 4 log records") assert audit_logs.count() == 2 assert set( audit_logs.values_list("activation_instance__activation_id", flat=True) @@ -649,9 +554,16 @@ def test_activation_filter_selects_audit_targets_only( .timestamp() ) assert all( - log_timestamp > cutoff_timestamp + log_timestamp >= cutoff_timestamp for log_timestamp in audit_logs.values_list("log_timestamp", flat=True) ) + assert ( + models.RulebookProcessLog.objects.filter( + activation_instance__activation_id=prepare_log_records[1].id, + log__startswith="activation-instance-", + ).count() + == 4 + ) @pytest.mark.django_db @@ -711,6 +623,10 @@ def test_retention_batches_continue_after_more_than_one_batch( assert not models.RulebookProcessLog.objects.filter( pk__in=[log.pk for log in logs] ).exists() + marker = models.RulebookProcessLog.objects.get( + log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT + ) + assert "Deleted 5 log rows." in marker.log @pytest.mark.django_db @@ -755,6 +671,32 @@ def insert_after_first_batch(queryset): assert models.RulebookProcessLog.objects.filter(pk=new_log[0].pk).exists() +@pytest.mark.django_db +def test_batch_delete_rechecks_cutoff_after_candidate_selection( + default_activation_instance, monkeypatch +): + log = models.RulebookProcessLog.objects.create( + log="changed-between-selection-and-delete", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + original_delete = QuerySet.delete + + def move_log_past_cutoff_before_delete(queryset): + models.RulebookProcessLog.objects.filter(pk=log.pk).update( + log_timestamp=3 + ) + return original_delete(queryset) + + monkeypatch.setattr(QuerySet, "delete", move_log_past_cutoff_before_delete) + cutoff = datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) + + assert delete_log_util.delete_logs_older_than(cutoff) == 0 + log.refresh_from_db() + assert log.log_timestamp == 3 + assert models.RulebookProcessLog.objects.count() == 1 + + @pytest.mark.django_db def test_retention_with_no_matching_rows_returns_zero( default_activation_instance, @@ -772,7 +714,7 @@ def test_retention_with_no_matching_rows_returns_zero( ) -@pytest.mark.django_db +@pytest.mark.django_db(transaction=True) def test_retention_failure_reports_committed_batch_count( default_activation_instance, monkeypatch ): @@ -803,7 +745,17 @@ def fail_second_delete(queryset): delete_log_util.delete_logs_older_than(cutoff) assert error.value.deleted_count == 1 - assert models.RulebookProcessLog.objects.count() == 2 + assert models.RulebookProcessLog.objects.count() == 3 + marker = models.RulebookProcessLog.objects.get( + log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT + ) + assert "Deleted 1 log rows." in marker.log + assert ( + models.RulebookProcessLog.objects.filter( + log__startswith="partial-" + ).count() + == 2 + ) @pytest.mark.django_db @@ -845,3 +797,232 @@ def test_retention_duration_cli_uses_execution_time_cutoff( ).count() == 2 ) + + +@pytest.mark.django_db +def test_mixed_selectors_form_union_and_validate_all_before_delete( + prepare_log_records, +): + first, second = prepare_log_records + cutoff = (timezone.now() - timedelta(days=5)).strftime("%Y-%m-%d") + original_ids = set( + models.RulebookProcessLog.objects.values_list("id", flat=True) + ) + + with pytest.raises(CommandError, match="Unknown activation names"): + call_command( + "purge_log_records", + "--activation-ids", + str(first.id), + "--activation-names", + second.name, + "missing-name", + "--date", + cutoff, + ) + assert set( + models.RulebookProcessLog.objects.values_list("id", flat=True) + ) == (original_ids) + + output = call_command( + "purge_log_records", + "--activation-ids", + str(first.id), + "--activation-names", + second.name, + "--date", + cutoff, + "--audit-trail=false", + ) + assert output.startswith("Purged 8 log records") + assert "for selected activations" in output + assert not models.RulebookProcessLog.objects.exists() + + +@pytest.mark.django_db +@pytest.mark.parametrize( + "options, error", + [ + ({"activation-ids": []}, "Activation IDs must"), + ({"activation-ids": [0]}, "Activation IDs must"), + ({"activation-names": [" "]}, "Activation names cannot"), + ], +) +def test_invalid_programmatic_selectors_never_delete( + prepare_log_records, options, error +): + with pytest.raises(CommandError, match=error): + call_command("purge_log_records", date="2024-10-01", **options) + assert models.RulebookProcessLog.objects.count() == 8 + + +@pytest.mark.django_db +@pytest.mark.parametrize( + "args", + [ + ("--audit-trail",), + ("--no-audit-trail",), + ("--audit-trail=maybe",), + ], +) +def test_audit_cli_rejects_unsupported_forms(prepare_log_records, args): + with pytest.raises(CommandError): + call_command("purge_log_records", "--date", "2024-10-01", *args) + assert models.RulebookProcessLog.objects.count() == 8 + + +@pytest.mark.django_db +def test_zero_row_result_creates_no_marker(default_activation_instance): + log = models.RulebookProcessLog.objects.create( + log="newer-than-cutoff", + activation_instance=default_activation_instance, + log_timestamp=int(timezone.now().timestamp()), + ) + output = call_command( + "purge_log_records", "--date", "2024-01-01", "--audit-trail=true" + ) + + assert output.startswith("Purged 0 log records") + assert "globally" in output + assert models.RulebookProcessLog.objects.get(pk=log.pk).log == ( + "newer-than-cutoff" + ) + assert models.RulebookProcessLog.objects.count() == 1 + + +@pytest.mark.django_db +def test_invalid_internal_uuid_rejected_before_deletion( + default_activation_instance, +): + log = models.RulebookProcessLog.objects.create( + log="old", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + with pytest.raises(CommandError, match="must be a UUID"): + call_command( + "purge_log_records", + date="2024-01-01", + **{"internal-job-uuid": "not-a-uuid"}, + ) + assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() + + +@pytest.mark.django_db +def test_cli_valid_internal_uuid_is_in_default_audit_marker( + default_activation_instance, +): + models.RulebookProcessLog.objects.create( + log="old", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + job_id = uuid4() + + output = call_command( + "purge_log_records", + "--date", + "2024-01-01", + "--audit-trail=true", + "--internal-job-uuid", + str(job_id), + ) + + assert output.startswith("Purged 1 log records") + marker = models.RulebookProcessLog.objects.get( + log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT + ) + assert f"Job ID: {job_id}." in marker.log + assert "Deleted 1 log rows." in marker.log + + +@pytest.mark.django_db +def test_prior_and_legacy_markers_are_never_counted_or_deleted( + default_activation_instance, +): + process = default_activation_instance + old_marker = models.RulebookProcessLog.objects.create( + activation_instance=process, + log=( + "All log records older than 2024-01-01 00:00:00 UTC were " + "purged at 2024-02-01 00:00:00 UTC." + ), + log_timestamp=1, + ) + ordinary = models.RulebookProcessLog.objects.create( + activation_instance=process, log="ordinary", log_timestamp=1 + ) + cutoff = datetime(2024, 3, 1, tzinfo=datetime_timezone.utc) + + assert delete_log_util.delete_logs_older_than(cutoff) == 1 + first_marker = models.RulebookProcessLog.objects.get( + log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT + ) + assert not models.RulebookProcessLog.objects.filter( + pk=ordinary.pk + ).exists() + assert models.RulebookProcessLog.objects.filter(pk=old_marker.pk).exists() + assert "Deleted 1 log rows." in first_marker.log + + models.RulebookProcessLog.objects.filter(pk=first_marker.pk).update( + log_timestamp=1 + ) + assert delete_log_util.delete_logs_older_than(cutoff) == 0 + assert models.RulebookProcessLog.objects.filter( + pk=first_marker.pk + ).exists() + assert models.RulebookProcessLog.objects.count() == 2 + + +@pytest.mark.django_db +def test_marker_uses_invocation_count_job_uuid_tracking_and_ceiled_timestamp( + default_activation_instance, +): + process = default_activation_instance + activation = process.activation + activation.log_tracking_id = " tracking-123 " + activation.save(update_fields=["log_tracking_id"]) + models.RulebookProcessLog.objects.create( + activation_instance=process, log="old", log_timestamp=1 + ) + job_id = uuid4() + cutoff = datetime( + 2024, 1, 1, 0, 0, 0, 500000, tzinfo=datetime_timezone.utc + ) + + before_purge = timezone.now() + assert ( + delete_log_util.delete_logs_older_than( + cutoff, internal_job_uuid=str(job_id) + ) + == 1 + ) + after_purge = timezone.now() + marker = models.RulebookProcessLog.objects.get( + log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT + ) + assert ( + max(ceil(before_purge.timestamp()), ceil(cutoff.timestamp())) + <= marker.log_timestamp + <= max(ceil(after_purge.timestamp()), ceil(cutoff.timestamp())) + ) + assert "2024-01-01 00:00:00.500000 UTC" in marker.log + assert "Deleted 1 log rows." in marker.log + assert f"Job ID: {job_id}." in marker.log + assert "Log Tracking id tracking-123." in marker.log + + models.RulebookProcessLog.objects.create( + activation_instance=process, log="another old row", log_timestamp=1 + ) + assert delete_log_util.delete_logs_older_than(cutoff) == 1 + markers = list( + models.RulebookProcessLog.objects.filter( + log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT + ) + ) + assert len(markers) == 2 + assert all("Deleted 1 log rows." in row.log for row in markers) + assert ( + "Job ID:" + not in next(row for row in markers if row.pk != marker.pk).log + ) diff --git a/tests/integration/tasks/test_management.py b/tests/integration/tasks/test_management.py index b40a4b39a..3eeec5d13 100644 --- a/tests/integration/tasks/test_management.py +++ b/tests/integration/tasks/test_management.py @@ -11,9 +11,9 @@ import pytest from dispatcherd.worker.exceptions import DispatcherCancel from django.core.management.base import CommandError -from django.test import override_settings from aap_eda.core import models +from aap_eda.core.utils.delete_log_util import LogPurgeError from aap_eda.tasks.management import ( LOG_PURGE_TASK_TIMEOUT_SECONDS, _aap_eda_manage, @@ -49,6 +49,7 @@ def test_submit_log_purge_uses_default_queue_uuid_and_purge_timeout(): "retention_duration": "P1M", "audit_trail": True, "activation-ids": [9], + "internal-job-uuid": job_id, }, ), "queue": "default", @@ -57,19 +58,47 @@ def test_submit_log_purge_uses_default_queue_uuid_and_purge_timeout(): } +@pytest.mark.django_db +def test_submit_log_purge_forwards_scope_when_audit_is_disabled(): + job_id = "712beb16-b7dd-40c9-aa29-a7f734376c7a" + with mock.patch( + "aap_eda.tasks.management.uuid4", return_value=job_id + ), mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": job_id}, "default"), + ) as submit_task: + submit_log_purge( + before_date="2020-01-01", + audit_trail=False, + activation_ids=[9], + activation_names=["production"], + ) + + assert submit_task.call_args.kwargs["args"][2] == { + "date": "2020-01-01", + "audit_trail": False, + "activation-ids": [9], + "activation-names": ["production"], + "internal-job-uuid": job_id, + } + + @pytest.mark.django_db def test_worker_invokes_purge_command_and_returns_deleted_count( - default_activation_instances, + default_activation_instance, + new_activation_instance, ): - logs = [ - models.RulebookProcessLog.objects.create( - log=f"worker-log-{index}", - activation_instance=instance, - log_timestamp=1, - ) - for index, instance in enumerate(default_activation_instances) - ] - job_id = "worker-job-17" + selected_log = models.RulebookProcessLog.objects.create( + log="selected worker log", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + retained_log = models.RulebookProcessLog.objects.create( + log="unselected worker log", + activation_instance=new_activation_instance, + log_timestamp=1, + ) + job_id = "712beb16-b7dd-40c9-aa29-a7f734376c7a" with mock.patch("aap_eda.tasks.management.logger.info") as log_info: result = _aap_eda_manage( @@ -78,9 +107,8 @@ def test_worker_invokes_purge_command_and_returns_deleted_count( { "date": "1970-01-02", "audit_trail": True, - "activation-ids": [ - default_activation_instances[0].activation_id - ], + "activation-ids": [default_activation_instance.activation_id], + "internal-job-uuid": job_id, }, ) @@ -88,26 +116,34 @@ def test_worker_invokes_purge_command_and_returns_deleted_count( "job_id": job_id, "command": "purge_log_records", "status": "completed", - "deleted": 2, + "deleted": 1, } assert not models.RulebookProcessLog.objects.filter( - pk__in=[log.pk for log in logs] + pk=selected_log.pk + ).exists() + assert models.RulebookProcessLog.objects.filter( + pk=retained_log.pk ).exists() - assert ( - models.RulebookProcessLog.objects.filter( - log__contains="were purged at" - ).count() - == 2 + markers = models.RulebookProcessLog.objects.filter( + activation_instance=default_activation_instance, + log__contains="were purged at", ) + assert markers.count() == 1 + assert "Deleted 1 log rows." in markers.get().log + assert f"Job ID: {job_id}." in markers.get().log + assert not models.RulebookProcessLog.objects.filter( + activation_instance=new_activation_instance, + log__contains="were purged at", + ).exists() assert any( call.args[0].startswith("Log purge finished") - and call.args[1:] == (job_id, "completed", 2) + and call.args[1:] == (job_id, "completed", 1) for call in log_info.call_args_list ) @pytest.mark.django_db -def test_worker_empty_options_obey_zero_retention_setting( +def test_worker_valid_cutoff_without_matching_logs_reports_no_op( default_activation_instance, ): models.RulebookProcessLog.objects.create( @@ -115,10 +151,10 @@ def test_worker_empty_options_obey_zero_retention_setting( activation_instance=default_activation_instance, log_timestamp=1, ) - with override_settings(ACTIVATION_DB_LOG_RETENTION_DAYS=0), mock.patch( - "aap_eda.tasks.management.logger.info" - ) as log_info: - result = _aap_eda_manage("no-op-job", "purge_log_records", {}) + with mock.patch("aap_eda.tasks.management.logger.info") as log_info: + result = _aap_eda_manage( + "no-op-job", "purge_log_records", {"date": "1970-01-01"} + ) assert result == { "job_id": "no-op-job", @@ -127,6 +163,7 @@ def test_worker_empty_options_obey_zero_retention_setting( "deleted": 0, } assert models.RulebookProcessLog.objects.filter(log="retained").exists() + assert models.RulebookProcessLog.objects.count() == 1 assert any( call.args[0].startswith("Log purge finished") and call.args[1:] == ("no-op-job", "no-op", 0) @@ -134,6 +171,21 @@ def test_worker_empty_options_obey_zero_retention_setting( ) +@pytest.mark.django_db +def test_worker_rejects_missing_cutoff_without_deleting( + default_activation_instance, +): + log = models.RulebookProcessLog.objects.create( + log="retained", + activation_instance=default_activation_instance, + log_timestamp=1, + ) + with pytest.raises(CommandError, match="Exactly one"): + _aap_eda_manage("missing-cutoff", "purge_log_records", {}) + + assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() + + @pytest.mark.django_db def test_worker_lock_contention_is_an_observable_skip(): class NotAcquired: @@ -184,6 +236,29 @@ def test_worker_propagates_command_and_timeout_failures(failure): assert log_exception.call_args.args[1] == "failed-job" +@pytest.mark.django_db +def test_worker_logs_committed_partial_count_on_purge_failure(): + failure = CommandError("later batch failed") + failure.__cause__ = LogPurgeError("later batch failed", 1000) + with mock.patch( + "aap_eda.tasks.management.call_command", side_effect=failure + ), mock.patch( + "aap_eda.tasks.management.logger.exception" + ) as log_exception, pytest.raises( + CommandError + ): + _aap_eda_manage( + "partial-job", "purge_log_records", {"date": "2020-01-01"} + ) + + assert "status=failed deleted_count=%d" in log_exception.call_args.args[0] + assert log_exception.call_args.args[1:] == ( + "partial-job", + "purge_log_records", + 1000, + ) + + @pytest.mark.django_db def test_worker_keeps_generic_management_command_scope(): with mock.patch( From 75864c897ccde37d8d1d4b0bc1389295023bca41 Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Fri, 23 Oct 2026 15:00:55 -0400 Subject: [PATCH 04/15] fix(logs): preserve purge scope from request to execution Unknown fields could silently turn a scoped request into a global purge. Resolving names before queueing also prevents a later rename from redirecting deletion to another activation. Assisted by: GPT-6 --- docs/development.md | 18 +++++-------- src/aap_eda/api/serializers/activation.py | 15 ++++++++--- tests/integration/api/test_log_purge.py | 32 +++++++++++++++++++++-- 3 files changed, 48 insertions(+), 17 deletions(-) diff --git a/docs/development.md b/docs/development.md index cc42c7e16..7142c1c30 100644 --- a/docs/development.md +++ b/docs/development.md @@ -469,7 +469,8 @@ Do **not** confuse the two — see the command docstring in - **Choose a cutoff:** Supply exactly one of `before_date` (midnight UTC in `YYYY-MM-DD` format) or a positive ISO 8601 `retention_duration`. Only rows with `log_timestamp` strictly before the cutoff qualify. Future UTC cutoffs - are rejected. + are rejected. A request without a cutoff returns HTTP 400 before a job is + queued; no logs are deleted. - **Choose the scope:** With no selectors, qualifying ordinary logs from every process are included, including processes without an activation. `activation_ids` and `activation_names` select the union of matching @@ -491,9 +492,11 @@ Content-Type: application/json - Use either `--date YYYY-MM-DD` or `--retention-duration P30D`. Calendar months and years in a duration are subtracted in UTC. If the target month - lacks the original day, the cutoff uses that month's final day. + lacks the original day, the cutoff uses that month's final day. Omitting both + options raises a command error before deletion - Use `--activation-ids 123 456`, `--activation-names name1 name2`, or both to - limit deletion to the selected activations. Omit both for a global purge. + limit deletion to the selected activations. Omit both to delete logs across + all activations. - Use `--audit-trail=true` or `--audit-trail=false`. A bare `--audit-trail` is invalid. - The optional `--internal-job-uuid` adds the EDA purge task UUID to markers. @@ -506,15 +509,6 @@ Content-Type: application/json partial count when audit is enabled. - When audit is enabled, each process that loses ordinary log rows gets one marker with its count for this invocation. -- This change makes no schema or data migration. New markers use a reserved - `log_created_at` value to exclude them from later purges. Earlier markers - with `log_created_at` set to null are excluded by an exact regular expression - matching the old fixed message format. No broad update of existing logs is - run. -- An ordinary log with that exact legacy text or the reserved timestamp is - indistinguishable from a marker and will also be retained. The regular - expression adds work to candidate and DELETE queries; measure performance - on a representative PostgreSQL database before drawing conclusions. **Check the outcome** diff --git a/src/aap_eda/api/serializers/activation.py b/src/aap_eda/api/serializers/activation.py index fe0279e40..86d036255 100644 --- a/src/aap_eda/api/serializers/activation.py +++ b/src/aap_eda/api/serializers/activation.py @@ -122,6 +122,12 @@ class LogPurgeRequestSerializer(serializers.Serializer): ) def validate(self, attrs): + unknown_fields = set(self.initial_data) - set(self.fields) + if unknown_fields: + raise serializers.ValidationError( + {field: "Unknown field." for field in sorted(unknown_fields)} + ) + before_date = attrs.get("before_date") duration = attrs.get("retention_duration") if (before_date is None) == (duration is None): @@ -146,12 +152,15 @@ def validate(self, attrs): ) from exc if "activation_ids" in attrs or "activation_names" in attrs: try: - resolve_activation_ids( - attrs.get("activation_ids"), - attrs.get("activation_names"), + attrs["activation_ids"] = sorted( + resolve_activation_ids( + attrs.get("activation_ids"), + attrs.get("activation_names"), + ) ) except ValueError as exc: raise serializers.ValidationError(str(exc)) from exc + attrs.pop("activation_names", None) return attrs diff --git a/tests/integration/api/test_log_purge.py b/tests/integration/api/test_log_purge.py index 599739d1d..24ecf4c5c 100644 --- a/tests/integration/api/test_log_purge.py +++ b/tests/integration/api/test_log_purge.py @@ -54,13 +54,37 @@ def test_superuser_queues_scoped_purge_with_one_eda_job_id( { "retention_duration": "P30D", "audit_trail": True, - "activation-ids": [default_activation.id], - "activation-names": [new_activation.name], + "activation-ids": sorted( + [default_activation.id, new_activation.id] + ), "internal-job-uuid": str(JOB_ID), }, ) +@pytest.mark.django_db +def test_name_only_scope_is_queued_as_activation_id( + superuser_client, default_activation +): + with mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": str(JOB_ID)}, "default"), + ) as submit_task: + response = superuser_client.post( + PURGE_URL, + { + "before_date": "2020-01-01", + "activation_names": [default_activation.name], + }, + format="json", + ) + + assert response.status_code == status.HTTP_202_ACCEPTED + options = submit_task.call_args.kwargs["args"][2] + assert options["activation-ids"] == [default_activation.id] + assert "activation-names" not in options + + @pytest.mark.django_db def test_superuser_queues_global_purge_with_absolute_date(superuser_client): with mock.patch( @@ -139,6 +163,10 @@ def test_anonymous_purge_uses_api_permission_denial(base_client): {"before_date": "2020-01-01", "activation_names": [""]}, {"before_date": "2020-01-01", "activation_names": [" "]}, {"before_date": "2020-01-01", "activation_ids": [99999999]}, + {"before_date": "2020-01-01", "activation_id": 1}, + {"before_date": "2020-01-01", "activation_id": "invalid"}, + {"before_date": "2020-01-01", "activation_id": None}, + {"before_date": "2020-01-01", "activation_namess": ["demo"]}, { "before_date": "2020-01-01", "activation_names": ["missing-activation"], From 372b954591fb83c1ab141484b4f962595755c8ba Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Fri, 23 Oct 2026 15:28:55 -0400 Subject: [PATCH 05/15] feat(logs): support full purge with fresh audit markers Customers need a way to clear accumulated logs regardless of age while retaining evidence that a purge occurred. Make this available through the CLI and API using the same purge command. Assisted by: GPT-6 --- docs/development.md | 36 +++- src/aap_eda/api/serializers/activation.py | 30 +++- src/aap_eda/api/views/activation.py | 12 +- .../management/commands/purge_log_records.py | 46 +++++- src/aap_eda/core/utils/delete_log_util.py | 70 +++++--- src/aap_eda/tasks/management.py | 3 + tests/integration/api/test_log_purge.py | 32 ++++ tests/integration/api/test_openapi.py | 2 + .../commands/test_purge_log_records.py | 155 ++++++++++++++++++ tests/integration/tasks/test_management.py | 52 +++++- 10 files changed, 401 insertions(+), 37 deletions(-) diff --git a/docs/development.md b/docs/development.md index 7142c1c30..cce1ac915 100644 --- a/docs/development.md +++ b/docs/development.md @@ -466,11 +466,16 @@ Do **not** confuse the two — see the command docstring in - **Submit a job:** A superuser sends `POST /api/eda/v1/logs/purge/`. HTTP 202 with a `job_id` means dispatcherd accepted the job; deletion may still be running. -- **Choose a cutoff:** Supply exactly one of `before_date` (midnight UTC in - `YYYY-MM-DD` format) or a positive ISO 8601 `retention_duration`. Only rows - with `log_timestamp` strictly before the cutoff qualify. Future UTC cutoffs - are rejected. A request without a cutoff returns HTTP 400 before a job is - queued; no logs are deleted. +- **Choose a cutoff:** For an age-based purge, supply exactly one of + `before_date` (midnight UTC in `YYYY-MM-DD` format) or a positive ISO 8601 + `retention_duration`. Only rows with `log_timestamp` strictly before the + cutoff qualify. Future UTC cutoffs are rejected. +- **Purge every existing log:** Instead, send `"purge-all-logs": true` without + a cutoff or activation selectors. This deletes ordinary logs and earlier + audit markers from every process, then leaves one new audit marker per + process that lost rows. The deleted count includes earlier markers. If + processes keep writing logs, new rows can appear during or after the purge. + Without a cutoff or this flag, the API returns HTTP 400 before queueing. - **Choose the scope:** With no selectors, qualifying ordinary logs from every process are included, including processes without an activation. `activation_ids` and `activation_names` select the union of matching @@ -488,15 +493,28 @@ Content-Type: application/json "activation_names": ["production-rules"]} ``` +To replace all existing logs with new audit markers: + +```http +POST /api/eda/v1/logs/purge/ +Content-Type: application/json + +{"purge-all-logs": true} +``` + **CLI options** - Use either `--date YYYY-MM-DD` or `--retention-duration P30D`. Calendar months and years in a duration are subtracted in UTC. If the target month - lacks the original day, the cutoff uses that month's final day. Omitting both - options raises a command error before deletion + lacks the original day, the cutoff uses that month's final day. +- Use `--purge-all-logs` instead of a cutoff to delete every existing log and + replace prior audit markers with a new marker for each affected process. + This flag cannot be combined with a cutoff, activation selectors, or + `--audit-trail=false`. Omitting both a cutoff and this flag raises a command + error before deletion. - Use `--activation-ids 123 456`, `--activation-names name1 name2`, or both to - limit deletion to the selected activations. Omit both to delete logs across - all activations. + limit deletion to the selected activations. Omit both to include every + activation and processes without an activation. - Use `--audit-trail=true` or `--audit-trail=false`. A bare `--audit-trail` is invalid. - The optional `--internal-job-uuid` adds the EDA purge task UUID to markers. diff --git a/src/aap_eda/api/serializers/activation.py b/src/aap_eda/api/serializers/activation.py index 86d036255..c89e1419c 100644 --- a/src/aap_eda/api/serializers/activation.py +++ b/src/aap_eda/api/serializers/activation.py @@ -93,7 +93,7 @@ def _update_event_stream_source(validated_data: dict) -> str: class LogPurgeRequestSerializer(serializers.Serializer): - """Validate cutoff and activation scope before scheduling a purge.""" + """Validate the cutoff or full purge before scheduling a job.""" before_date = serializers.DateField( required=False, @@ -121,6 +121,19 @@ class LogPurgeRequestSerializer(serializers.Serializer): help_text="Limit deletion to these activation names.", ) + def get_fields(self): + fields = super().get_fields() + fields["purge-all-logs"] = serializers.BooleanField( + source="purge_all_logs", + required=False, + default=False, + help_text=( + "Delete all existing process logs and replace them with " + "audit markers. Cannot be combined with a cutoff or scope." + ), + ) + return fields + def validate(self, attrs): unknown_fields = set(self.initial_data) - set(self.fields) if unknown_fields: @@ -130,6 +143,21 @@ def validate(self, attrs): before_date = attrs.get("before_date") duration = attrs.get("retention_duration") + if attrs["purge_all_logs"]: + if before_date is not None or duration is not None: + raise serializers.ValidationError( + "purge-all-logs cannot be combined with a cutoff." + ) + if "activation_ids" in attrs or "activation_names" in attrs: + raise serializers.ValidationError( + "purge-all-logs cannot be combined with activation " + "selectors." + ) + if not attrs["audit_trail"]: + raise serializers.ValidationError( + "purge-all-logs requires audit_trail=true." + ) + return attrs if (before_date is None) == (duration is None): raise serializers.ValidationError( "Exactly one of before_date or retention_duration is required." diff --git a/src/aap_eda/api/views/activation.py b/src/aap_eda/api/views/activation.py index 900541e31..a1d2b14c3 100644 --- a/src/aap_eda/api/views/activation.py +++ b/src/aap_eda/api/views/activation.py @@ -880,12 +880,16 @@ class LogPurgeViewSet(viewsets.GenericViewSet): @extend_schema( description=( - "Queue deletion of process logs older than one UTC cutoff: " + "Queue deletion of process logs using one UTC cutoff: " "before_date (YYYY-MM-DD) or retention_duration (positive ISO " - "8601). Without activation selectors, all processes, including " + "8601). Alternatively, purge-all-logs=true deletes every " + "existing log, including prior audit markers, and leaves one " + "new audit marker per affected process. This mode cannot be " + "combined with a cutoff, activation selectors, or disabled " + "audit. Without activation selectors, all processes, including " "orphaned ones, are included. Activation IDs and names limit " - "deletion to their union. Audit markers default to enabled. " - "The returned job ID acknowledges scheduling only." + "cutoff deletion to their union. The returned job ID " + "acknowledges scheduling only." ), request=serializers.LogPurgeRequestSerializer, responses={ diff --git a/src/aap_eda/core/management/commands/purge_log_records.py b/src/aap_eda/core/management/commands/purge_log_records.py index ac48eac5e..464609ee2 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -33,7 +33,9 @@ class Command(BaseCommand): """Purge old logs globally or for selected activations.""" help = ( - "Purge log records older than exactly one cutoff. Without activation " + "Purge log records older than exactly one cutoff, or use " + "--purge-all-logs to replace every existing log with an audit " + "marker. Without activation " "selectors, include every process (including orphaned processes). " "Activation IDs and names limit deletion to their union. " "One audit marker per affected process is enabled by default." @@ -76,6 +78,17 @@ def add_arguments(self, parser: CommandParser) -> None: "example P30D or P1M. Mutually exclusive with --date." ), ) + parser.add_argument( + "--purge-all-logs", + dest="purge-all-logs", + action="store_true", + help=( + "Delete all existing process logs at every timestamp, " + "including earlier audit markers, and leave one new audit " + "marker per affected process. Cannot be combined with a " + "cutoff, activation selectors, or --audit-trail=false." + ), + ) parser.add_argument( "--audit-trail", dest="audit_trail", @@ -132,8 +145,21 @@ def _cutoff(options: dict) -> datetime: def handle(self, *args, **options): ids = options.get("activation-ids") names = options.get("activation-names") - cutoff = self._cutoff(options) - if cutoff > datetime.now(timezone.utc): + purge_all_logs = options.get("purge-all-logs", False) + if not isinstance(purge_all_logs, bool): + raise CommandError("--purge-all-logs must be a boolean flag.") + if purge_all_logs and ( + options.get("date") is not None + or options.get("retention_duration") is not None + or ids is not None + or names is not None + ): + raise CommandError( + "--purge-all-logs cannot be combined with a cutoff or " + "activation selectors." + ) + cutoff = None if purge_all_logs else self._cutoff(options) + if cutoff is not None and cutoff > datetime.now(timezone.utc): raise CommandError("--date must not be in the future.") job_uuid = options.get("internal-job-uuid") if job_uuid is not None: @@ -151,6 +177,8 @@ def handle(self, *args, **options): raise CommandError(str(exc)) from exc elif not isinstance(audit_trail, bool): raise CommandError("--audit-trail must be true or false.") + if purge_all_logs and not audit_trail: + raise CommandError("--purge-all-logs requires audit trail.") try: deleted_count = delete_logs_older_than( @@ -159,10 +187,22 @@ def handle(self, *args, **options): activation_names=names, audit_trail=audit_trail, internal_job_uuid=job_uuid, + purge_all_logs=purge_all_logs, ) except (LogPurgeError, ValueError) as exc: raise CommandError(str(exc)) from exc + if purge_all_logs: + marker_result = ( + "Created audit markers for affected processes." + if deleted_count + else "No audit markers created." + ) + return self.style.SUCCESS( + f"Purged {deleted_count} log records globally at all " + f"timestamps. {marker_result}" + ) + scope = ( "globally" if ids is None and names is None diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index 271612825..a3e6a80fd 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -97,15 +97,18 @@ def resolve_activation_ids( return existing_ids -def _ordinary_logs( +def _logs_to_purge( process_id: int, - cutoff_timestamp: float, + cutoff_timestamp: float | None, selected_ids: set[int] | None, + purge_all_logs: bool, ): logs = models.RulebookProcessLog.objects.filter( - activation_instance_id=process_id, - log_timestamp__lt=cutoff_timestamp, + activation_instance_id=process_id ) + if purge_all_logs: + return logs + logs = logs.filter(log_timestamp__lt=cutoff_timestamp) if selected_ids is not None: logs = logs.filter(activation_instance__activation_id__in=selected_ids) return logs.exclude(log_created_at=PURGE_MARKER_CREATED_AT).exclude( @@ -115,19 +118,24 @@ def _ordinary_logs( def _marker_text( - cutoff: datetime, + cutoff: datetime | None, purge_time: datetime, count: int, tracking_id: str | None, orphaned: bool, internal_job_uuid: str | None, ) -> str: - cutoff_text = _utc_text(cutoff) purge_text = _utc_text(purge_time) - text = ( - f"All log records older than {cutoff_text} were purged at " - f"{purge_text}. Deleted {count} log rows." - ) + if cutoff is None: + text = ( + f"Global log purge ran at {purge_text}. " + f"Deleted {count} log rows." + ) + else: + text = ( + f"All log records older than {_utc_text(cutoff)} were purged at " + f"{purge_text}. Deleted {count} log rows." + ) if internal_job_uuid is not None: text += f" Job ID: {internal_job_uuid}." if tracking_id and tracking_id.strip(): @@ -138,16 +146,35 @@ def _marker_text( def delete_logs_older_than( - cutoff: datetime, + cutoff: datetime | None, *, activation_ids: list[int] | None = None, activation_names: list[str] | None = None, audit_trail: bool = True, internal_job_uuid: str | None = None, + purge_all_logs: bool = False, ) -> int: - """Purge ordinary logs per process in committed, bounded ID batches.""" - selected_ids = resolve_activation_ids(activation_ids, activation_names) - cutoff_timestamp = cutoff.timestamp() + """Purge logs per process in committed, bounded ID batches.""" + if not isinstance(purge_all_logs, bool): + raise ValueError("purge_all_logs must be a boolean.") + if purge_all_logs: + if cutoff is not None or any( + selector is not None + for selector in (activation_ids, activation_names) + ): + raise ValueError( + "--purge-all-logs cannot be combined with a cutoff or " + "activation selectors." + ) + if not audit_trail: + raise ValueError("--purge-all-logs requires audit trail.") + selected_ids = None + cutoff_timestamp = None + else: + if cutoff is None: + raise ValueError("A cutoff is required unless purging all logs.") + selected_ids = resolve_activation_ids(activation_ids, activation_names) + cutoff_timestamp = cutoff.timestamp() processes = models.RulebookProcess.objects.all() if selected_ids is not None: processes = processes.filter(activation_id__in=selected_ids) @@ -172,8 +199,8 @@ def delete_logs_older_than( if not process_batch: break for process_id, activation_id, tracking_id in process_batch: - qualifying = _ordinary_logs( - process_id, cutoff_timestamp, selected_ids + qualifying = _logs_to_purge( + process_id, cutoff_timestamp, selected_ids, purge_all_logs ) highest_log_id = qualifying.aggregate(max_id=Max("id"))[ "max_id" @@ -196,8 +223,11 @@ def delete_logs_older_than( break with transaction.atomic(): _, per_model_counts = ( - _ordinary_logs( - process_id, cutoff_timestamp, selected_ids + _logs_to_purge( + process_id, + cutoff_timestamp, + selected_ids, + purge_all_logs, ) .filter(id__in=batch_ids) .delete() @@ -207,7 +237,9 @@ def delete_logs_older_than( purge_time = datetime.now(timezone.utc) marker_timestamp = max( ceil(purge_time.timestamp()), - ceil(cutoff_timestamp), + ceil(cutoff_timestamp) + if cutoff_timestamp is not None + else 0, ) marker_text = _marker_text( cutoff, diff --git a/src/aap_eda/tasks/management.py b/src/aap_eda/tasks/management.py index 9602b1220..746b69987 100644 --- a/src/aap_eda/tasks/management.py +++ b/src/aap_eda/tasks/management.py @@ -38,6 +38,7 @@ def submit_log_purge( audit_trail: bool = True, activation_ids: list[int] | None = None, activation_names: list[str] | None = None, + purge_all_logs: bool = False, ) -> str: """Submit a fixed-purpose log purge task.""" command_options = {"audit_trail": audit_trail} @@ -49,6 +50,8 @@ def submit_log_purge( command_options["activation-ids"] = activation_ids if activation_names is not None: command_options["activation-names"] = activation_names + if purge_all_logs: + command_options["purge-all-logs"] = True return aap_eda_manage_commands( "purge_log_records", diff --git a/tests/integration/api/test_log_purge.py b/tests/integration/api/test_log_purge.py index 24ecf4c5c..9cf1ee6c7 100644 --- a/tests/integration/api/test_log_purge.py +++ b/tests/integration/api/test_log_purge.py @@ -106,6 +106,31 @@ def test_superuser_queues_global_purge_with_absolute_date(superuser_client): } +@pytest.mark.django_db +def test_superuser_queues_purge_all_logs_without_cutoff(superuser_client): + with mock.patch( + "aap_eda.tasks.management.uuid4", return_value=JOB_ID + ), mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": str(JOB_ID)}, "default"), + ) as submit_task: + response = superuser_client.post( + PURGE_URL, {"purge-all-logs": True}, format="json" + ) + + assert response.status_code == status.HTTP_202_ACCEPTED + assert response.data == {"job_id": str(JOB_ID)} + assert submit_task.call_args.kwargs["args"] == ( + str(JOB_ID), + "purge_log_records", + { + "audit_trail": True, + "purge-all-logs": True, + "internal-job-uuid": str(JOB_ID), + }, + ) + + @pytest.mark.django_db def test_api_keeps_activation_scope_when_audit_is_disabled( superuser_client, default_activation @@ -158,6 +183,13 @@ def test_anonymous_purge_uses_api_permission_denial(base_client): {"retention_duration": "not-a-duration"}, {"retention_duration": "P0D"}, {"retention_duration": "-P1D"}, + {"purge-all-logs": False}, + {"purge_all_logs": True}, + {"purge-all-logs": True, "before_date": "2020-01-01"}, + {"purge-all-logs": True, "retention_duration": "P30D"}, + {"purge-all-logs": True, "audit_trail": False}, + {"purge-all-logs": True, "activation_ids": [1]}, + {"purge-all-logs": True, "activation_names": ["example"]}, {"before_date": "2020-01-01", "activation_ids": [0]}, {"before_date": "2020-01-01", "activation_ids": []}, {"before_date": "2020-01-01", "activation_names": [""]}, diff --git a/tests/integration/api/test_openapi.py b/tests/integration/api/test_openapi.py index 4857a1101..e86c74e0a 100644 --- a/tests/integration/api/test_openapi.py +++ b/tests/integration/api/test_openapi.py @@ -112,8 +112,10 @@ def test_log_purge_openapi_contract(admin_client): "audit_trail", "activation_ids", "activation_names", + "purge-all-logs", } assert request_properties["audit_trail"]["default"] is True + assert request_properties["purge-all-logs"]["default"] is False assert "internal_job_uuid" not in request_properties responses = operation["responses"] diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index 161ac8bfe..49eb3e3cc 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -1026,3 +1026,158 @@ def test_marker_uses_invocation_count_job_uuid_tracking_and_ceiled_timestamp( "Job ID:" not in next(row for row in markers if row.pk != marker.pk).log ) + + +@pytest.mark.django_db +def test_purge_all_logs_replaces_old_rows_and_markers_per_process( + null_activation_test_data, monkeypatch +): + monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 2) + normal = null_activation_test_data["normal_process"] + orphan = null_activation_test_data["null_process"] + models.RulebookProcessLog.objects.create( + activation_instance=normal, + log="old purge marker", + log_timestamp=1, + log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT, + ) + models.RulebookProcessLog.objects.create( + activation_instance=normal, + log="future ordinary log", + log_timestamp=int(timezone.now().timestamp()) + 10000, + ) + models.RulebookProcessLog.objects.create( + activation_instance=orphan, + log=( + "All log records older than 2024-01-01 00:00:00 UTC were " + "purged at 2024-02-01 00:00:00 UTC." + ), + log_timestamp=1, + ) + old_ids = set( + models.RulebookProcessLog.objects.values_list("id", flat=True) + ) + job_id = uuid4() + + output = call_command( + "purge_log_records", + "--purge-all-logs", + "--internal-job-uuid", + str(job_id), + ) + + assert output.startswith("Purged 7 log records globally") + assert not models.RulebookProcessLog.objects.filter( + pk__in=old_ids + ).exists() + markers = models.RulebookProcessLog.objects.all() + assert markers.count() == 2 + normal_marker = markers.get(activation_instance=normal) + orphan_marker = markers.get(activation_instance=orphan) + assert "Global log purge ran at" in normal_marker.log + assert "Deleted 4 log rows." in normal_marker.log + assert "Deleted 3 log rows." in orphan_marker.log + assert f"Job ID: {job_id}." in normal_marker.log + assert "Log Tracking id unavailable (orphaned process)." in ( + orphan_marker.log + ) + assert all( + marker.log_created_at == delete_log_util.PURGE_MARKER_CREATED_AT + for marker in markers + ) + + +@pytest.mark.django_db +@pytest.mark.parametrize( + "conflicting_options", + [ + ("--date", "2024-01-01"), + ("--retention-duration", "P1D"), + ("--activation-ids", "1"), + ("--activation-names", "example"), + ("--audit-trail=false",), + ], +) +def test_purge_all_logs_rejects_other_modes_before_deletion( + default_activation_instance, conflicting_options +): + log = models.RulebookProcessLog.objects.create( + activation_instance=default_activation_instance, + log="must remain", + log_timestamp=1, + ) + + with pytest.raises(CommandError, match="purge-all-logs"): + call_command( + "purge_log_records", "--purge-all-logs", *conflicting_options + ) + + assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() + + +@pytest.mark.django_db +def test_purge_all_logs_rejects_programmatic_non_boolean_flag( + default_activation_instance, +): + log = models.RulebookProcessLog.objects.create( + activation_instance=default_activation_instance, + log="must remain", + log_timestamp=1, + ) + + with pytest.raises(CommandError, match="must be a boolean flag"): + call_command("purge_log_records", **{"purge-all-logs": "false"}) + + assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() + + +@pytest.mark.django_db +def test_purge_all_logs_with_no_rows_creates_no_marker( + default_activation_instance, +): + output = call_command("purge_log_records", "--purge-all-logs") + + assert output.startswith("Purged 0 log records globally") + assert "No audit markers created." in output + assert not models.RulebookProcessLog.objects.exists() + + +@pytest.mark.django_db(transaction=True) +def test_purge_all_logs_failure_keeps_committed_marker_count( + default_activation_instance, monkeypatch +): + monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 1) + models.RulebookProcessLog.objects.bulk_create( + [ + models.RulebookProcessLog( + activation_instance=default_activation_instance, + log=f"old-{index}", + log_timestamp=1, + ) + for index in range(2) + ] + ) + original_delete = QuerySet.delete + calls = 0 + + def fail_second_delete(queryset): + nonlocal calls + calls += 1 + if calls == 2: + raise RuntimeError("injected batch failure") + return original_delete(queryset) + + monkeypatch.setattr(QuerySet, "delete", fail_second_delete) + with pytest.raises(CommandError, match="failed after 1 committed rows"): + call_command("purge_log_records", "--purge-all-logs") + + assert ( + models.RulebookProcessLog.objects.filter( + log__startswith="old-" + ).count() + == 1 + ) + marker = models.RulebookProcessLog.objects.get( + log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT + ) + assert "Deleted 1 log rows." in marker.log diff --git a/tests/integration/tasks/test_management.py b/tests/integration/tasks/test_management.py index 3eeec5d13..065909e94 100644 --- a/tests/integration/tasks/test_management.py +++ b/tests/integration/tasks/test_management.py @@ -13,7 +13,10 @@ from django.core.management.base import CommandError from aap_eda.core import models -from aap_eda.core.utils.delete_log_util import LogPurgeError +from aap_eda.core.utils.delete_log_util import ( + PURGE_MARKER_CREATED_AT, + LogPurgeError, +) from aap_eda.tasks.management import ( LOG_PURGE_TASK_TIMEOUT_SECONDS, _aap_eda_manage, @@ -83,6 +86,53 @@ def test_submit_log_purge_forwards_scope_when_audit_is_disabled(): } +@pytest.mark.django_db +def test_submitted_purge_all_logs_uses_same_command_and_job_id( + default_activation_instance, new_activation_instance +): + models.RulebookProcessLog.objects.create( + activation_instance=default_activation_instance, + log="old marker", + log_timestamp=1, + log_created_at=PURGE_MARKER_CREATED_AT, + ) + models.RulebookProcessLog.objects.create( + activation_instance=default_activation_instance, + log="current log", + log_timestamp=9999999999, + ) + models.RulebookProcessLog.objects.create( + activation_instance=new_activation_instance, + log="another log", + log_timestamp=1, + ) + job_id = "712beb16-b7dd-40c9-aa29-a7f734376c7a" + with mock.patch( + "aap_eda.tasks.management.uuid4", return_value=job_id + ), mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": job_id}, "default"), + ) as submit_task: + assert submit_log_purge(purge_all_logs=True) == job_id + + worker_args = submit_task.call_args.kwargs["args"] + assert worker_args[2] == { + "audit_trail": True, + "purge-all-logs": True, + "internal-job-uuid": job_id, + } + result = _aap_eda_manage(*worker_args) + + assert result["status"] == "completed" + assert result["deleted"] == 3 + markers = models.RulebookProcessLog.objects.all() + assert markers.count() == 2 + assert all(f"Job ID: {job_id}." in marker.log for marker in markers) + assert all( + marker.log_created_at == PURGE_MARKER_CREATED_AT for marker in markers + ) + + @pytest.mark.django_db def test_worker_invokes_purge_command_and_returns_deleted_count( default_activation_instance, From 2a627039f9e15784c8b432d58e824cbc4cb65900 Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Fri, 23 Oct 2026 15:40:35 -0400 Subject: [PATCH 06/15] refactor to address sonar qube failure --- src/aap_eda/api/serializers/activation.py | 38 +-- .../management/commands/purge_log_records.py | 33 ++- src/aap_eda/core/utils/delete_log_util.py | 228 +++++++++++------- 3 files changed, 185 insertions(+), 114 deletions(-) diff --git a/src/aap_eda/api/serializers/activation.py b/src/aap_eda/api/serializers/activation.py index c89e1419c..7d0404fff 100644 --- a/src/aap_eda/api/serializers/activation.py +++ b/src/aap_eda/api/serializers/activation.py @@ -134,30 +134,36 @@ def get_fields(self): ) return fields + @staticmethod + def _validate_full_purge(attrs): + if ( + attrs.get("before_date") is not None + or attrs.get("retention_duration") is not None + ): + raise serializers.ValidationError( + "purge-all-logs cannot be combined with a cutoff." + ) + if "activation_ids" in attrs or "activation_names" in attrs: + raise serializers.ValidationError( + "purge-all-logs cannot be combined with activation selectors." + ) + if not attrs["audit_trail"]: + raise serializers.ValidationError( + "purge-all-logs requires audit_trail=true." + ) + def validate(self, attrs): unknown_fields = set(self.initial_data) - set(self.fields) if unknown_fields: raise serializers.ValidationError( - {field: "Unknown field." for field in sorted(unknown_fields)} + dict.fromkeys(sorted(unknown_fields), "Unknown field.") ) - before_date = attrs.get("before_date") - duration = attrs.get("retention_duration") if attrs["purge_all_logs"]: - if before_date is not None or duration is not None: - raise serializers.ValidationError( - "purge-all-logs cannot be combined with a cutoff." - ) - if "activation_ids" in attrs or "activation_names" in attrs: - raise serializers.ValidationError( - "purge-all-logs cannot be combined with activation " - "selectors." - ) - if not attrs["audit_trail"]: - raise serializers.ValidationError( - "purge-all-logs requires audit_trail=true." - ) + self._validate_full_purge(attrs) return attrs + before_date = attrs.get("before_date") + duration = attrs.get("retention_duration") if (before_date is None) == (duration is None): raise serializers.ValidationError( "Exactly one of before_date or retention_duration is required." diff --git a/src/aap_eda/core/management/commands/purge_log_records.py b/src/aap_eda/core/management/commands/purge_log_records.py index 464609ee2..1badccd79 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -142,7 +142,7 @@ def _cutoff(options: dict) -> datetime: "Exactly one of --date or --retention-duration is required." ) - def handle(self, *args, **options): + def _purge_mode(self, options: dict) -> tuple[bool, datetime | None]: ids = options.get("activation-ids") names = options.get("activation-names") purge_all_logs = options.get("purge-all-logs", False) @@ -161,6 +161,24 @@ def handle(self, *args, **options): cutoff = None if purge_all_logs else self._cutoff(options) if cutoff is not None and cutoff > datetime.now(timezone.utc): raise CommandError("--date must not be in the future.") + return purge_all_logs, cutoff + + def _validated_audit_trail(self, value, purge_all_logs: bool) -> bool: + if isinstance(value, str): + try: + value = self._audit_trail_value(value) + except ArgumentTypeError as exc: + raise CommandError(str(exc)) from exc + elif not isinstance(value, bool): + raise CommandError("--audit-trail must be true or false.") + if purge_all_logs and not value: + raise CommandError("--purge-all-logs requires audit trail.") + return value + + def handle(self, *args, **options): + ids = options.get("activation-ids") + names = options.get("activation-names") + purge_all_logs, cutoff = self._purge_mode(options) job_uuid = options.get("internal-job-uuid") if job_uuid is not None: try: @@ -169,16 +187,9 @@ def handle(self, *args, **options): raise CommandError( "--internal-job-uuid must be a UUID." ) from exc - audit_trail = options["audit_trail"] - if isinstance(audit_trail, str): - try: - audit_trail = self._audit_trail_value(audit_trail) - except ArgumentTypeError as exc: - raise CommandError(str(exc)) from exc - elif not isinstance(audit_trail, bool): - raise CommandError("--audit-trail must be true or false.") - if purge_all_logs and not audit_trail: - raise CommandError("--purge-all-logs requires audit trail.") + audit_trail = self._validated_audit_trail( + options["audit_trail"], purge_all_logs + ) try: deleted_count = delete_logs_older_than( diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index a3e6a80fd..5b52940b6 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -12,6 +12,7 @@ # See the License for the specific language governing permissions and # limitations under the License. +from dataclasses import dataclass from datetime import datetime, timezone from math import ceil @@ -51,6 +52,16 @@ def __init__(self, message: str, deleted_count: int): super().__init__(message) +@dataclass(frozen=True) +class _PurgeOptions: + cutoff: datetime | None + cutoff_timestamp: float | None + selected_ids: set[int] | None + audit_trail: bool + internal_job_uuid: str | None + purge_all_logs: bool + + def resolve_activation_ids( activation_ids: list[int] | None, activation_names: list[str] | None, @@ -145,16 +156,15 @@ def _marker_text( return text -def delete_logs_older_than( +def _validate_purge_options( cutoff: datetime | None, *, - activation_ids: list[int] | None = None, - activation_names: list[str] | None = None, - audit_trail: bool = True, - internal_job_uuid: str | None = None, - purge_all_logs: bool = False, -) -> int: - """Purge logs per process in committed, bounded ID batches.""" + activation_ids: list[int] | None, + activation_names: list[str] | None, + audit_trail: bool, + internal_job_uuid: str | None, + purge_all_logs: bool, +) -> _PurgeOptions: if not isinstance(purge_all_logs, bool): raise ValueError("purge_all_logs must be a boolean.") if purge_all_logs: @@ -175,16 +185,134 @@ def delete_logs_older_than( raise ValueError("A cutoff is required unless purging all logs.") selected_ids = resolve_activation_ids(activation_ids, activation_names) cutoff_timestamp = cutoff.timestamp() + return _PurgeOptions( + cutoff, + cutoff_timestamp, + selected_ids, + audit_trail, + internal_job_uuid, + purge_all_logs, + ) + + +def _write_audit_marker( + process_id: int, + activation_id: int | None, + tracking_id: str | None, + marker_id: int | None, + deleted_count: int, + options: _PurgeOptions, +) -> int: + purge_time = datetime.now(timezone.utc) + marker_timestamp = max( + ceil(purge_time.timestamp()), + ceil(options.cutoff_timestamp) + if options.cutoff_timestamp is not None + else 0, + ) + marker_text = _marker_text( + options.cutoff, + purge_time, + deleted_count, + tracking_id, + activation_id is None, + options.internal_job_uuid, + ) + if marker_id is None: + marker = models.RulebookProcessLog.objects.create( + activation_instance_id=process_id, + log=marker_text, + log_timestamp=marker_timestamp, + log_created_at=PURGE_MARKER_CREATED_AT, + ) + return marker.id + updated = models.RulebookProcessLog.objects.filter(pk=marker_id).update( + log=marker_text, + log_timestamp=marker_timestamp, + ) + if updated != 1: + raise RuntimeError("The current purge marker disappeared.") + return marker_id + + +def _purge_process_logs(process: tuple, options: _PurgeOptions): + """Yield each committed batch count so failures retain partial totals.""" + process_id, activation_id, tracking_id = process + qualifying = _logs_to_purge( + process_id, + options.cutoff_timestamp, + options.selected_ids, + options.purge_all_logs, + ) + highest_log_id = qualifying.aggregate(max_id=Max("id"))["max_id"] + if highest_log_id is None: + return + + last_log_id = 0 + process_deleted = 0 + marker_id = None + model_label = models.RulebookProcessLog._meta.label + while last_log_id < highest_log_id: + batch_ids = list( + qualifying.filter(id__gt=last_log_id, id__lte=highest_log_id) + .order_by("id") + .values_list("id", flat=True)[:DELETE_BATCH_SIZE] + ) + if not batch_ids: + break + with transaction.atomic(): + _, per_model_counts = ( + _logs_to_purge( + process_id, + options.cutoff_timestamp, + options.selected_ids, + options.purge_all_logs, + ) + .filter(id__in=batch_ids) + .delete() + ) + batch_deleted = per_model_counts.get(model_label, 0) + if options.audit_trail and batch_deleted: + marker_id = _write_audit_marker( + process_id, + activation_id, + tracking_id, + marker_id, + process_deleted + batch_deleted, + options, + ) + process_deleted += batch_deleted + last_log_id = batch_ids[-1] + yield batch_deleted + + +def delete_logs_older_than( + cutoff: datetime | None, + *, + activation_ids: list[int] | None = None, + activation_names: list[str] | None = None, + audit_trail: bool = True, + internal_job_uuid: str | None = None, + purge_all_logs: bool = False, +) -> int: + """Purge logs per process in committed, bounded ID batches.""" + options = _validate_purge_options( + cutoff, + activation_ids=activation_ids, + activation_names=activation_names, + audit_trail=audit_trail, + internal_job_uuid=internal_job_uuid, + purge_all_logs=purge_all_logs, + ) processes = models.RulebookProcess.objects.all() - if selected_ids is not None: - processes = processes.filter(activation_id__in=selected_ids) + if options.selected_ids is not None: + processes = processes.filter(activation_id__in=options.selected_ids) highest_process_id = processes.aggregate(max_id=Max("id"))["max_id"] if highest_process_id is None: return 0 deleted_count = 0 last_process_id = 0 - model_label = models.RulebookProcessLog._meta.label try: while last_process_id < highest_process_id: process_batch = list( @@ -198,83 +326,9 @@ def delete_logs_older_than( ) if not process_batch: break - for process_id, activation_id, tracking_id in process_batch: - qualifying = _logs_to_purge( - process_id, cutoff_timestamp, selected_ids, purge_all_logs - ) - highest_log_id = qualifying.aggregate(max_id=Max("id"))[ - "max_id" - ] - if highest_log_id is None: - continue - - last_log_id = 0 - process_deleted = 0 - marker_id = None - while last_log_id < highest_log_id: - batch_ids = list( - qualifying.filter( - id__gt=last_log_id, id__lte=highest_log_id - ) - .order_by("id") - .values_list("id", flat=True)[:DELETE_BATCH_SIZE] - ) - if not batch_ids: - break - with transaction.atomic(): - _, per_model_counts = ( - _logs_to_purge( - process_id, - cutoff_timestamp, - selected_ids, - purge_all_logs, - ) - .filter(id__in=batch_ids) - .delete() - ) - batch_deleted = per_model_counts.get(model_label, 0) - if audit_trail and batch_deleted: - purge_time = datetime.now(timezone.utc) - marker_timestamp = max( - ceil(purge_time.timestamp()), - ceil(cutoff_timestamp) - if cutoff_timestamp is not None - else 0, - ) - marker_text = _marker_text( - cutoff, - purge_time, - process_deleted + batch_deleted, - tracking_id, - activation_id is None, - internal_job_uuid, - ) - if marker_id is None: - marker = ( - models.RulebookProcessLog.objects.create( - activation_instance_id=process_id, - log=marker_text, - log_timestamp=marker_timestamp, - log_created_at=PURGE_MARKER_CREATED_AT, - ) - ) - marker_id = marker.id - else: - updated = ( - models.RulebookProcessLog.objects.filter( - pk=marker_id - ).update( - log=marker_text, - log_timestamp=marker_timestamp, - ) - ) - if updated != 1: - raise RuntimeError( - "The current purge marker disappeared." - ) - process_deleted += batch_deleted + for process in process_batch: + for batch_deleted in _purge_process_logs(process, options): deleted_count += batch_deleted - last_log_id = batch_ids[-1] last_process_id = process_batch[-1][0] except Exception as exc: raise LogPurgeError( From 66478b274ed489f5c587c7299d871661dfa3ab6e Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Mon, 26 Oct 2026 14:25:02 -0400 Subject: [PATCH 07/15] feat(logs): improve purge audit markers and CLI traceability Scheduled purges should let prior audit markers age out with other logs. Operators also need a recognizable ID for manual purges, and the internal marker timestamp should not appear as a real log time. Assisted by: GPT-6 --- docs/development.md | 20 +- .../management/commands/purge_log_records.py | 18 +- src/aap_eda/core/utils/delete_log_util.py | 43 ++-- .../api/test_activation_instance.py | 40 ++++ .../commands/test_purge_log_records.py | 185 +++++++++++------- tests/integration/tasks/test_management.py | 30 +-- 6 files changed, 205 insertions(+), 131 deletions(-) diff --git a/docs/development.md b/docs/development.md index cce1ac915..5d7fe7a9c 100644 --- a/docs/development.md +++ b/docs/development.md @@ -469,14 +469,15 @@ Do **not** confuse the two — see the command docstring in - **Choose a cutoff:** For an age-based purge, supply exactly one of `before_date` (midnight UTC in `YYYY-MM-DD` format) or a positive ISO 8601 `retention_duration`. Only rows with `log_timestamp` strictly before the - cutoff qualify. Future UTC cutoffs are rejected. + cutoff qualify, including earlier audit markers. Future UTC cutoffs are + rejected. - **Purge every existing log:** Instead, send `"purge-all-logs": true` without a cutoff or activation selectors. This deletes ordinary logs and earlier audit markers from every process, then leaves one new audit marker per process that lost rows. The deleted count includes earlier markers. If processes keep writing logs, new rows can appear during or after the purge. Without a cutoff or this flag, the API returns HTTP 400 before queueing. -- **Choose the scope:** With no selectors, qualifying ordinary logs from every +- **Choose the scope:** With no selectors, qualifying logs from every process are included, including processes without an activation. `activation_ids` and `activation_names` select the union of matching activations. Empty or unknown selectors are rejected before queueing. @@ -517,16 +518,23 @@ Content-Type: application/json activation and processes without an activation. - Use `--audit-trail=true` or `--audit-trail=false`. A bare `--audit-trail` is invalid. -- The optional `--internal-job-uuid` adds the EDA purge task UUID to markers. - The API supplies this UUID automatically. +- The optional `--internal-job-uuid` accepts a UUID or a custom ID of 1-128 + ASCII letters, digits, periods, underscores, or hyphens, starting with a + letter or digit. Valid UUIDs are normalized. The value appears in audit + markers under `Purge Job ID`. The API supplies its task UUID automatically. **Deletion and audit markers** - Deletion commits in batches. If a later batch fails, worker logs record the count already deleted, and the job reports failure. Audit markers record the partial count when audit is enabled. -- When audit is enabled, each process that loses ordinary log rows gets one - marker with its count for this invocation. +- When audit is enabled, each process that loses log rows gets one marker with + its count for this invocation. Markers use `Recorded at` for the time the + audit row was written and store that time in `log_created_at`. The API + returns this recorded time. +- Cutoff purges treat earlier markers like other log rows: they are deleted and + counted once their `log_timestamp` falls before the cutoff. Recent markers + can therefore remain across scheduled purges until they reach the cutoff. **Check the outcome** diff --git a/src/aap_eda/core/management/commands/purge_log_records.py b/src/aap_eda/core/management/commands/purge_log_records.py index 1badccd79..21eaf6a41 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -12,6 +12,7 @@ # See the License for the specific language governing permissions and # limitations under the License. +import re from argparse import ArgumentTypeError from datetime import datetime, time, timezone from uuid import UUID @@ -101,7 +102,10 @@ def add_arguments(self, parser: CommandParser) -> None: "--internal-job-uuid", dest="internal-job-uuid", default=None, - help="EDA purge task UUID to include in audit markers.", + help=( + "Purge job UUID or custom ID (1-128 letters, digits, periods, " + "underscores, or hyphens) to include in audit markers." + ), ) @staticmethod @@ -184,9 +188,15 @@ def handle(self, *args, **options): try: job_uuid = str(UUID(str(job_uuid))) except (TypeError, ValueError, AttributeError) as exc: - raise CommandError( - "--internal-job-uuid must be a UUID." - ) from exc + if not isinstance(job_uuid, str) or not re.fullmatch( + r"[A-Za-z0-9][A-Za-z0-9._-]{0,127}", job_uuid + ): + raise CommandError( + "--internal-job-uuid must be a UUID or a custom ID " + "of 1-128 ASCII letters, digits, periods, " + "underscores, or hyphens, starting with a letter " + "or digit." + ) from exc audit_trail = self._validated_audit_trail( options["audit_trail"], purge_all_logs ) diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index 5b52940b6..45be061ba 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -23,18 +23,6 @@ DELETE_BATCH_SIZE = 1000 -# This reserved value identifies new markers without a schema change. -PURGE_MARKER_CREATED_AT = datetime(9999, 12, 31, tzinfo=timezone.utc) - -# Older versions wrote this fixed message with NULL log_created_at. Text -# matching cannot distinguish an ordinary log with identical content. -LEGACY_MARKER_PATTERN = ( - r"^All log records older than [0-9]{4}-[0-9]{2}-[0-9]{2} " - r"[0-9]{2}:[0-9]{2}:[0-9]{2} UTC were purged at " - r"[0-9]{4}-[0-9]{2}-[0-9]{2} " - r"[0-9]{2}:[0-9]{2}:[0-9]{2} UTC\.$" -) - def _utc_text(value: datetime) -> str: value = value.astimezone(timezone.utc) @@ -122,10 +110,7 @@ def _logs_to_purge( logs = logs.filter(log_timestamp__lt=cutoff_timestamp) if selected_ids is not None: logs = logs.filter(activation_instance__activation_id__in=selected_ids) - return logs.exclude(log_created_at=PURGE_MARKER_CREATED_AT).exclude( - log_created_at__isnull=True, - log__regex=LEGACY_MARKER_PATTERN, - ) + return logs def _marker_text( @@ -136,24 +121,21 @@ def _marker_text( orphaned: bool, internal_job_uuid: str | None, ) -> str: - purge_text = _utc_text(purge_time) + details = [f"Recorded at: {_utc_text(purge_time)}"] + noun = "record" if count == 1 else "records" if cutoff is None: - text = ( - f"Global log purge ran at {purge_text}. " - f"Deleted {count} log rows." - ) + text = f"Purged {count} log {noun} globally." else: - text = ( - f"All log records older than {_utc_text(cutoff)} were purged at " - f"{purge_text}. Deleted {count} log rows." - ) + text = f"Purged {count} log {noun} older than {_utc_text(cutoff)}." if internal_job_uuid is not None: - text += f" Job ID: {internal_job_uuid}." + details.append(f"Purge Job ID: {internal_job_uuid}") if tracking_id and tracking_id.strip(): - text += f" Log Tracking id {tracking_id.strip()}." + details.append(f"Activation Lifecycle ID: {tracking_id.strip()}") elif orphaned: - text += " Log Tracking id unavailable (orphaned process)." - return text + details.append( + "Activation Lifecycle ID: unavailable (orphaned process)" + ) + return f"{text} [{' | '.join(details)}]" def _validate_purge_options( @@ -223,12 +205,13 @@ def _write_audit_marker( activation_instance_id=process_id, log=marker_text, log_timestamp=marker_timestamp, - log_created_at=PURGE_MARKER_CREATED_AT, + log_created_at=purge_time, ) return marker.id updated = models.RulebookProcessLog.objects.filter(pk=marker_id).update( log=marker_text, log_timestamp=marker_timestamp, + log_created_at=purge_time, ) if updated != 1: raise RuntimeError("The current purge marker disappeared.") diff --git a/tests/integration/api/test_activation_instance.py b/tests/integration/api/test_activation_instance.py index 746ead842..ca909fb9d 100644 --- a/tests/integration/api/test_activation_instance.py +++ b/tests/integration/api/test_activation_instance.py @@ -12,6 +12,7 @@ # See the License for the specific language governing permissions and # limitations under the License. +from datetime import datetime, timezone from typing import Any, Dict, List import pytest @@ -19,6 +20,7 @@ from rest_framework.test import APIClient from aap_eda.core import enums, models +from aap_eda.core.utils.delete_log_util import delete_logs_older_than from aap_eda.utils.log_sanitizer import REDACTED_STRING from tests.integration.constants import api_url_v1 @@ -117,6 +119,44 @@ def test_list_logs_from_activation_instance( ] +@pytest.mark.django_db +def test_list_logs_returns_actual_purge_marker_time( + default_activation_instances: List[models.RulebookProcess], + admin_client: APIClient, +): + instance = default_activation_instances[0] + models.RulebookProcessLog.objects.create( + activation_instance=instance, + log="old log", + log_timestamp=1, + ) + before_purge = datetime.now(timezone.utc) + assert ( + delete_logs_older_than( + datetime(2024, 1, 1, tzinfo=timezone.utc), + activation_ids=[instance.activation_id], + ) + == 1 + ) + after_purge = datetime.now(timezone.utc) + marker = models.RulebookProcessLog.objects.get( + activation_instance=instance, log__startswith="Purged " + ) + + response = admin_client.get( + f"{api_url_v1}/activation-instances/{instance.id}/logs/" + ) + + assert response.status_code == status.HTTP_200_OK + marker_data = next( + entry for entry in response.data["results"] if entry["id"] == marker.id + ) + assert before_purge <= marker.log_created_at <= after_purge + assert marker_data[ + "log_created_at" + ] == marker.log_created_at.isoformat().replace("+00:00", "Z") + + @pytest.mark.django_db def test_list_activation_instance_logs_filter( default_activation_instances: List[models.RulebookProcess], diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index 49eb3e3cc..f73b53040 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -30,6 +30,10 @@ from aap_eda.core.utils.log_retention import retention_cutoff +def _audit_markers(): + return models.RulebookProcessLog.objects.filter(log__startswith="Purged ") + + @pytest.fixture def prepare_log_records( default_decision_environment: models.DecisionEnvironment, @@ -242,21 +246,23 @@ def test_purge_log_records( assert models.RulebookProcessLog.objects.count() == 4 for log_record in models.RulebookProcessLog.objects.all(): - assert f"All log records older than {date_str}" in log_record.log - assert "Deleted 2 log rows." in log_record.log + assert f"Purged 2 log records older than {date_str}" in ( + log_record.log + ) + assert "[Recorded at:" in log_record.log else: # Only the two older processes lose rows and receive markers. assert models.RulebookProcessLog.objects.count() == 6 audit_logs = models.RulebookProcessLog.objects.filter( - log__contains=f"All log records older than {date_str}" + log__contains=f"Purged 2 log records older than {date_str}" ) assert audit_logs.count() == 2 - assert all("Deleted 2 log rows." in row.log for row in audit_logs) + assert all("[Recorded at:" in row.log for row in audit_logs) # Check that 10-day logs still exist (not purged) - original_logs = models.RulebookProcessLog.objects.exclude( - log__contains="purged" + original_logs = models.RulebookProcessLog.objects.filter( + log__startswith="activation-instance-10-days-ago" ) assert original_logs.count() == 4 @@ -374,15 +380,13 @@ def test_global_purge_includes_orphan_and_marks_each_process( assert not models.RulebookProcessLog.objects.filter( log__contains="for null test" ).exists() - markers = models.RulebookProcessLog.objects.filter( - log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT - ) + markers = _audit_markers() assert markers.count() == 2 orphan_marker = markers.get( activation_instance=null_activation_test_data["null_process"] ) - assert "Deleted 2 log rows." in orphan_marker.log - assert "Log Tracking id unavailable (orphaned process)." in ( + assert "Purged 2 log records older than" in orphan_marker.log + assert "Activation Lifecycle ID: unavailable (orphaned process)" in ( orphan_marker.log ) @@ -428,9 +432,7 @@ def test_purge_without_audit_trail_does_not_create_audit_logs( assert output.startswith("Purged 4 log records") assert models.RulebookProcessLog.objects.count() == 4 - assert not models.RulebookProcessLog.objects.filter( - log__contains="were purged at" - ).exists() + assert not _audit_markers().exists() assert "Purged 4 log records" in capsys.readouterr().out @@ -540,9 +542,7 @@ def test_activation_filter_limits_deletion_and_markers( cutoff, ) - audit_logs = models.RulebookProcessLog.objects.filter( - log__contains="were purged at" - ) + audit_logs = _audit_markers() assert output.startswith("Purged 4 log records") assert audit_logs.count() == 2 assert set( @@ -623,10 +623,13 @@ def test_retention_batches_continue_after_more_than_one_batch( assert not models.RulebookProcessLog.objects.filter( pk__in=[log.pk for log in logs] ).exists() - marker = models.RulebookProcessLog.objects.get( - log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT + marker = _audit_markers().get() + assert "Purged 5 log records older than" in marker.log + assert marker.log_created_at is not None + assert ( + f"Recorded at: {delete_log_util._utc_text(marker.log_created_at)}" + in marker.log ) - assert "Deleted 5 log rows." in marker.log @pytest.mark.django_db @@ -746,10 +749,8 @@ def fail_second_delete(queryset): assert error.value.deleted_count == 1 assert models.RulebookProcessLog.objects.count() == 3 - marker = models.RulebookProcessLog.objects.get( - log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT - ) - assert "Deleted 1 log rows." in marker.log + marker = _audit_markers().get() + assert "Purged 1 log record older than" in marker.log assert ( models.RulebookProcessLog.objects.filter( log__startswith="partial-" @@ -891,19 +892,22 @@ def test_zero_row_result_creates_no_marker(default_activation_instance): @pytest.mark.django_db -def test_invalid_internal_uuid_rejected_before_deletion( - default_activation_instance, +@pytest.mark.parametrize( + "invalid_id", ["", "bad id", "bad|id", "bad\nid", "école", "a" * 129] +) +def test_invalid_internal_job_id_rejected_before_deletion( + default_activation_instance, invalid_id ): log = models.RulebookProcessLog.objects.create( log="old", activation_instance=default_activation_instance, log_timestamp=1, ) - with pytest.raises(CommandError, match="must be a UUID"): + with pytest.raises(CommandError, match="must be a UUID or a custom ID"): call_command( "purge_log_records", date="2024-01-01", - **{"internal-job-uuid": "not-a-uuid"}, + **{"internal-job-uuid": invalid_id}, ) assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() @@ -925,53 +929,79 @@ def test_cli_valid_internal_uuid_is_in_default_audit_marker( "2024-01-01", "--audit-trail=true", "--internal-job-uuid", - str(job_id), + str(job_id).upper(), ) assert output.startswith("Purged 1 log records") - marker = models.RulebookProcessLog.objects.get( - log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT + marker = _audit_markers().get() + assert f"Purge Job ID: {job_id}" in marker.log + assert "Purged 1 log record older than" in marker.log + assert "[Recorded at:" in marker.log + + +@pytest.mark.django_db +def test_cli_custom_internal_job_id_is_in_audit_marker( + default_activation_instance, +): + models.RulebookProcessLog.objects.create( + log="old", + activation_instance=default_activation_instance, + log_timestamp=1, ) - assert f"Job ID: {job_id}." in marker.log - assert "Deleted 1 log rows." in marker.log + + output = call_command( + "purge_log_records", + "--date", + "2024-01-01", + "--internal-job-uuid", + "Freds-Troubleshootin-Logs", + ) + + assert output.startswith("Purged 1 log records") + marker = _audit_markers().get() + assert "Purge Job ID: Freds-Troubleshootin-Logs" in marker.log @pytest.mark.django_db -def test_prior_and_legacy_markers_are_never_counted_or_deleted( +def test_prior_markers_are_deleted_when_older_than_cutoff( default_activation_instance, ): process = default_activation_instance + prior_recorded_at = datetime(2024, 2, 1, tzinfo=datetime_timezone.utc) old_marker = models.RulebookProcessLog.objects.create( activation_instance=process, log=( - "All log records older than 2024-01-01 00:00:00 UTC were " - "purged at 2024-02-01 00:00:00 UTC." + "Purged 1 log record older than 2024-01-01 00:00:00 UTC. " + "[Recorded at: 2024-02-01 00:00:00 UTC]" ), - log_timestamp=1, + log_timestamp=int(prior_recorded_at.timestamp()), + log_created_at=prior_recorded_at, ) ordinary = models.RulebookProcessLog.objects.create( activation_instance=process, log="ordinary", log_timestamp=1 ) cutoff = datetime(2024, 3, 1, tzinfo=datetime_timezone.utc) - assert delete_log_util.delete_logs_older_than(cutoff) == 1 - first_marker = models.RulebookProcessLog.objects.get( - log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT - ) + assert delete_log_util.delete_logs_older_than(cutoff) == 2 + first_marker = _audit_markers().get() assert not models.RulebookProcessLog.objects.filter( pk=ordinary.pk ).exists() - assert models.RulebookProcessLog.objects.filter(pk=old_marker.pk).exists() - assert "Deleted 1 log rows." in first_marker.log + assert not models.RulebookProcessLog.objects.filter( + pk=old_marker.pk + ).exists() + assert "Purged 2 log records older than" in first_marker.log models.RulebookProcessLog.objects.filter(pk=first_marker.pk).update( log_timestamp=1 ) - assert delete_log_util.delete_logs_older_than(cutoff) == 0 - assert models.RulebookProcessLog.objects.filter( + assert delete_log_util.delete_logs_older_than(cutoff) == 1 + assert not models.RulebookProcessLog.objects.filter( pk=first_marker.pk ).exists() - assert models.RulebookProcessLog.objects.count() == 2 + replacement = _audit_markers().get() + assert "Purged 1 log record older than" in replacement.log + assert models.RulebookProcessLog.objects.count() == 1 @pytest.mark.django_db @@ -998,32 +1028,31 @@ def test_marker_uses_invocation_count_job_uuid_tracking_and_ceiled_timestamp( == 1 ) after_purge = timezone.now() - marker = models.RulebookProcessLog.objects.get( - log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT - ) + marker = _audit_markers().get() assert ( max(ceil(before_purge.timestamp()), ceil(cutoff.timestamp())) <= marker.log_timestamp <= max(ceil(after_purge.timestamp()), ceil(cutoff.timestamp())) ) - assert "2024-01-01 00:00:00.500000 UTC" in marker.log - assert "Deleted 1 log rows." in marker.log - assert f"Job ID: {job_id}." in marker.log - assert "Log Tracking id tracking-123." in marker.log + assert before_purge <= marker.log_created_at <= after_purge + assert marker.log.startswith( + "Purged 1 log record older than " + "2024-01-01 00:00:00.500000 UTC. [Recorded at: " + ) + assert marker.log.endswith( + f" | Purge Job ID: {job_id} | " + "Activation Lifecycle ID: tracking-123]" + ) models.RulebookProcessLog.objects.create( activation_instance=process, log="another old row", log_timestamp=1 ) assert delete_log_util.delete_logs_older_than(cutoff) == 1 - markers = list( - models.RulebookProcessLog.objects.filter( - log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT - ) - ) + markers = list(_audit_markers()) assert len(markers) == 2 - assert all("Deleted 1 log rows." in row.log for row in markers) + assert all("Purged 1 log record older than" in row.log for row in markers) assert ( - "Job ID:" + "Purge Job ID:" not in next(row for row in markers if row.pk != marker.pk).log ) @@ -1035,11 +1064,15 @@ def test_purge_all_logs_replaces_old_rows_and_markers_per_process( monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 2) normal = null_activation_test_data["normal_process"] orphan = null_activation_test_data["null_process"] + prior_recorded_at = datetime(2024, 2, 1, tzinfo=datetime_timezone.utc) models.RulebookProcessLog.objects.create( activation_instance=normal, - log="old purge marker", - log_timestamp=1, - log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT, + log=( + "Purged 1 log record older than 2024-01-01 00:00:00 UTC. " + "[Recorded at: 2024-02-01 00:00:00 UTC]" + ), + log_timestamp=int(prior_recorded_at.timestamp()), + log_created_at=prior_recorded_at, ) models.RulebookProcessLog.objects.create( activation_instance=normal, @@ -1049,10 +1082,11 @@ def test_purge_all_logs_replaces_old_rows_and_markers_per_process( models.RulebookProcessLog.objects.create( activation_instance=orphan, log=( - "All log records older than 2024-01-01 00:00:00 UTC were " - "purged at 2024-02-01 00:00:00 UTC." + "Purged 1 log record older than 2024-01-01 00:00:00 UTC. " + "[Recorded at: 2024-02-01 00:00:00 UTC]" ), - log_timestamp=1, + log_timestamp=int(prior_recorded_at.timestamp()), + log_created_at=prior_recorded_at, ) old_ids = set( models.RulebookProcessLog.objects.values_list("id", flat=True) @@ -1074,15 +1108,16 @@ def test_purge_all_logs_replaces_old_rows_and_markers_per_process( assert markers.count() == 2 normal_marker = markers.get(activation_instance=normal) orphan_marker = markers.get(activation_instance=orphan) - assert "Global log purge ran at" in normal_marker.log - assert "Deleted 4 log rows." in normal_marker.log - assert "Deleted 3 log rows." in orphan_marker.log - assert f"Job ID: {job_id}." in normal_marker.log - assert "Log Tracking id unavailable (orphaned process)." in ( + assert "Purged 4 log records globally. [Recorded at:" in normal_marker.log + assert "Purged 3 log records globally. [Recorded at:" in orphan_marker.log + assert f"Purge Job ID: {job_id}" in normal_marker.log + assert "Activation Lifecycle ID: unavailable (orphaned process)" in ( orphan_marker.log ) assert all( - marker.log_created_at == delete_log_util.PURGE_MARKER_CREATED_AT + marker.log_created_at is not None + and f"Recorded at: {delete_log_util._utc_text(marker.log_created_at)}" + in marker.log for marker in markers ) @@ -1177,7 +1212,5 @@ def fail_second_delete(queryset): ).count() == 1 ) - marker = models.RulebookProcessLog.objects.get( - log_created_at=delete_log_util.PURGE_MARKER_CREATED_AT - ) - assert "Deleted 1 log rows." in marker.log + marker = _audit_markers().get() + assert "Purged 1 log record globally." in marker.log diff --git a/tests/integration/tasks/test_management.py b/tests/integration/tasks/test_management.py index 065909e94..26edc4ac6 100644 --- a/tests/integration/tasks/test_management.py +++ b/tests/integration/tasks/test_management.py @@ -6,6 +6,7 @@ # # http://www.apache.org/licenses/LICENSE-2.0 +from datetime import datetime, timezone from unittest import mock import pytest @@ -13,10 +14,7 @@ from django.core.management.base import CommandError from aap_eda.core import models -from aap_eda.core.utils.delete_log_util import ( - PURGE_MARKER_CREATED_AT, - LogPurgeError, -) +from aap_eda.core.utils.delete_log_util import LogPurgeError from aap_eda.tasks.management import ( LOG_PURGE_TASK_TIMEOUT_SECONDS, _aap_eda_manage, @@ -90,11 +88,15 @@ def test_submit_log_purge_forwards_scope_when_audit_is_disabled(): def test_submitted_purge_all_logs_uses_same_command_and_job_id( default_activation_instance, new_activation_instance ): + prior_recorded_at = datetime(2024, 2, 1, tzinfo=timezone.utc) models.RulebookProcessLog.objects.create( activation_instance=default_activation_instance, - log="old marker", - log_timestamp=1, - log_created_at=PURGE_MARKER_CREATED_AT, + log=( + "Purged 1 log record older than 2024-01-01 00:00:00 UTC. " + "[Recorded at: 2024-02-01 00:00:00 UTC]" + ), + log_timestamp=int(prior_recorded_at.timestamp()), + log_created_at=prior_recorded_at, ) models.RulebookProcessLog.objects.create( activation_instance=default_activation_instance, @@ -127,10 +129,8 @@ def test_submitted_purge_all_logs_uses_same_command_and_job_id( assert result["deleted"] == 3 markers = models.RulebookProcessLog.objects.all() assert markers.count() == 2 - assert all(f"Job ID: {job_id}." in marker.log for marker in markers) - assert all( - marker.log_created_at == PURGE_MARKER_CREATED_AT for marker in markers - ) + assert all(f"Purge Job ID: {job_id}" in marker.log for marker in markers) + assert all(marker.log_created_at is not None for marker in markers) @pytest.mark.django_db @@ -176,14 +176,14 @@ def test_worker_invokes_purge_command_and_returns_deleted_count( ).exists() markers = models.RulebookProcessLog.objects.filter( activation_instance=default_activation_instance, - log__contains="were purged at", + log__startswith="Purged ", ) assert markers.count() == 1 - assert "Deleted 1 log rows." in markers.get().log - assert f"Job ID: {job_id}." in markers.get().log + assert "Purged 1 log record older than" in markers.get().log + assert f"Purge Job ID: {job_id}" in markers.get().log assert not models.RulebookProcessLog.objects.filter( activation_instance=new_activation_instance, - log__contains="were purged at", + log__startswith="Purged ", ).exists() assert any( call.args[0].startswith("Log purge finished") From 84446ba94e14831c3225aca0c0a867a479d3c246 Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Mon, 26 Oct 2026 15:23:58 -0400 Subject: [PATCH 08/15] feat(logs): make purge delete batch size configurable Allows operators to tune purge transaction size for larger log volumes while keeping process traversal bounded. Caps large batches to avoid exceeding PostgreSQL query parameter limits. Assisted by: GPT-6 --- docs/development.md | 12 ++ src/aap_eda/api/serializers/activation.py | 16 ++- src/aap_eda/api/views/activation.py | 4 +- .../management/commands/purge_log_records.py | 15 ++ src/aap_eda/core/utils/delete_log_util.py | 36 ++++- src/aap_eda/tasks/management.py | 3 + tests/integration/api/test_log_purge.py | 29 ++++ tests/integration/api/test_openapi.py | 7 + .../commands/test_purge_log_records.py | 136 ++++++++++++++++-- 9 files changed, 243 insertions(+), 15 deletions(-) diff --git a/docs/development.md b/docs/development.md index 5d7fe7a9c..281db7a41 100644 --- a/docs/development.md +++ b/docs/development.md @@ -483,6 +483,12 @@ Do **not** confuse the two — see the command docstring in activations. Empty or unknown selectors are rejected before queueing. - **Choose audit behavior:** Audit markers are enabled by default. Set API `audit_trail` to `false` to disable them. +- **Choose a log-delete batch size:** Optionally send + `"log_delete_batch_size": 5000` to delete at most 5,000 log rows per + transaction. The default is 10,000 and accepted values are 1–50,000. + A very large activation scope can lower the effective batch size to stay + within PostgreSQL's query-parameter limit. This setting does not change the + 1,000-process fetch size. For example, this request queues a purge for the named activation: @@ -518,6 +524,10 @@ Content-Type: application/json activation and processes without an activation. - Use `--audit-trail=true` or `--audit-trail=false`. A bare `--audit-trail` is invalid. +- Use `--log-delete-batch-size N` to set the maximum number of log rows + deleted per transaction. The default is 10,000 and the accepted range is + 1–50,000. This works for cutoff and full purges; process fetching stays at + 1,000 processes per page. - The optional `--internal-job-uuid` accepts a UUID or a custom ID of 1-128 ASCII letters, digits, periods, underscores, or hyphens, starting with a letter or digit. Valid UUIDs are normalized. The value appears in audit @@ -528,6 +538,8 @@ Content-Type: application/json - Deletion commits in batches. If a later batch fails, worker logs record the count already deleted, and the job reports failure. Audit markers record the partial count when audit is enabled. +- A larger log-delete batch size can reduce database round trips, while each + transaction holds more rows and a failed batch can roll back more work. - When audit is enabled, each process that loses log rows gets one marker with its count for this invocation. Markers use `Recorded at` for the time the audit row was written and store that time in `log_created_at`. The API diff --git a/src/aap_eda/api/serializers/activation.py b/src/aap_eda/api/serializers/activation.py index 7d0404fff..5975764e0 100644 --- a/src/aap_eda/api/serializers/activation.py +++ b/src/aap_eda/api/serializers/activation.py @@ -55,7 +55,11 @@ get_resolved_secrets, get_secret_fields, ) -from aap_eda.core.utils.delete_log_util import resolve_activation_ids +from aap_eda.core.utils.delete_log_util import ( + DEFAULT_LOG_DELETE_BATCH_SIZE, + MAX_LOG_DELETE_BATCH_SIZE, + resolve_activation_ids, +) from aap_eda.core.utils.k8s_service_name import create_k8s_service_name from aap_eda.core.utils.log_retention import retention_cutoff from aap_eda.core.utils.rulebook import ( @@ -108,6 +112,16 @@ class LogPurgeRequestSerializer(serializers.Serializer): default=True, help_text="Write one audit marker per process that loses logs.", ) + log_delete_batch_size = serializers.IntegerField( + required=False, + min_value=1, + max_value=MAX_LOG_DELETE_BATCH_SIZE, + help_text=( + "Maximum log rows deleted per transaction " + f"(1-{MAX_LOG_DELETE_BATCH_SIZE:,}; " + f"default: {DEFAULT_LOG_DELETE_BATCH_SIZE:,})." + ), + ) activation_ids = serializers.ListField( child=serializers.IntegerField(min_value=1), required=False, diff --git a/src/aap_eda/api/views/activation.py b/src/aap_eda/api/views/activation.py index a1d2b14c3..0f2e55022 100644 --- a/src/aap_eda/api/views/activation.py +++ b/src/aap_eda/api/views/activation.py @@ -888,7 +888,9 @@ class LogPurgeViewSet(viewsets.GenericViewSet): "combined with a cutoff, activation selectors, or disabled " "audit. Without activation selectors, all processes, including " "orphaned ones, are included. Activation IDs and names limit " - "cutoff deletion to their union. The returned job ID " + "cutoff deletion to their union. The optional " + "log_delete_batch_size sets the maximum log rows deleted per " + "transaction (1-50,000; default 10,000). The returned job ID " "acknowledges scheduling only." ), request=serializers.LogPurgeRequestSerializer, diff --git a/src/aap_eda/core/management/commands/purge_log_records.py b/src/aap_eda/core/management/commands/purge_log_records.py index 21eaf6a41..990e94232 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -24,6 +24,8 @@ ) from aap_eda.core.utils.delete_log_util import ( + DEFAULT_LOG_DELETE_BATCH_SIZE, + MAX_LOG_DELETE_BATCH_SIZE, LogPurgeError, delete_logs_older_than, ) @@ -98,6 +100,18 @@ def add_arguments(self, parser: CommandParser) -> None: metavar="true|false", help="Create a marker for each affected process (default: true).", ) + parser.add_argument( + "--log-delete-batch-size", + dest="log_delete_batch_size", + type=int, + default=DEFAULT_LOG_DELETE_BATCH_SIZE, + metavar="N", + help=( + "Delete at most N log rows per transaction " + f"(default: {DEFAULT_LOG_DELETE_BATCH_SIZE}; " + f"range: 1-{MAX_LOG_DELETE_BATCH_SIZE})." + ), + ) parser.add_argument( "--internal-job-uuid", dest="internal-job-uuid", @@ -209,6 +223,7 @@ def handle(self, *args, **options): audit_trail=audit_trail, internal_job_uuid=job_uuid, purge_all_logs=purge_all_logs, + log_delete_batch_size=options["log_delete_batch_size"], ) except (LogPurgeError, ValueError) as exc: raise CommandError(str(exc)) from exc diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index 45be061ba..6f9f2a540 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -21,7 +21,10 @@ from aap_eda.core import models -DELETE_BATCH_SIZE = 1000 +PROCESS_PAGE_SIZE = 1000 +DEFAULT_LOG_DELETE_BATCH_SIZE = 10_000 +MAX_LOG_DELETE_BATCH_SIZE = 50_000 +POSTGRES_QUERY_PARAMETER_LIMIT = 65_535 def _utc_text(value: datetime) -> str: @@ -48,6 +51,7 @@ class _PurgeOptions: audit_trail: bool internal_job_uuid: str | None purge_all_logs: bool + log_delete_batch_size: int def resolve_activation_ids( @@ -146,7 +150,17 @@ def _validate_purge_options( audit_trail: bool, internal_job_uuid: str | None, purge_all_logs: bool, + log_delete_batch_size: int, ) -> _PurgeOptions: + if ( + not isinstance(log_delete_batch_size, int) + or isinstance(log_delete_batch_size, bool) + or not 1 <= log_delete_batch_size <= MAX_LOG_DELETE_BATCH_SIZE + ): + raise ValueError( + "log_delete_batch_size must be an integer between 1 and " + f"{MAX_LOG_DELETE_BATCH_SIZE}." + ) if not isinstance(purge_all_logs, bool): raise ValueError("purge_all_logs must be a boolean.") if purge_all_logs: @@ -167,6 +181,19 @@ def _validate_purge_options( raise ValueError("A cutoff is required unless purging all logs.") selected_ids = resolve_activation_ids(activation_ids, activation_names) cutoff_timestamp = cutoff.timestamp() + if selected_ids is not None: + # Scoped queries also bind each activation ID. Reserve four + # parameters for the process, cutoff, and keyset bounds. + available_log_parameters = ( + POSTGRES_QUERY_PARAMETER_LIMIT - len(selected_ids) - 4 + ) + if available_log_parameters < 1: + raise ValueError( + "Too many selected activations for a log purge query." + ) + log_delete_batch_size = min( + log_delete_batch_size, available_log_parameters + ) return _PurgeOptions( cutoff, cutoff_timestamp, @@ -174,6 +201,7 @@ def _validate_purge_options( audit_trail, internal_job_uuid, purge_all_logs, + log_delete_batch_size, ) @@ -239,7 +267,7 @@ def _purge_process_logs(process: tuple, options: _PurgeOptions): batch_ids = list( qualifying.filter(id__gt=last_log_id, id__lte=highest_log_id) .order_by("id") - .values_list("id", flat=True)[:DELETE_BATCH_SIZE] + .values_list("id", flat=True)[: options.log_delete_batch_size] ) if not batch_ids: break @@ -277,6 +305,7 @@ def delete_logs_older_than( audit_trail: bool = True, internal_job_uuid: str | None = None, purge_all_logs: bool = False, + log_delete_batch_size: int = DEFAULT_LOG_DELETE_BATCH_SIZE, ) -> int: """Purge logs per process in committed, bounded ID batches.""" options = _validate_purge_options( @@ -286,6 +315,7 @@ def delete_logs_older_than( audit_trail=audit_trail, internal_job_uuid=internal_job_uuid, purge_all_logs=purge_all_logs, + log_delete_batch_size=log_delete_batch_size, ) processes = models.RulebookProcess.objects.all() if options.selected_ids is not None: @@ -305,7 +335,7 @@ def delete_logs_older_than( .order_by("id") .values_list( "id", "activation_id", "activation__log_tracking_id" - )[:DELETE_BATCH_SIZE] + )[:PROCESS_PAGE_SIZE] ) if not process_batch: break diff --git a/src/aap_eda/tasks/management.py b/src/aap_eda/tasks/management.py index 746b69987..372affeef 100644 --- a/src/aap_eda/tasks/management.py +++ b/src/aap_eda/tasks/management.py @@ -39,6 +39,7 @@ def submit_log_purge( activation_ids: list[int] | None = None, activation_names: list[str] | None = None, purge_all_logs: bool = False, + log_delete_batch_size: int | None = None, ) -> str: """Submit a fixed-purpose log purge task.""" command_options = {"audit_trail": audit_trail} @@ -52,6 +53,8 @@ def submit_log_purge( command_options["activation-names"] = activation_names if purge_all_logs: command_options["purge-all-logs"] = True + if log_delete_batch_size is not None: + command_options["log_delete_batch_size"] = log_delete_batch_size return aap_eda_manage_commands( "purge_log_records", diff --git a/tests/integration/api/test_log_purge.py b/tests/integration/api/test_log_purge.py index 9cf1ee6c7..3be1efbff 100644 --- a/tests/integration/api/test_log_purge.py +++ b/tests/integration/api/test_log_purge.py @@ -131,6 +131,28 @@ def test_superuser_queues_purge_all_logs_without_cutoff(superuser_client): ) +@pytest.mark.django_db +@pytest.mark.parametrize( + "payload, expected_size", + [ + ({"before_date": "2020-01-01", "log_delete_batch_size": 1}, 1), + ({"purge-all-logs": True, "log_delete_batch_size": 50_000}, 50_000), + ], +) +def test_api_forwards_log_delete_batch_size( + superuser_client, payload, expected_size +): + with mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": str(JOB_ID)}, "default"), + ) as submit_task: + response = superuser_client.post(PURGE_URL, payload, format="json") + + assert response.status_code == status.HTTP_202_ACCEPTED + command_options = submit_task.call_args.kwargs["args"][2] + assert command_options["log_delete_batch_size"] == expected_size + + @pytest.mark.django_db def test_api_keeps_activation_scope_when_audit_is_disabled( superuser_client, default_activation @@ -199,6 +221,13 @@ def test_anonymous_purge_uses_api_permission_denial(base_client): {"before_date": "2020-01-01", "activation_id": "invalid"}, {"before_date": "2020-01-01", "activation_id": None}, {"before_date": "2020-01-01", "activation_namess": ["demo"]}, + {"before_date": "2020-01-01", "log_delete_batch_size": 0}, + {"before_date": "2020-01-01", "log_delete_batch_size": -1}, + {"before_date": "2020-01-01", "log_delete_batch_size": 50_001}, + {"before_date": "2020-01-01", "log_delete_batch_size": True}, + {"before_date": "2020-01-01", "log_delete_batch_size": 1.5}, + {"before_date": "2020-01-01", "log_delete_batch_size": "abc"}, + {"purge-all-logs": True, "log_delete_batch_size": 50_001}, { "before_date": "2020-01-01", "activation_names": ["missing-activation"], diff --git a/tests/integration/api/test_openapi.py b/tests/integration/api/test_openapi.py index e86c74e0a..7a2718606 100644 --- a/tests/integration/api/test_openapi.py +++ b/tests/integration/api/test_openapi.py @@ -110,11 +110,18 @@ def test_log_purge_openapi_contract(admin_client): "before_date", "retention_duration", "audit_trail", + "log_delete_batch_size", "activation_ids", "activation_names", "purge-all-logs", } assert request_properties["audit_trail"]["default"] is True + assert request_properties["log_delete_batch_size"]["minimum"] == 1 + assert request_properties["log_delete_batch_size"]["maximum"] == 50_000 + assert ( + "default: 10,000" + in request_properties["log_delete_batch_size"]["description"] + ) assert request_properties["purge-all-logs"]["default"] is False assert "internal_job_uuid" not in request_properties diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index f73b53040..1577963b6 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -445,6 +445,109 @@ def test_purge_retention_setting_does_not_supply_cutoff(prepare_log_records): assert models.RulebookProcessLog.objects.count() == 8 +@pytest.mark.django_db +@pytest.mark.parametrize("batch_size", [0, -1, 50_001, True, "2", 1.5, None]) +def test_programmatic_batch_size_rejected_before_deletion( + default_activation_instance, batch_size +): + log = models.RulebookProcessLog.objects.create( + activation_instance=default_activation_instance, + log="must remain", + log_timestamp=1, + ) + + with pytest.raises(CommandError, match="log_delete_batch_size"): + call_command( + "purge_log_records", + date="2024-01-01", + log_delete_batch_size=batch_size, + ) + + assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() + + +@pytest.mark.django_db +@pytest.mark.parametrize("batch_size", [0, -1, 50_001, True, "2", 1.5, None]) +def test_utility_rejects_invalid_batch_size_before_deletion( + default_activation_instance, batch_size +): + log = models.RulebookProcessLog.objects.create( + activation_instance=default_activation_instance, + log="must remain", + log_timestamp=1, + ) + + with pytest.raises(ValueError, match="log_delete_batch_size"): + delete_log_util.delete_logs_older_than( + datetime(2024, 1, 1, tzinfo=datetime_timezone.utc), + log_delete_batch_size=batch_size, + ) + + assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() + + +@pytest.mark.django_db +@pytest.mark.parametrize("batch_size", ["0", "50001", "not-an-integer"]) +def test_cli_rejects_invalid_batch_size_before_deletion( + default_activation_instance, batch_size +): + log = models.RulebookProcessLog.objects.create( + activation_instance=default_activation_instance, + log="must remain", + log_timestamp=1, + ) + + with pytest.raises(CommandError): + call_command( + "purge_log_records", + "--date", + "2024-01-01", + "--log-delete-batch-size", + batch_size, + ) + + assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() + + +@pytest.mark.django_db +def test_cli_batch_size_defaults_to_10000_and_accepts_50000(): + with mock.patch( + "aap_eda.core.management.commands.purge_log_records." + "delete_logs_older_than", + return_value=0, + ) as delete_logs: + call_command("purge_log_records", "--date", "2024-01-01") + assert delete_logs.call_args.kwargs["log_delete_batch_size"] == 10_000 + + call_command( + "purge_log_records", + "--date", + "2024-01-01", + "--log-delete-batch-size", + "50000", + ) + assert delete_logs.call_args.kwargs["log_delete_batch_size"] == 50_000 + + +def test_large_activation_scope_caps_effective_log_batch_size(): + with mock.patch.object( + delete_log_util, + "resolve_activation_ids", + return_value=set(range(20_000)), + ): + options = delete_log_util._validate_purge_options( + datetime(2024, 1, 1, tzinfo=datetime_timezone.utc), + activation_ids=[1], + activation_names=None, + audit_trail=True, + internal_job_uuid=None, + purge_all_logs=False, + log_delete_batch_size=50_000, + ) + + assert options.log_delete_batch_size == 45_531 + + @pytest.mark.django_db @pytest.mark.parametrize( "args", @@ -602,7 +705,6 @@ def test_retention_duration_deletes_strictly_older_rows_across_activations( def test_retention_batches_continue_after_more_than_one_batch( default_activation_instance, monkeypatch ): - monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 2) logs = models.RulebookProcessLog.objects.bulk_create( [ models.RulebookProcessLog( @@ -613,16 +715,26 @@ def test_retention_batches_continue_after_more_than_one_batch( for index in range(5) ] ) + original_delete = QuerySet.delete + deleted_batch_sizes = [] + + def record_batch_size(queryset): + deleted_batch_sizes.append(queryset.count()) + return original_delete(queryset) + + monkeypatch.setattr(QuerySet, "delete", record_batch_size) assert ( delete_log_util.delete_logs_older_than( - datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) + datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc), + log_delete_batch_size=2, ) == 5 ) assert not models.RulebookProcessLog.objects.filter( pk__in=[log.pk for log in logs] ).exists() + assert deleted_batch_sizes == [2, 2, 1] marker = _audit_markers().get() assert "Purged 5 log records older than" in marker.log assert marker.log_created_at is not None @@ -636,7 +748,6 @@ def test_retention_batches_continue_after_more_than_one_batch( def test_retention_stops_at_initial_highest_qualifying_id( default_activation_instance, monkeypatch ): - monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 1) models.RulebookProcessLog.objects.bulk_create( [ models.RulebookProcessLog( @@ -667,7 +778,8 @@ def insert_after_first_batch(queryset): monkeypatch.setattr(QuerySet, "delete", insert_after_first_batch) deleted = delete_log_util.delete_logs_older_than( - datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) + datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc), + log_delete_batch_size=1, ) assert deleted == 2 @@ -721,7 +833,6 @@ def test_retention_with_no_matching_rows_returns_zero( def test_retention_failure_reports_committed_batch_count( default_activation_instance, monkeypatch ): - monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 1) models.RulebookProcessLog.objects.bulk_create( [ models.RulebookProcessLog( @@ -745,7 +856,7 @@ def fail_second_delete(queryset): monkeypatch.setattr(QuerySet, "delete", fail_second_delete) cutoff = datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) with pytest.raises(delete_log_util.LogPurgeError) as error: - delete_log_util.delete_logs_older_than(cutoff) + delete_log_util.delete_logs_older_than(cutoff, log_delete_batch_size=1) assert error.value.deleted_count == 1 assert models.RulebookProcessLog.objects.count() == 3 @@ -1059,9 +1170,8 @@ def test_marker_uses_invocation_count_job_uuid_tracking_and_ceiled_timestamp( @pytest.mark.django_db def test_purge_all_logs_replaces_old_rows_and_markers_per_process( - null_activation_test_data, monkeypatch + null_activation_test_data, ): - monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 2) normal = null_activation_test_data["normal_process"] orphan = null_activation_test_data["null_process"] prior_recorded_at = datetime(2024, 2, 1, tzinfo=datetime_timezone.utc) @@ -1098,6 +1208,8 @@ def test_purge_all_logs_replaces_old_rows_and_markers_per_process( "--purge-all-logs", "--internal-job-uuid", str(job_id), + "--log-delete-batch-size", + "2", ) assert output.startswith("Purged 7 log records globally") @@ -1181,7 +1293,6 @@ def test_purge_all_logs_with_no_rows_creates_no_marker( def test_purge_all_logs_failure_keeps_committed_marker_count( default_activation_instance, monkeypatch ): - monkeypatch.setattr(delete_log_util, "DELETE_BATCH_SIZE", 1) models.RulebookProcessLog.objects.bulk_create( [ models.RulebookProcessLog( @@ -1204,7 +1315,12 @@ def fail_second_delete(queryset): monkeypatch.setattr(QuerySet, "delete", fail_second_delete) with pytest.raises(CommandError, match="failed after 1 committed rows"): - call_command("purge_log_records", "--purge-all-logs") + call_command( + "purge_log_records", + "--purge-all-logs", + "--log-delete-batch-size", + "1", + ) assert ( models.RulebookProcessLog.objects.filter( From f7156b4ef55c5d29eaefd73d48a116670a598beb Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Mon, 26 Oct 2026 16:03:47 -0400 Subject: [PATCH 09/15] fix sonar cloud failure --- src/aap_eda/core/utils/delete_log_util.py | 22 +++++++++++-------- .../commands/test_purge_log_records.py | 3 ++- 2 files changed, 15 insertions(+), 10 deletions(-) diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index 6f9f2a540..ad65764d6 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -142,6 +142,18 @@ def _marker_text( return f"{text} [{' | '.join(details)}]" +def _validate_log_delete_batch_size(log_delete_batch_size: int) -> None: + if ( + not isinstance(log_delete_batch_size, int) + or isinstance(log_delete_batch_size, bool) + or not 1 <= log_delete_batch_size <= MAX_LOG_DELETE_BATCH_SIZE + ): + raise ValueError( + "log_delete_batch_size must be an integer between 1 and " + f"{MAX_LOG_DELETE_BATCH_SIZE}." + ) + + def _validate_purge_options( cutoff: datetime | None, *, @@ -152,15 +164,7 @@ def _validate_purge_options( purge_all_logs: bool, log_delete_batch_size: int, ) -> _PurgeOptions: - if ( - not isinstance(log_delete_batch_size, int) - or isinstance(log_delete_batch_size, bool) - or not 1 <= log_delete_batch_size <= MAX_LOG_DELETE_BATCH_SIZE - ): - raise ValueError( - "log_delete_batch_size must be an integer between 1 and " - f"{MAX_LOG_DELETE_BATCH_SIZE}." - ) + _validate_log_delete_batch_size(log_delete_batch_size) if not isinstance(purge_all_logs, bool): raise ValueError("purge_all_logs must be a boolean.") if purge_all_logs: diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index 1577963b6..5061916a3 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -477,9 +477,10 @@ def test_utility_rejects_invalid_batch_size_before_deletion( log_timestamp=1, ) + cutoff = datetime(2024, 1, 1, tzinfo=datetime_timezone.utc) with pytest.raises(ValueError, match="log_delete_batch_size"): delete_log_util.delete_logs_older_than( - datetime(2024, 1, 1, tzinfo=datetime_timezone.utc), + cutoff, log_delete_batch_size=batch_size, ) From fd15df43b6b191d51c555d4aed90934279cb4f9e Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Mon, 26 Oct 2026 17:25:16 -0400 Subject: [PATCH 10/15] chore(logs): remove unused retention setting --- docs/development.md | 2 +- src/aap_eda/settings/defaults.py | 3 --- .../commands/test_purge_log_records.py | 17 +++-------------- 3 files changed, 4 insertions(+), 18 deletions(-) diff --git a/docs/development.md b/docs/development.md index 281db7a41..d87745208 100644 --- a/docs/development.md +++ b/docs/development.md @@ -546,7 +546,7 @@ Content-Type: application/json returns this recorded time. - Cutoff purges treat earlier markers like other log rows: they are deleted and counted once their `log_timestamp` falls before the cutoff. Recent markers - can therefore remain across scheduled purges until they reach the cutoff. + can therefore remain until a later cutoff purge reaches them. **Check the outcome** diff --git a/src/aap_eda/settings/defaults.py b/src/aap_eda/settings/defaults.py index 478fe6c4b..b3c1a44fb 100644 --- a/src/aap_eda/settings/defaults.py +++ b/src/aap_eda/settings/defaults.py @@ -161,9 +161,6 @@ RULEBOOK_QUEUE_NAME: str = "activation" -# Nonpositive values disable scheduled/default log deletion. -ACTIVATION_DB_LOG_RETENTION_DAYS: int = 0 - API_PREFIX: str = "api/eda" APP_LOG_LEVEL: str = "INFO" diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index 5061916a3..5b63771fd 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -22,7 +22,6 @@ from django.core.management.base import CommandError from django.db import connection, transaction from django.db.models.query import QuerySet -from django.test import override_settings from django.utils import timezone from aap_eda.core import enums, models @@ -169,10 +168,9 @@ def prepare_log_records( @pytest.mark.django_db -def test_purge_log_records_requires_explicit_cutoff_even_with_setting(): - with override_settings(ACTIVATION_DB_LOG_RETENTION_DAYS=0): - with pytest.raises(CommandError, match="Exactly one"): - call_command("purge_log_records") +def test_purge_log_records_requires_explicit_cutoff(): + with pytest.raises(CommandError, match="Exactly one"): + call_command("purge_log_records") @pytest.mark.django_db @@ -436,15 +434,6 @@ def test_purge_without_audit_trail_does_not_create_audit_logs( assert "Purged 4 log records" in capsys.readouterr().out -@pytest.mark.django_db -def test_purge_retention_setting_does_not_supply_cutoff(prepare_log_records): - with override_settings(ACTIVATION_DB_LOG_RETENTION_DAYS=15): - with pytest.raises(CommandError, match="Exactly one"): - call_command("purge_log_records") - - assert models.RulebookProcessLog.objects.count() == 8 - - @pytest.mark.django_db @pytest.mark.parametrize("batch_size", [0, -1, 50_001, True, "2", 1.5, None]) def test_programmatic_batch_size_rejected_before_deletion( From 0a776bbcad552437e3d49256a41f6b9a6ce7bc6e Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Mon, 26 Oct 2026 19:19:42 -0400 Subject: [PATCH 11/15] fix(logs): purge logs without activation instances Some customer databases contain logs with a NULL activation instance. The per-process purge cannot reach them, leaving rows behind after --purge-all-logs. Delete them in bounded batches and include them in the reported total without claiming an audit marker was created. Assisted by: GPT-6 --- src/aap_eda/api/views/activation.py | 10 +++--- .../management/commands/purge_log_records.py | 32 +++++++++++++++---- src/aap_eda/core/utils/delete_log_util.py | 26 +++++++++++++++ .../commands/test_purge_log_records.py | 28 ++++++++++++++++ 4 files changed, 85 insertions(+), 11 deletions(-) diff --git a/src/aap_eda/api/views/activation.py b/src/aap_eda/api/views/activation.py index 0f2e55022..8ebeeedd6 100644 --- a/src/aap_eda/api/views/activation.py +++ b/src/aap_eda/api/views/activation.py @@ -883,10 +883,12 @@ class LogPurgeViewSet(viewsets.GenericViewSet): "Queue deletion of process logs using one UTC cutoff: " "before_date (YYYY-MM-DD) or retention_duration (positive ISO " "8601). Alternatively, purge-all-logs=true deletes every " - "existing log, including prior audit markers, and leaves one " - "new audit marker per affected process. This mode cannot be " - "combined with a cutoff, activation selectors, or disabled " - "audit. Without activation selectors, all processes, including " + "existing log, including prior audit markers and logs without " + "a process, and leaves one new audit marker per affected " + "process. Logs without a process cannot receive a marker. " + "This mode cannot be combined with a cutoff, activation " + "selectors, or disabled audit. Without activation selectors, " + "all processes, including " "orphaned ones, are included. Activation IDs and names limit " "cutoff deletion to their union. The optional " "log_delete_batch_size sets the maximum log rows deleted per " diff --git a/src/aap_eda/core/management/commands/purge_log_records.py b/src/aap_eda/core/management/commands/purge_log_records.py index 990e94232..5901a4659 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -28,6 +28,7 @@ MAX_LOG_DELETE_BATCH_SIZE, LogPurgeError, delete_logs_older_than, + purge_unattached_logs, ) from aap_eda.core.utils.log_retention import retention_cutoff @@ -37,8 +38,8 @@ class Command(BaseCommand): help = ( "Purge log records older than exactly one cutoff, or use " - "--purge-all-logs to replace every existing log with an audit " - "marker. Without activation " + "--purge-all-logs to delete every existing log and leave one audit " + "marker per affected process. Without activation " "selectors, include every process (including orphaned processes). " "Activation IDs and names limit deletion to their union. " "One audit marker per affected process is enabled by default." @@ -88,8 +89,10 @@ def add_arguments(self, parser: CommandParser) -> None: help=( "Delete all existing process logs at every timestamp, " "including earlier audit markers, and leave one new audit " - "marker per affected process. Cannot be combined with a " - "cutoff, activation selectors, or --audit-trail=false." + "marker per affected process. Also delete logs without a " + "process, which cannot receive a marker. Cannot be combined " + "with a cutoff, activation selectors, or " + "--audit-trail=false." ), ) parser.add_argument( @@ -193,6 +196,18 @@ def _validated_audit_trail(self, value, purge_all_logs: bool) -> bool: raise CommandError("--purge-all-logs requires audit trail.") return value + @staticmethod + def _delete_unattached_logs(deleted_count: int, batch_size: int) -> int: + try: + for batch_deleted in purge_unattached_logs(batch_size): + deleted_count += batch_deleted + except Exception as exc: + raise CommandError( + f"Log purge failed after {deleted_count} committed rows: " + f"{exc}" + ) from exc + return deleted_count + def handle(self, *args, **options): ids = options.get("activation-ids") names = options.get("activation-names") @@ -216,7 +231,7 @@ def handle(self, *args, **options): ) try: - deleted_count = delete_logs_older_than( + process_deleted_count = delete_logs_older_than( cutoff, activation_ids=ids, activation_names=names, @@ -229,9 +244,12 @@ def handle(self, *args, **options): raise CommandError(str(exc)) from exc if purge_all_logs: + deleted_count = self._delete_unattached_logs( + process_deleted_count, options["log_delete_batch_size"] + ) marker_result = ( "Created audit markers for affected processes." - if deleted_count + if process_deleted_count else "No audit markers created." ) return self.style.SUCCESS( @@ -245,6 +263,6 @@ def handle(self, *args, **options): else "for selected activations" ) return self.style.SUCCESS( - f"Purged {deleted_count} log records older than " + f"Purged {process_deleted_count} log records older than " f"{cutoff.strftime('%Y-%m-%d %H:%M:%S UTC')} {scope}." ) diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index ad65764d6..200d68689 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -301,6 +301,32 @@ def _purge_process_logs(process: tuple, options: _PurgeOptions): yield batch_deleted +def purge_unattached_logs(log_delete_batch_size: int): + """Yield deleted counts for bounded batches of logs without a process.""" + qualifying = models.RulebookProcessLog.objects.filter( + activation_instance_id__isnull=True + ) + highest_log_id = qualifying.aggregate(max_id=Max("id"))["max_id"] + if highest_log_id is None: + return + + last_log_id = 0 + model_label = models.RulebookProcessLog._meta.label + while last_log_id < highest_log_id: + batch_ids = list( + qualifying.filter(id__gt=last_log_id, id__lte=highest_log_id) + .order_by("id") + .values_list("id", flat=True)[:log_delete_batch_size] + ) + if not batch_ids: + break + with transaction.atomic(): + _, per_model_counts = qualifying.filter(id__in=batch_ids).delete() + batch_deleted = per_model_counts.get(model_label, 0) + last_log_id = batch_ids[-1] + yield batch_deleted + + def delete_logs_older_than( cutoff: datetime | None, *, diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index 5b63771fd..ae85499a6 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -1279,6 +1279,34 @@ def test_purge_all_logs_with_no_rows_creates_no_marker( assert not models.RulebookProcessLog.objects.exists() +@pytest.mark.django_db +def test_purge_all_logs_deletes_logs_without_process(): + assert not models.RulebookProcess.objects.exists() + with connection.cursor() as cursor: + cursor.execute( + "ALTER TABLE core_rulebook_process_log " + "ALTER COLUMN activation_instance_id DROP NOT NULL" + ) + cursor.execute( + "INSERT INTO core_rulebook_process_log " + "(activation_instance_id, log, log_timestamp) " + "SELECT NULL, 'unattached-' || series.n, 1 " + "FROM generate_series(1, 5) AS series(n) RETURNING id" + ) + inserted_ids = [row[0] for row in cursor.fetchall()] + assert len(inserted_ids) == 5 + + output = call_command( + "purge_log_records", "--purge-all-logs", "--log-delete-batch-size", "2" + ) + + assert output.startswith("Purged 5 log records globally") + assert "No audit markers created." in output + assert not models.RulebookProcessLog.objects.filter( + id__in=inserted_ids + ).exists() + + @pytest.mark.django_db(transaction=True) def test_purge_all_logs_failure_keeps_committed_marker_count( default_activation_instance, monkeypatch From 274c632201def21fef446b6e9d24ebfcd10bf0a5 Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Tue, 27 Oct 2026 11:26:13 -0400 Subject: [PATCH 12/15] feat(logs): simplify purge deletion and allow global cutoffs Reduce database work during log purges and let operators apply a retention cutoff across all activations, including unattached logs. Assisted by: GPT-6 --- docs/development.md | 42 ++- src/aap_eda/api/serializers/activation.py | 46 ++- src/aap_eda/api/views/activation.py | 21 +- .../management/commands/purge_log_records.py | 101 +++---- src/aap_eda/core/utils/delete_log_util.py | 171 +++-------- src/aap_eda/tasks/management.py | 3 - tests/integration/api/test_log_purge.py | 54 ++-- tests/integration/api/test_openapi.py | 7 - .../commands/test_purge_log_records.py | 270 +++++++++--------- 9 files changed, 294 insertions(+), 421 deletions(-) diff --git a/docs/development.md b/docs/development.md index d87745208..77dc90fd9 100644 --- a/docs/development.md +++ b/docs/development.md @@ -471,10 +471,11 @@ Do **not** confuse the two — see the command docstring in `retention_duration`. Only rows with `log_timestamp` strictly before the cutoff qualify, including earlier audit markers. Future UTC cutoffs are rejected. -- **Purge every existing log:** Instead, send `"purge-all-logs": true` without - a cutoff or activation selectors. This deletes ordinary logs and earlier - audit markers from every process, then leaves one new audit marker per - process that lost rows. The deleted count includes earlier markers. If +- **Purge logs globally:** Send `"purge-all-logs": true` without activation + selectors. Alone, it deletes logs at every timestamp. Combine it with + `before_date` or `retention_duration` to delete only older logs, including + unattached logs. Each affected process receives a new audit marker; unattached + logs cannot receive one. The deleted count includes earlier markers. If processes keep writing logs, new rows can appear during or after the purge. Without a cutoff or this flag, the API returns HTTP 400 before queueing. - **Choose the scope:** With no selectors, qualifying logs from every @@ -483,12 +484,6 @@ Do **not** confuse the two — see the command docstring in activations. Empty or unknown selectors are rejected before queueing. - **Choose audit behavior:** Audit markers are enabled by default. Set API `audit_trail` to `false` to disable them. -- **Choose a log-delete batch size:** Optionally send - `"log_delete_batch_size": 5000` to delete at most 5,000 log rows per - transaction. The default is 10,000 and accepted values are 1–50,000. - A very large activation scope can lower the effective batch size to stay - within PostgreSQL's query-parameter limit. This setting does not change the - 1,000-process fetch size. For example, this request queues a purge for the named activation: @@ -509,14 +504,23 @@ Content-Type: application/json {"purge-all-logs": true} ``` +To purge logs globally before a cutoff: + +```http +POST /api/eda/v1/logs/purge/ +Content-Type: application/json + +{"purge-all-logs": true, "before_date": "2024-01-01"} +``` + **CLI options** - Use either `--date YYYY-MM-DD` or `--retention-duration P30D`. Calendar months and years in a duration are subtracted in UTC. If the target month lacks the original day, the cutoff uses that month's final day. -- Use `--purge-all-logs` instead of a cutoff to delete every existing log and - replace prior audit markers with a new marker for each affected process. - This flag cannot be combined with a cutoff, activation selectors, or +- Use `--purge-all-logs` alone to delete every existing log, or combine it + with `--date` or `--retention-duration` to delete only older logs globally. + This flag cannot be combined with activation selectors or `--audit-trail=false`. Omitting both a cutoff and this flag raises a command error before deletion. - Use `--activation-ids 123 456`, `--activation-names name1 name2`, or both to @@ -524,10 +528,6 @@ Content-Type: application/json activation and processes without an activation. - Use `--audit-trail=true` or `--audit-trail=false`. A bare `--audit-trail` is invalid. -- Use `--log-delete-batch-size N` to set the maximum number of log rows - deleted per transaction. The default is 10,000 and the accepted range is - 1–50,000. This works for cutoff and full purges; process fetching stays at - 1,000 processes per page. - The optional `--internal-job-uuid` accepts a UUID or a custom ID of 1-128 ASCII letters, digits, periods, underscores, or hyphens, starting with a letter or digit. Valid UUIDs are normalized. The value appears in audit @@ -535,11 +535,9 @@ Content-Type: application/json **Deletion and audit markers** -- Deletion commits in batches. If a later batch fails, worker logs record the - count already deleted, and the job reports failure. Audit markers record the - partial count when audit is enabled. -- A larger log-delete batch size can reduce database round trips, while each - transaction holds more rows and a failed batch can roll back more work. +- Deletion runs once per process. If a later process fails, worker logs record + the count already deleted, and the job reports failure. Audit markers record + the count for each affected process when audit is enabled. - When audit is enabled, each process that loses log rows gets one marker with its count for this invocation. Markers use `Recorded at` for the time the audit row was written and store that time in `log_created_at`. The API diff --git a/src/aap_eda/api/serializers/activation.py b/src/aap_eda/api/serializers/activation.py index 5975764e0..024120494 100644 --- a/src/aap_eda/api/serializers/activation.py +++ b/src/aap_eda/api/serializers/activation.py @@ -55,11 +55,7 @@ get_resolved_secrets, get_secret_fields, ) -from aap_eda.core.utils.delete_log_util import ( - DEFAULT_LOG_DELETE_BATCH_SIZE, - MAX_LOG_DELETE_BATCH_SIZE, - resolve_activation_ids, -) +from aap_eda.core.utils.delete_log_util import resolve_activation_ids from aap_eda.core.utils.k8s_service_name import create_k8s_service_name from aap_eda.core.utils.log_retention import retention_cutoff from aap_eda.core.utils.rulebook import ( @@ -112,16 +108,6 @@ class LogPurgeRequestSerializer(serializers.Serializer): default=True, help_text="Write one audit marker per process that loses logs.", ) - log_delete_batch_size = serializers.IntegerField( - required=False, - min_value=1, - max_value=MAX_LOG_DELETE_BATCH_SIZE, - help_text=( - "Maximum log rows deleted per transaction " - f"(1-{MAX_LOG_DELETE_BATCH_SIZE:,}; " - f"default: {DEFAULT_LOG_DELETE_BATCH_SIZE:,})." - ), - ) activation_ids = serializers.ListField( child=serializers.IntegerField(min_value=1), required=False, @@ -142,21 +128,16 @@ def get_fields(self): required=False, default=False, help_text=( - "Delete all existing process logs and replace them with " - "audit markers. Cannot be combined with a cutoff or scope." + "Delete all existing process logs globally. Can be combined " + "with before_date or retention_duration to limit deletion " + "to older logs. Cannot be combined with activation selectors " + "or disabled audit." ), ) return fields @staticmethod def _validate_full_purge(attrs): - if ( - attrs.get("before_date") is not None - or attrs.get("retention_duration") is not None - ): - raise serializers.ValidationError( - "purge-all-logs cannot be combined with a cutoff." - ) if "activation_ids" in attrs or "activation_names" in attrs: raise serializers.ValidationError( "purge-all-logs cannot be combined with activation selectors." @@ -173,14 +154,19 @@ def validate(self, attrs): dict.fromkeys(sorted(unknown_fields), "Unknown field.") ) - if attrs["purge_all_logs"]: + purge_all_logs = attrs["purge_all_logs"] + if purge_all_logs: self._validate_full_purge(attrs) - return attrs before_date = attrs.get("before_date") duration = attrs.get("retention_duration") - if (before_date is None) == (duration is None): + both_cutoffs = before_date is not None and duration is not None + no_cutoff = ( + not purge_all_logs and before_date is None and duration is None + ) + if both_cutoffs or no_cutoff: raise serializers.ValidationError( - "Exactly one of before_date or retention_duration is required." + "Exactly one of before_date or retention_duration " + "is required." ) if before_date is not None: cutoff = datetime.combine( @@ -191,13 +177,15 @@ def validate(self, attrs): {"before_date": "The UTC cutoff must not be future."} ) attrs["before_date"] = before_date.isoformat() - else: + elif duration is not None: try: retention_cutoff(duration) except ValueError as exc: raise serializers.ValidationError( {"retention_duration": str(exc)} ) from exc + if purge_all_logs: + return attrs if "activation_ids" in attrs or "activation_names" in attrs: try: attrs["activation_ids"] = sorted( diff --git a/src/aap_eda/api/views/activation.py b/src/aap_eda/api/views/activation.py index 8ebeeedd6..5a2e89a27 100644 --- a/src/aap_eda/api/views/activation.py +++ b/src/aap_eda/api/views/activation.py @@ -882,17 +882,16 @@ class LogPurgeViewSet(viewsets.GenericViewSet): description=( "Queue deletion of process logs using one UTC cutoff: " "before_date (YYYY-MM-DD) or retention_duration (positive ISO " - "8601). Alternatively, purge-all-logs=true deletes every " - "existing log, including prior audit markers and logs without " - "a process, and leaves one new audit marker per affected " - "process. Logs without a process cannot receive a marker. " - "This mode cannot be combined with a cutoff, activation " - "selectors, or disabled audit. Without activation selectors, " - "all processes, including " - "orphaned ones, are included. Activation IDs and names limit " - "cutoff deletion to their union. The optional " - "log_delete_batch_size sets the maximum log rows deleted per " - "transaction (1-50,000; default 10,000). The returned job ID " + "8601). Alternatively, purge-all-logs=true deletes logs " + "globally. It can be combined with before_date or " + "retention_duration to delete only older logs, including prior " + "audit markers and logs without a process. It leaves one new " + "audit marker per affected process. Logs without a process " + "cannot receive a marker. This mode cannot be combined with " + "activation selectors or disabled audit. Without activation " + "selectors, all processes, including orphaned ones, are included. " + "Activation IDs and names limit " + "cutoff deletion to their union. The returned job ID " "acknowledges scheduling only." ), request=serializers.LogPurgeRequestSerializer, diff --git a/src/aap_eda/core/management/commands/purge_log_records.py b/src/aap_eda/core/management/commands/purge_log_records.py index 5901a4659..cb63a4006 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -24,8 +24,6 @@ ) from aap_eda.core.utils.delete_log_util import ( - DEFAULT_LOG_DELETE_BATCH_SIZE, - MAX_LOG_DELETE_BATCH_SIZE, LogPurgeError, delete_logs_older_than, purge_unattached_logs, @@ -38,8 +36,8 @@ class Command(BaseCommand): help = ( "Purge log records older than exactly one cutoff, or use " - "--purge-all-logs to delete every existing log and leave one audit " - "marker per affected process. Without activation " + "--purge-all-logs with an optional cutoff to delete logs globally " + "and leave one audit marker per affected process. Without activation " "selectors, include every process (including orphaned processes). " "Activation IDs and names limit deletion to their union. " "One audit marker per affected process is enabled by default." @@ -87,12 +85,12 @@ def add_arguments(self, parser: CommandParser) -> None: dest="purge-all-logs", action="store_true", help=( - "Delete all existing process logs at every timestamp, " - "including earlier audit markers, and leave one new audit " - "marker per affected process. Also delete logs without a " - "process, which cannot receive a marker. Cannot be combined " - "with a cutoff, activation selectors, or " - "--audit-trail=false." + "Delete all existing process logs. When used alone, deletes " + "every log at every timestamp. When combined with --date or " + "--retention-duration, deletes logs older than the cutoff " + "across all activations. Also deletes unattached logs " + "(filtered by cutoff when provided). Cannot be combined " + "with activation selectors or --audit-trail=false." ), ) parser.add_argument( @@ -103,18 +101,6 @@ def add_arguments(self, parser: CommandParser) -> None: metavar="true|false", help="Create a marker for each affected process (default: true).", ) - parser.add_argument( - "--log-delete-batch-size", - dest="log_delete_batch_size", - type=int, - default=DEFAULT_LOG_DELETE_BATCH_SIZE, - metavar="N", - help=( - "Delete at most N log rows per transaction " - f"(default: {DEFAULT_LOG_DELETE_BATCH_SIZE}; " - f"range: 1-{MAX_LOG_DELETE_BATCH_SIZE})." - ), - ) parser.add_argument( "--internal-job-uuid", dest="internal-job-uuid", @@ -169,17 +155,24 @@ def _purge_mode(self, options: dict) -> tuple[bool, datetime | None]: purge_all_logs = options.get("purge-all-logs", False) if not isinstance(purge_all_logs, bool): raise CommandError("--purge-all-logs must be a boolean flag.") - if purge_all_logs and ( + if purge_all_logs and (ids is not None or names is not None): + raise CommandError( + "--purge-all-logs cannot be combined with " + "activation selectors." + ) + has_cutoff = ( options.get("date") is not None or options.get("retention_duration") is not None - or ids is not None - or names is not None - ): + ) + if purge_all_logs and not has_cutoff: + cutoff = None + elif has_cutoff: + cutoff = self._cutoff(options) + else: raise CommandError( - "--purge-all-logs cannot be combined with a cutoff or " - "activation selectors." + "Exactly one of --date, --retention-duration, or " + "--purge-all-logs is required." ) - cutoff = None if purge_all_logs else self._cutoff(options) if cutoff is not None and cutoff > datetime.now(timezone.utc): raise CommandError("--date must not be in the future.") return purge_all_logs, cutoff @@ -197,10 +190,11 @@ def _validated_audit_trail(self, value, purge_all_logs: bool) -> bool: return value @staticmethod - def _delete_unattached_logs(deleted_count: int, batch_size: int) -> int: + def _delete_unattached_logs( + deleted_count: int, cutoff_timestamp: float | None + ) -> int: try: - for batch_deleted in purge_unattached_logs(batch_size): - deleted_count += batch_deleted + deleted_count += purge_unattached_logs(cutoff_timestamp) except Exception as exc: raise CommandError( f"Log purge failed after {deleted_count} committed rows: " @@ -208,24 +202,29 @@ def _delete_unattached_logs(deleted_count: int, batch_size: int) -> int: ) from exc return deleted_count + @staticmethod + def _validated_job_uuid(job_uuid): + if job_uuid is None: + return None + try: + return str(UUID(str(job_uuid))) + except (TypeError, ValueError, AttributeError) as exc: + if not isinstance(job_uuid, str) or not re.fullmatch( + r"[A-Za-z0-9][A-Za-z0-9._-]{0,127}", job_uuid + ): + raise CommandError( + "--internal-job-uuid must be a UUID or a custom ID " + "of 1-128 ASCII letters, digits, periods, " + "underscores, or hyphens, starting with a letter " + "or digit." + ) from exc + return job_uuid + def handle(self, *args, **options): ids = options.get("activation-ids") names = options.get("activation-names") purge_all_logs, cutoff = self._purge_mode(options) - job_uuid = options.get("internal-job-uuid") - if job_uuid is not None: - try: - job_uuid = str(UUID(str(job_uuid))) - except (TypeError, ValueError, AttributeError) as exc: - if not isinstance(job_uuid, str) or not re.fullmatch( - r"[A-Za-z0-9][A-Za-z0-9._-]{0,127}", job_uuid - ): - raise CommandError( - "--internal-job-uuid must be a UUID or a custom ID " - "of 1-128 ASCII letters, digits, periods, " - "underscores, or hyphens, starting with a letter " - "or digit." - ) from exc + job_uuid = self._validated_job_uuid(options.get("internal-job-uuid")) audit_trail = self._validated_audit_trail( options["audit_trail"], purge_all_logs ) @@ -238,20 +237,26 @@ def handle(self, *args, **options): audit_trail=audit_trail, internal_job_uuid=job_uuid, purge_all_logs=purge_all_logs, - log_delete_batch_size=options["log_delete_batch_size"], ) except (LogPurgeError, ValueError) as exc: raise CommandError(str(exc)) from exc if purge_all_logs: deleted_count = self._delete_unattached_logs( - process_deleted_count, options["log_delete_batch_size"] + process_deleted_count, + cutoff.timestamp() if cutoff is not None else None, ) marker_result = ( "Created audit markers for affected processes." if process_deleted_count else "No audit markers created." ) + if cutoff is not None: + cutoff_str = cutoff.strftime("%Y-%m-%d %H:%M:%S UTC") + return self.style.SUCCESS( + f"Purged {deleted_count} log records globally older " + f"than {cutoff_str}. {marker_result}" + ) return self.style.SUCCESS( f"Purged {deleted_count} log records globally at all " f"timestamps. {marker_result}" diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index 200d68689..5cb65ce43 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -16,15 +16,11 @@ from datetime import datetime, timezone from math import ceil -from django.db import transaction from django.db.models import Max from aap_eda.core import models PROCESS_PAGE_SIZE = 1000 -DEFAULT_LOG_DELETE_BATCH_SIZE = 10_000 -MAX_LOG_DELETE_BATCH_SIZE = 50_000 -POSTGRES_QUERY_PARAMETER_LIMIT = 65_535 def _utc_text(value: datetime) -> str: @@ -51,7 +47,6 @@ class _PurgeOptions: audit_trail: bool internal_job_uuid: str | None purge_all_logs: bool - log_delete_batch_size: int def resolve_activation_ids( @@ -100,23 +95,6 @@ def resolve_activation_ids( return existing_ids -def _logs_to_purge( - process_id: int, - cutoff_timestamp: float | None, - selected_ids: set[int] | None, - purge_all_logs: bool, -): - logs = models.RulebookProcessLog.objects.filter( - activation_instance_id=process_id - ) - if purge_all_logs: - return logs - logs = logs.filter(log_timestamp__lt=cutoff_timestamp) - if selected_ids is not None: - logs = logs.filter(activation_instance__activation_id__in=selected_ids) - return logs - - def _marker_text( cutoff: datetime | None, purge_time: datetime, @@ -142,18 +120,6 @@ def _marker_text( return f"{text} [{' | '.join(details)}]" -def _validate_log_delete_batch_size(log_delete_batch_size: int) -> None: - if ( - not isinstance(log_delete_batch_size, int) - or isinstance(log_delete_batch_size, bool) - or not 1 <= log_delete_batch_size <= MAX_LOG_DELETE_BATCH_SIZE - ): - raise ValueError( - "log_delete_batch_size must be an integer between 1 and " - f"{MAX_LOG_DELETE_BATCH_SIZE}." - ) - - def _validate_purge_options( cutoff: datetime | None, *, @@ -162,42 +128,27 @@ def _validate_purge_options( audit_trail: bool, internal_job_uuid: str | None, purge_all_logs: bool, - log_delete_batch_size: int, ) -> _PurgeOptions: - _validate_log_delete_batch_size(log_delete_batch_size) if not isinstance(purge_all_logs, bool): raise ValueError("purge_all_logs must be a boolean.") if purge_all_logs: - if cutoff is not None or any( + if any( selector is not None for selector in (activation_ids, activation_names) ): raise ValueError( - "--purge-all-logs cannot be combined with a cutoff or " + "--purge-all-logs cannot be combined with " "activation selectors." ) if not audit_trail: raise ValueError("--purge-all-logs requires audit trail.") selected_ids = None - cutoff_timestamp = None + cutoff_timestamp = cutoff.timestamp() if cutoff is not None else None else: if cutoff is None: raise ValueError("A cutoff is required unless purging all logs.") selected_ids = resolve_activation_ids(activation_ids, activation_names) cutoff_timestamp = cutoff.timestamp() - if selected_ids is not None: - # Scoped queries also bind each activation ID. Reserve four - # parameters for the process, cutoff, and keyset bounds. - available_log_parameters = ( - POSTGRES_QUERY_PARAMETER_LIMIT - len(selected_ids) - 4 - ) - if available_log_parameters < 1: - raise ValueError( - "Too many selected activations for a log purge query." - ) - log_delete_batch_size = min( - log_delete_batch_size, available_log_parameters - ) return _PurgeOptions( cutoff, cutoff_timestamp, @@ -205,7 +156,6 @@ def _validate_purge_options( audit_trail, internal_job_uuid, purge_all_logs, - log_delete_batch_size, ) @@ -213,7 +163,6 @@ def _write_audit_marker( process_id: int, activation_id: int | None, tracking_id: str | None, - marker_id: int | None, deleted_count: int, options: _PurgeOptions, ) -> int: @@ -232,99 +181,46 @@ def _write_audit_marker( activation_id is None, options.internal_job_uuid, ) - if marker_id is None: - marker = models.RulebookProcessLog.objects.create( - activation_instance_id=process_id, - log=marker_text, - log_timestamp=marker_timestamp, - log_created_at=purge_time, - ) - return marker.id - updated = models.RulebookProcessLog.objects.filter(pk=marker_id).update( + marker = models.RulebookProcessLog.objects.create( + activation_instance_id=process_id, log=marker_text, log_timestamp=marker_timestamp, log_created_at=purge_time, ) - if updated != 1: - raise RuntimeError("The current purge marker disappeared.") - return marker_id + return marker.id -def _purge_process_logs(process: tuple, options: _PurgeOptions): - """Yield each committed batch count so failures retain partial totals.""" +def _purge_process_logs(process: tuple, options: _PurgeOptions) -> int: process_id, activation_id, tracking_id = process - qualifying = _logs_to_purge( - process_id, - options.cutoff_timestamp, - options.selected_ids, - options.purge_all_logs, + logs = models.RulebookProcessLog.objects.filter( + activation_instance_id=process_id ) - highest_log_id = qualifying.aggregate(max_id=Max("id"))["max_id"] - if highest_log_id is None: - return - - last_log_id = 0 - process_deleted = 0 - marker_id = None - model_label = models.RulebookProcessLog._meta.label - while last_log_id < highest_log_id: - batch_ids = list( - qualifying.filter(id__gt=last_log_id, id__lte=highest_log_id) - .order_by("id") - .values_list("id", flat=True)[: options.log_delete_batch_size] + if options.cutoff_timestamp is not None: + logs = logs.filter(log_timestamp__lt=options.cutoff_timestamp) + if options.selected_ids is not None: + logs = logs.filter( + activation_instance__activation_id__in=options.selected_ids ) - if not batch_ids: - break - with transaction.atomic(): - _, per_model_counts = ( - _logs_to_purge( - process_id, - options.cutoff_timestamp, - options.selected_ids, - options.purge_all_logs, - ) - .filter(id__in=batch_ids) - .delete() - ) - batch_deleted = per_model_counts.get(model_label, 0) - if options.audit_trail and batch_deleted: - marker_id = _write_audit_marker( - process_id, - activation_id, - tracking_id, - marker_id, - process_deleted + batch_deleted, - options, - ) - process_deleted += batch_deleted - last_log_id = batch_ids[-1] - yield batch_deleted + deleted_count, _ = logs.delete() + if options.audit_trail and deleted_count: + _write_audit_marker( + process_id, + activation_id, + tracking_id, + deleted_count, + options, + ) + return deleted_count -def purge_unattached_logs(log_delete_batch_size: int): - """Yield deleted counts for bounded batches of logs without a process.""" - qualifying = models.RulebookProcessLog.objects.filter( +def purge_unattached_logs(cutoff_timestamp: float | None = None) -> int: + logs = models.RulebookProcessLog.objects.filter( activation_instance_id__isnull=True ) - highest_log_id = qualifying.aggregate(max_id=Max("id"))["max_id"] - if highest_log_id is None: - return - - last_log_id = 0 - model_label = models.RulebookProcessLog._meta.label - while last_log_id < highest_log_id: - batch_ids = list( - qualifying.filter(id__gt=last_log_id, id__lte=highest_log_id) - .order_by("id") - .values_list("id", flat=True)[:log_delete_batch_size] - ) - if not batch_ids: - break - with transaction.atomic(): - _, per_model_counts = qualifying.filter(id__in=batch_ids).delete() - batch_deleted = per_model_counts.get(model_label, 0) - last_log_id = batch_ids[-1] - yield batch_deleted + if cutoff_timestamp is not None: + logs = logs.filter(log_timestamp__lt=cutoff_timestamp) + deleted_count, _ = logs.delete() + return deleted_count def delete_logs_older_than( @@ -335,9 +231,8 @@ def delete_logs_older_than( audit_trail: bool = True, internal_job_uuid: str | None = None, purge_all_logs: bool = False, - log_delete_batch_size: int = DEFAULT_LOG_DELETE_BATCH_SIZE, ) -> int: - """Purge logs per process in committed, bounded ID batches.""" + """Purge qualifying logs one process at a time.""" options = _validate_purge_options( cutoff, activation_ids=activation_ids, @@ -345,7 +240,6 @@ def delete_logs_older_than( audit_trail=audit_trail, internal_job_uuid=internal_job_uuid, purge_all_logs=purge_all_logs, - log_delete_batch_size=log_delete_batch_size, ) processes = models.RulebookProcess.objects.all() if options.selected_ids is not None: @@ -370,8 +264,7 @@ def delete_logs_older_than( if not process_batch: break for process in process_batch: - for batch_deleted in _purge_process_logs(process, options): - deleted_count += batch_deleted + deleted_count += _purge_process_logs(process, options) last_process_id = process_batch[-1][0] except Exception as exc: raise LogPurgeError( diff --git a/src/aap_eda/tasks/management.py b/src/aap_eda/tasks/management.py index 372affeef..746b69987 100644 --- a/src/aap_eda/tasks/management.py +++ b/src/aap_eda/tasks/management.py @@ -39,7 +39,6 @@ def submit_log_purge( activation_ids: list[int] | None = None, activation_names: list[str] | None = None, purge_all_logs: bool = False, - log_delete_batch_size: int | None = None, ) -> str: """Submit a fixed-purpose log purge task.""" command_options = {"audit_trail": audit_trail} @@ -53,8 +52,6 @@ def submit_log_purge( command_options["activation-names"] = activation_names if purge_all_logs: command_options["purge-all-logs"] = True - if log_delete_batch_size is not None: - command_options["log_delete_batch_size"] = log_delete_batch_size return aap_eda_manage_commands( "purge_log_records", diff --git a/tests/integration/api/test_log_purge.py b/tests/integration/api/test_log_purge.py index 3be1efbff..8c6ec0466 100644 --- a/tests/integration/api/test_log_purge.py +++ b/tests/integration/api/test_log_purge.py @@ -132,25 +132,41 @@ def test_superuser_queues_purge_all_logs_without_cutoff(superuser_client): @pytest.mark.django_db -@pytest.mark.parametrize( - "payload, expected_size", - [ - ({"before_date": "2020-01-01", "log_delete_batch_size": 1}, 1), - ({"purge-all-logs": True, "log_delete_batch_size": 50_000}, 50_000), - ], -) -def test_api_forwards_log_delete_batch_size( - superuser_client, payload, expected_size +def test_superuser_queues_purge_all_logs_with_cutoff(superuser_client): + with mock.patch( + "aap_eda.tasks.management.submit_task", + return_value=({"uuid": str(JOB_ID)}, "default"), + ) as submit_task: + response = superuser_client.post( + PURGE_URL, + {"purge-all-logs": True, "before_date": "2020-01-01"}, + format="json", + ) + + assert response.status_code == status.HTTP_202_ACCEPTED + command_options = submit_task.call_args.kwargs["args"][2] + assert command_options["purge-all-logs"] is True + assert command_options["date"] == "2020-01-01" + + +@pytest.mark.django_db +def test_superuser_queues_purge_all_logs_with_retention_duration( + superuser_client, ): with mock.patch( "aap_eda.tasks.management.submit_task", return_value=({"uuid": str(JOB_ID)}, "default"), ) as submit_task: - response = superuser_client.post(PURGE_URL, payload, format="json") + response = superuser_client.post( + PURGE_URL, + {"purge-all-logs": True, "retention_duration": "P30D"}, + format="json", + ) assert response.status_code == status.HTTP_202_ACCEPTED command_options = submit_task.call_args.kwargs["args"][2] - assert command_options["log_delete_batch_size"] == expected_size + assert command_options["purge-all-logs"] is True + assert command_options["retention_duration"] == "P30D" @pytest.mark.django_db @@ -207,8 +223,13 @@ def test_anonymous_purge_uses_api_permission_denial(base_client): {"retention_duration": "-P1D"}, {"purge-all-logs": False}, {"purge_all_logs": True}, - {"purge-all-logs": True, "before_date": "2020-01-01"}, - {"purge-all-logs": True, "retention_duration": "P30D"}, + { + "purge-all-logs": True, + "before_date": "2020-01-01", + "retention_duration": "P30D", + }, + {"purge-all-logs": True, "before_date": "2999-01-01"}, + {"purge-all-logs": True, "retention_duration": "P0D"}, {"purge-all-logs": True, "audit_trail": False}, {"purge-all-logs": True, "activation_ids": [1]}, {"purge-all-logs": True, "activation_names": ["example"]}, @@ -221,13 +242,6 @@ def test_anonymous_purge_uses_api_permission_denial(base_client): {"before_date": "2020-01-01", "activation_id": "invalid"}, {"before_date": "2020-01-01", "activation_id": None}, {"before_date": "2020-01-01", "activation_namess": ["demo"]}, - {"before_date": "2020-01-01", "log_delete_batch_size": 0}, - {"before_date": "2020-01-01", "log_delete_batch_size": -1}, - {"before_date": "2020-01-01", "log_delete_batch_size": 50_001}, - {"before_date": "2020-01-01", "log_delete_batch_size": True}, - {"before_date": "2020-01-01", "log_delete_batch_size": 1.5}, - {"before_date": "2020-01-01", "log_delete_batch_size": "abc"}, - {"purge-all-logs": True, "log_delete_batch_size": 50_001}, { "before_date": "2020-01-01", "activation_names": ["missing-activation"], diff --git a/tests/integration/api/test_openapi.py b/tests/integration/api/test_openapi.py index 7a2718606..e86c74e0a 100644 --- a/tests/integration/api/test_openapi.py +++ b/tests/integration/api/test_openapi.py @@ -110,18 +110,11 @@ def test_log_purge_openapi_contract(admin_client): "before_date", "retention_duration", "audit_trail", - "log_delete_batch_size", "activation_ids", "activation_names", "purge-all-logs", } assert request_properties["audit_trail"]["default"] is True - assert request_properties["log_delete_batch_size"]["minimum"] == 1 - assert request_properties["log_delete_batch_size"]["maximum"] == 50_000 - assert ( - "default: 10,000" - in request_properties["log_delete_batch_size"]["description"] - ) assert request_properties["purge-all-logs"]["default"] is False assert "internal_job_uuid" not in request_properties diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index ae85499a6..a2f59d8e2 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -434,110 +434,6 @@ def test_purge_without_audit_trail_does_not_create_audit_logs( assert "Purged 4 log records" in capsys.readouterr().out -@pytest.mark.django_db -@pytest.mark.parametrize("batch_size", [0, -1, 50_001, True, "2", 1.5, None]) -def test_programmatic_batch_size_rejected_before_deletion( - default_activation_instance, batch_size -): - log = models.RulebookProcessLog.objects.create( - activation_instance=default_activation_instance, - log="must remain", - log_timestamp=1, - ) - - with pytest.raises(CommandError, match="log_delete_batch_size"): - call_command( - "purge_log_records", - date="2024-01-01", - log_delete_batch_size=batch_size, - ) - - assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() - - -@pytest.mark.django_db -@pytest.mark.parametrize("batch_size", [0, -1, 50_001, True, "2", 1.5, None]) -def test_utility_rejects_invalid_batch_size_before_deletion( - default_activation_instance, batch_size -): - log = models.RulebookProcessLog.objects.create( - activation_instance=default_activation_instance, - log="must remain", - log_timestamp=1, - ) - - cutoff = datetime(2024, 1, 1, tzinfo=datetime_timezone.utc) - with pytest.raises(ValueError, match="log_delete_batch_size"): - delete_log_util.delete_logs_older_than( - cutoff, - log_delete_batch_size=batch_size, - ) - - assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() - - -@pytest.mark.django_db -@pytest.mark.parametrize("batch_size", ["0", "50001", "not-an-integer"]) -def test_cli_rejects_invalid_batch_size_before_deletion( - default_activation_instance, batch_size -): - log = models.RulebookProcessLog.objects.create( - activation_instance=default_activation_instance, - log="must remain", - log_timestamp=1, - ) - - with pytest.raises(CommandError): - call_command( - "purge_log_records", - "--date", - "2024-01-01", - "--log-delete-batch-size", - batch_size, - ) - - assert models.RulebookProcessLog.objects.filter(pk=log.pk).exists() - - -@pytest.mark.django_db -def test_cli_batch_size_defaults_to_10000_and_accepts_50000(): - with mock.patch( - "aap_eda.core.management.commands.purge_log_records." - "delete_logs_older_than", - return_value=0, - ) as delete_logs: - call_command("purge_log_records", "--date", "2024-01-01") - assert delete_logs.call_args.kwargs["log_delete_batch_size"] == 10_000 - - call_command( - "purge_log_records", - "--date", - "2024-01-01", - "--log-delete-batch-size", - "50000", - ) - assert delete_logs.call_args.kwargs["log_delete_batch_size"] == 50_000 - - -def test_large_activation_scope_caps_effective_log_batch_size(): - with mock.patch.object( - delete_log_util, - "resolve_activation_ids", - return_value=set(range(20_000)), - ): - options = delete_log_util._validate_purge_options( - datetime(2024, 1, 1, tzinfo=datetime_timezone.utc), - activation_ids=[1], - activation_names=None, - audit_trail=True, - internal_job_uuid=None, - purge_all_logs=False, - log_delete_batch_size=50_000, - ) - - assert options.log_delete_batch_size == 45_531 - - @pytest.mark.django_db @pytest.mark.parametrize( "args", @@ -692,13 +588,13 @@ def test_retention_duration_deletes_strictly_older_rows_across_activations( @pytest.mark.django_db -def test_retention_batches_continue_after_more_than_one_batch( +def test_retention_deletes_qualifying_rows_in_one_call_per_process( default_activation_instance, monkeypatch ): logs = models.RulebookProcessLog.objects.bulk_create( [ models.RulebookProcessLog( - log=f"batch-{index}", + log=f"old-{index}", activation_instance=default_activation_instance, log_timestamp=1, ) @@ -706,25 +602,24 @@ def test_retention_batches_continue_after_more_than_one_batch( ] ) original_delete = QuerySet.delete - deleted_batch_sizes = [] + deleted_query_sizes = [] - def record_batch_size(queryset): - deleted_batch_sizes.append(queryset.count()) + def record_delete(queryset): + deleted_query_sizes.append(queryset.count()) return original_delete(queryset) - monkeypatch.setattr(QuerySet, "delete", record_batch_size) + monkeypatch.setattr(QuerySet, "delete", record_delete) assert ( delete_log_util.delete_logs_older_than( datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc), - log_delete_batch_size=2, ) == 5 ) assert not models.RulebookProcessLog.objects.filter( pk__in=[log.pk for log in logs] ).exists() - assert deleted_batch_sizes == [2, 2, 1] + assert deleted_query_sizes == [5] marker = _audit_markers().get() assert "Purged 5 log records older than" in marker.log assert marker.log_created_at is not None @@ -735,7 +630,7 @@ def record_batch_size(queryset): @pytest.mark.django_db -def test_retention_stops_at_initial_highest_qualifying_id( +def test_retention_does_not_revisit_process_after_deletion( default_activation_instance, monkeypatch ): models.RulebookProcessLog.objects.bulk_create( @@ -752,7 +647,7 @@ def test_retention_stops_at_initial_highest_qualifying_id( new_log = [] calls = 0 - def insert_after_first_batch(queryset): + def insert_after_delete(queryset): nonlocal calls result = original_delete(queryset) calls += 1 @@ -766,10 +661,9 @@ def insert_after_first_batch(queryset): ) return result - monkeypatch.setattr(QuerySet, "delete", insert_after_first_batch) + monkeypatch.setattr(QuerySet, "delete", insert_after_delete) deleted = delete_log_util.delete_logs_older_than( datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc), - log_delete_batch_size=1, ) assert deleted == 2 @@ -777,7 +671,7 @@ def insert_after_first_batch(queryset): @pytest.mark.django_db -def test_batch_delete_rechecks_cutoff_after_candidate_selection( +def test_delete_rechecks_cutoff_when_executed( default_activation_instance, monkeypatch ): log = models.RulebookProcessLog.objects.create( @@ -820,17 +714,17 @@ def test_retention_with_no_matching_rows_returns_zero( @pytest.mark.django_db(transaction=True) -def test_retention_failure_reports_committed_batch_count( - default_activation_instance, monkeypatch +def test_retention_failure_reports_committed_process_count( + default_activation_instances, monkeypatch ): models.RulebookProcessLog.objects.bulk_create( [ models.RulebookProcessLog( log=f"partial-{index}", - activation_instance=default_activation_instance, + activation_instance=process, log_timestamp=1, ) - for index in range(3) + for index, process in enumerate(default_activation_instances) ] ) original_delete = QuerySet.delete @@ -840,23 +734,23 @@ def fail_second_delete(queryset): nonlocal calls calls += 1 if calls == 2: - raise RuntimeError("injected batch failure") + raise RuntimeError("injected process failure") return original_delete(queryset) monkeypatch.setattr(QuerySet, "delete", fail_second_delete) cutoff = datetime(1970, 1, 1, 0, 0, 2, tzinfo=datetime_timezone.utc) with pytest.raises(delete_log_util.LogPurgeError) as error: - delete_log_util.delete_logs_older_than(cutoff, log_delete_batch_size=1) + delete_log_util.delete_logs_older_than(cutoff) assert error.value.deleted_count == 1 - assert models.RulebookProcessLog.objects.count() == 3 + assert models.RulebookProcessLog.objects.count() == 2 marker = _audit_markers().get() assert "Purged 1 log record older than" in marker.log assert ( models.RulebookProcessLog.objects.filter( log__startswith="partial-" ).count() - == 2 + == 1 ) @@ -1198,8 +1092,6 @@ def test_purge_all_logs_replaces_old_rows_and_markers_per_process( "--purge-all-logs", "--internal-job-uuid", str(job_id), - "--log-delete-batch-size", - "2", ) assert output.startswith("Purged 7 log records globally") @@ -1224,12 +1116,86 @@ def test_purge_all_logs_replaces_old_rows_and_markers_per_process( ) +@pytest.mark.django_db +def test_purge_all_logs_with_date_deletes_old_logs_globally( + default_activation_instances, +): + old_timestamp = datetime( + 2023, 1, 1, tzinfo=datetime_timezone.utc + ).timestamp() + recent_timestamp = datetime( + 2025, 1, 1, tzinfo=datetime_timezone.utc + ).timestamp() + old_logs = [] + recent_logs = [] + for process in default_activation_instances: + old_logs.append( + models.RulebookProcessLog.objects.create( + activation_instance=process, + log="old", + log_timestamp=old_timestamp, + ) + ) + recent_logs.append( + models.RulebookProcessLog.objects.create( + activation_instance=process, + log="recent", + log_timestamp=recent_timestamp, + ) + ) + + output = call_command( + "purge_log_records", "--purge-all-logs", "--date", "2024-01-01" + ) + + assert output.startswith( + "Purged 2 log records globally older than 2024-01-01" + ) + assert not models.RulebookProcessLog.objects.filter( + pk__in=[log.pk for log in old_logs] + ).exists() + assert ( + models.RulebookProcessLog.objects.filter( + pk__in=[log.pk for log in recent_logs] + ).count() + == 2 + ) + assert _audit_markers().count() == 2 + assert all( + "Purged 1 log record older than" in marker.log + for marker in _audit_markers() + ) + + +@pytest.mark.django_db +def test_purge_all_logs_with_retention_duration(default_activation_instances): + now = int(timezone.now().timestamp()) + for process in default_activation_instances: + models.RulebookProcessLog.objects.create( + activation_instance=process, + log="old", + log_timestamp=now - 7200, + ) + models.RulebookProcessLog.objects.create( + activation_instance=process, + log="recent", + log_timestamp=now, + ) + + output = call_command( + "purge_log_records", "--purge-all-logs", "--retention-duration", "PT1H" + ) + + assert output.startswith("Purged 2 log records globally older than") + assert not models.RulebookProcessLog.objects.filter(log="old").exists() + assert models.RulebookProcessLog.objects.filter(log="recent").count() == 2 + assert _audit_markers().count() == 2 + + @pytest.mark.django_db @pytest.mark.parametrize( "conflicting_options", [ - ("--date", "2024-01-01"), - ("--retention-duration", "P1D"), ("--activation-ids", "1"), ("--activation-names", "example"), ("--audit-trail=false",), @@ -1296,9 +1262,7 @@ def test_purge_all_logs_deletes_logs_without_process(): inserted_ids = [row[0] for row in cursor.fetchall()] assert len(inserted_ids) == 5 - output = call_command( - "purge_log_records", "--purge-all-logs", "--log-delete-batch-size", "2" - ) + output = call_command("purge_log_records", "--purge-all-logs") assert output.startswith("Purged 5 log records globally") assert "No audit markers created." in output @@ -1307,18 +1271,45 @@ def test_purge_all_logs_deletes_logs_without_process(): ).exists() +@pytest.mark.django_db +def test_purge_all_logs_with_cutoff_filters_unattached_logs(): + cutoff = datetime(2024, 1, 1, tzinfo=datetime_timezone.utc).timestamp() + with connection.cursor() as cursor: + cursor.execute( + "ALTER TABLE core_rulebook_process_log " + "ALTER COLUMN activation_instance_id DROP NOT NULL" + ) + cursor.execute( + "INSERT INTO core_rulebook_process_log " + "(activation_instance_id, log, log_timestamp) " + "VALUES (NULL, 'old unattached', %s), " + "(NULL, 'recent unattached', %s) RETURNING id", + [cutoff - 1, cutoff + 1], + ) + old_id, recent_id = [row[0] for row in cursor.fetchall()] + + output = call_command( + "purge_log_records", "--purge-all-logs", "--date", "2024-01-01" + ) + + assert output.startswith("Purged 1 log records globally older than") + assert not models.RulebookProcessLog.objects.filter(pk=old_id).exists() + assert models.RulebookProcessLog.objects.filter(pk=recent_id).exists() + assert not _audit_markers().exists() + + @pytest.mark.django_db(transaction=True) def test_purge_all_logs_failure_keeps_committed_marker_count( - default_activation_instance, monkeypatch + default_activation_instances, monkeypatch ): models.RulebookProcessLog.objects.bulk_create( [ models.RulebookProcessLog( - activation_instance=default_activation_instance, + activation_instance=process, log=f"old-{index}", log_timestamp=1, ) - for index in range(2) + for index, process in enumerate(default_activation_instances) ] ) original_delete = QuerySet.delete @@ -1328,17 +1319,12 @@ def fail_second_delete(queryset): nonlocal calls calls += 1 if calls == 2: - raise RuntimeError("injected batch failure") + raise RuntimeError("injected process failure") return original_delete(queryset) monkeypatch.setattr(QuerySet, "delete", fail_second_delete) with pytest.raises(CommandError, match="failed after 1 committed rows"): - call_command( - "purge_log_records", - "--purge-all-logs", - "--log-delete-batch-size", - "1", - ) + call_command("purge_log_records", "--purge-all-logs") assert ( models.RulebookProcessLog.objects.filter( From b49a7bfbf77dc4bae669c5887b516cc02d50cd6a Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Tue, 27 Oct 2026 13:52:14 -0400 Subject: [PATCH 13/15] refactor(logs): address PR #1717 review feedback --- docs/development.md | 5 +- src/aap_eda/api/serializers/activation.py | 103 +++++++++++------- .../management/commands/purge_log_records.py | 28 +++-- src/aap_eda/core/utils/delete_log_util.py | 8 ++ src/aap_eda/tasks/management.py | 5 +- .../commands/test_purge_log_records.py | 31 +++++- tests/integration/tasks/test_management.py | 2 - 7 files changed, 117 insertions(+), 65 deletions(-) diff --git a/docs/development.md b/docs/development.md index 77dc90fd9..403550b78 100644 --- a/docs/development.md +++ b/docs/development.md @@ -527,7 +527,7 @@ Content-Type: application/json limit deletion to the selected activations. Omit both to include every activation and processes without an activation. - Use `--audit-trail=true` or `--audit-trail=false`. A bare `--audit-trail` is - invalid. + invalid. Default is True. - The optional `--internal-job-uuid` accepts a UUID or a custom ID of 1-128 ASCII letters, digits, periods, underscores, or hyphens, starting with a letter or digit. Valid UUIDs are normalized. The value appears in audit @@ -558,9 +558,6 @@ kubectl logs -n "${NAMESPACE:-aap-eda}" \ | grep "job_id=${JOB_ID}" ``` -- The dispatcherd `running` view reports only in-flight work. Structured - worker log lines are the completion and deletion-count record. - ### Running linters The project uses `flake8` with a set of plugins, `black`, `isort` and `ruff` (experimental), diff --git a/src/aap_eda/api/serializers/activation.py b/src/aap_eda/api/serializers/activation.py index 024120494..c710e19aa 100644 --- a/src/aap_eda/api/serializers/activation.py +++ b/src/aap_eda/api/serializers/activation.py @@ -93,7 +93,7 @@ def _update_event_stream_source(validated_data: dict) -> str: class LogPurgeRequestSerializer(serializers.Serializer): - """Validate the cutoff or full purge before scheduling a job.""" + """Serializer for the asynchronous log purge endpoint.""" before_date = serializers.DateField( required=False, @@ -138,6 +138,7 @@ def get_fields(self): @staticmethod def _validate_full_purge(attrs): + """Reject selector or audit-off combinations with purge-all-logs.""" if "activation_ids" in attrs or "activation_names" in attrs: raise serializers.ValidationError( "purge-all-logs cannot be combined with activation selectors." @@ -147,6 +148,61 @@ def _validate_full_purge(attrs): "purge-all-logs requires audit_trail=true." ) + def _validate_cutoff(self, attrs): + """Ensure exactly one cutoff is supplied and normalize it.""" + before_date = attrs.get("before_date") + duration = attrs.get("retention_duration") + has_date = before_date is not None + has_duration = duration is not None + err = "Exactly one of before_date or retention_duration is required." + + if has_date and has_duration: + raise serializers.ValidationError(err) + if not has_date and not has_duration and not attrs["purge_all_logs"]: + raise serializers.ValidationError(err) + if has_date: + self._validate_before_date(attrs, before_date) + elif has_duration: + self._validate_duration(duration) + + @staticmethod + def _validate_before_date(attrs, before_date): + """Reject future dates and normalise before_date to ISO string.""" + cutoff = datetime.combine( + before_date, time.min, tzinfo=datetime_timezone.utc + ) + if cutoff > datetime.now(datetime_timezone.utc): + raise serializers.ValidationError( + {"before_date": "The UTC cutoff must not be future."} + ) + attrs["before_date"] = before_date.isoformat() + + @staticmethod + def _validate_duration(duration): + """Validate retention_duration as a positive ISO 8601 duration.""" + try: + retention_cutoff(duration) + except ValueError as exc: + raise serializers.ValidationError( + {"retention_duration": str(exc)} + ) from exc + + @staticmethod + def _resolve_activations(attrs): + """Resolve activation names to IDs.""" + if "activation_ids" not in attrs and "activation_names" not in attrs: + return + try: + attrs["activation_ids"] = sorted( + resolve_activation_ids( + attrs.get("activation_ids"), + attrs.get("activation_names"), + ) + ) + except ValueError as exc: + raise serializers.ValidationError(str(exc)) from exc + attrs.pop("activation_names", None) + def validate(self, attrs): unknown_fields = set(self.initial_data) - set(self.fields) if unknown_fields: @@ -154,49 +210,12 @@ def validate(self, attrs): dict.fromkeys(sorted(unknown_fields), "Unknown field.") ) - purge_all_logs = attrs["purge_all_logs"] - if purge_all_logs: + if attrs["purge_all_logs"]: self._validate_full_purge(attrs) - before_date = attrs.get("before_date") - duration = attrs.get("retention_duration") - both_cutoffs = before_date is not None and duration is not None - no_cutoff = ( - not purge_all_logs and before_date is None and duration is None - ) - if both_cutoffs or no_cutoff: - raise serializers.ValidationError( - "Exactly one of before_date or retention_duration " - "is required." - ) - if before_date is not None: - cutoff = datetime.combine( - before_date, time.min, tzinfo=datetime_timezone.utc - ) - if cutoff > datetime.now(datetime_timezone.utc): - raise serializers.ValidationError( - {"before_date": "The UTC cutoff must not be future."} - ) - attrs["before_date"] = before_date.isoformat() - elif duration is not None: - try: - retention_cutoff(duration) - except ValueError as exc: - raise serializers.ValidationError( - {"retention_duration": str(exc)} - ) from exc - if purge_all_logs: + self._validate_cutoff(attrs) + if attrs["purge_all_logs"]: return attrs - if "activation_ids" in attrs or "activation_names" in attrs: - try: - attrs["activation_ids"] = sorted( - resolve_activation_ids( - attrs.get("activation_ids"), - attrs.get("activation_names"), - ) - ) - except ValueError as exc: - raise serializers.ValidationError(str(exc)) from exc - attrs.pop("activation_names", None) + self._resolve_activations(attrs) return attrs diff --git a/src/aap_eda/core/management/commands/purge_log_records.py b/src/aap_eda/core/management/commands/purge_log_records.py index cb63a4006..187ec2e46 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -113,6 +113,7 @@ def add_arguments(self, parser: CommandParser) -> None: @staticmethod def _audit_trail_value(value: str) -> bool: + """Parse audit-trail CLI flag to boolean.""" if value == "true": return True if value == "false": @@ -121,6 +122,7 @@ def _audit_trail_value(value: str) -> bool: @staticmethod def _cutoff(options: dict) -> datetime: + """Parse and validate cutoff date from CLI options.""" cutoff_date = options.get("date") retention_duration = options.get("retention_duration") if cutoff_date is not None and retention_duration is not None: @@ -150,6 +152,7 @@ def _cutoff(options: dict) -> datetime: ) def _purge_mode(self, options: dict) -> tuple[bool, datetime | None]: + """Resolve and validate the purge scope and cutoff from CLI options.""" ids = options.get("activation-ids") names = options.get("activation-names") purge_all_logs = options.get("purge-all-logs", False) @@ -178,6 +181,7 @@ def _purge_mode(self, options: dict) -> tuple[bool, datetime | None]: return purge_all_logs, cutoff def _validated_audit_trail(self, value, purge_all_logs: bool) -> bool: + """Coerce and validate the audit-trail flag.""" if isinstance(value, str): try: value = self._audit_trail_value(value) @@ -193,17 +197,20 @@ def _validated_audit_trail(self, value, purge_all_logs: bool) -> bool: def _delete_unattached_logs( deleted_count: int, cutoff_timestamp: float | None ) -> int: + """Delete logs not linked to any activation instance.""" try: deleted_count += purge_unattached_logs(cutoff_timestamp) except Exception as exc: - raise CommandError( + raise LogPurgeError( f"Log purge failed after {deleted_count} committed rows: " - f"{exc}" + f"{exc}", + deleted_count=deleted_count, ) from exc return deleted_count @staticmethod def _validated_job_uuid(job_uuid): + """Normalise a UUID or validate a custom job ID string.""" if job_uuid is None: return None try: @@ -238,36 +245,39 @@ def handle(self, *args, **options): internal_job_uuid=job_uuid, purge_all_logs=purge_all_logs, ) + if purge_all_logs: + deleted_count = self._delete_unattached_logs( + process_deleted_count, + cutoff.timestamp() if cutoff is not None else None, + ) except (LogPurgeError, ValueError) as exc: raise CommandError(str(exc)) from exc if purge_all_logs: - deleted_count = self._delete_unattached_logs( - process_deleted_count, - cutoff.timestamp() if cutoff is not None else None, - ) marker_result = ( "Created audit markers for affected processes." if process_deleted_count else "No audit markers created." ) + noun = "record" if deleted_count == 1 else "records" if cutoff is not None: cutoff_str = cutoff.strftime("%Y-%m-%d %H:%M:%S UTC") return self.style.SUCCESS( - f"Purged {deleted_count} log records globally older " + f"Purged {deleted_count} log {noun} globally older " f"than {cutoff_str}. {marker_result}" ) return self.style.SUCCESS( - f"Purged {deleted_count} log records globally at all " + f"Purged {deleted_count} log {noun} globally at all " f"timestamps. {marker_result}" ) + noun = "record" if process_deleted_count == 1 else "records" scope = ( "globally" if ids is None and names is None else "for selected activations" ) return self.style.SUCCESS( - f"Purged {process_deleted_count} log records older than " + f"Purged {process_deleted_count} log {noun} older than " f"{cutoff.strftime('%Y-%m-%d %H:%M:%S UTC')} {scope}." ) diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index 5cb65ce43..049be3d6c 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -24,6 +24,7 @@ def _utc_text(value: datetime) -> str: + """Format datetime as UTC string with optional microseconds.""" value = value.astimezone(timezone.utc) time_format = "%Y-%m-%d %H:%M:%S" if value.microsecond: @@ -41,6 +42,8 @@ def __init__(self, message: str, deleted_count: int): @dataclass(frozen=True) class _PurgeOptions: + """Validated purge operation parameters.""" + cutoff: datetime | None cutoff_timestamp: float | None selected_ids: set[int] | None @@ -103,6 +106,7 @@ def _marker_text( orphaned: bool, internal_job_uuid: str | None, ) -> str: + """Format audit marker text with purge metadata.""" details = [f"Recorded at: {_utc_text(purge_time)}"] noun = "record" if count == 1 else "records" if cutoff is None: @@ -129,6 +133,7 @@ def _validate_purge_options( internal_job_uuid: str | None, purge_all_logs: bool, ) -> _PurgeOptions: + """Validate purge parameters and return configuration object.""" if not isinstance(purge_all_logs, bool): raise ValueError("purge_all_logs must be a boolean.") if purge_all_logs: @@ -166,6 +171,7 @@ def _write_audit_marker( deleted_count: int, options: _PurgeOptions, ) -> int: + """Create audit marker log record for a purge operation.""" purge_time = datetime.now(timezone.utc) marker_timestamp = max( ceil(purge_time.timestamp()), @@ -191,6 +197,7 @@ def _write_audit_marker( def _purge_process_logs(process: tuple, options: _PurgeOptions) -> int: + """Delete logs for one process matching purge criteria.""" process_id, activation_id, tracking_id = process logs = models.RulebookProcessLog.objects.filter( activation_instance_id=process_id @@ -214,6 +221,7 @@ def _purge_process_logs(process: tuple, options: _PurgeOptions) -> int: def purge_unattached_logs(cutoff_timestamp: float | None = None) -> int: + """Delete logs not linked to any activation instance.""" logs = models.RulebookProcessLog.objects.filter( activation_instance_id__isnull=True ) diff --git a/src/aap_eda/tasks/management.py b/src/aap_eda/tasks/management.py index 746b69987..1c54c3451 100644 --- a/src/aap_eda/tasks/management.py +++ b/src/aap_eda/tasks/management.py @@ -28,7 +28,7 @@ MANAGEMENT_TASKS_QUEUE = "default" LOG_PURGE_TASK_TIMEOUT_SECONDS = 3600 -_DELETED_COUNT = re.compile(r"^Purged (\d+) log records") +_DELETED_COUNT = re.compile(r"^Purged (\d+) log records?") def submit_log_purge( @@ -37,7 +37,6 @@ def submit_log_purge( retention_duration: str | None = None, audit_trail: bool = True, activation_ids: list[int] | None = None, - activation_names: list[str] | None = None, purge_all_logs: bool = False, ) -> str: """Submit a fixed-purpose log purge task.""" @@ -48,8 +47,6 @@ def submit_log_purge( command_options["retention_duration"] = retention_duration if activation_ids is not None: command_options["activation-ids"] = activation_ids - if activation_names is not None: - command_options["activation-names"] = activation_names if purge_all_logs: command_options["purge-all-logs"] = True diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index a2f59d8e2..a1e679fd3 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -785,7 +785,7 @@ def test_retention_duration_cli_uses_execution_time_cutoff( "purge_log_records", "--retention-duration", "P1D" ) - assert output.startswith("Purged 1 log records") + assert output.startswith("Purged 1 log record") assert not models.RulebookProcessLog.objects.filter(pk=logs[0].pk).exists() assert ( models.RulebookProcessLog.objects.filter( @@ -927,7 +927,7 @@ def test_cli_valid_internal_uuid_is_in_default_audit_marker( str(job_id).upper(), ) - assert output.startswith("Purged 1 log records") + assert output.startswith("Purged 1 log record") marker = _audit_markers().get() assert f"Purge Job ID: {job_id}" in marker.log assert "Purged 1 log record older than" in marker.log @@ -952,7 +952,7 @@ def test_cli_custom_internal_job_id_is_in_audit_marker( "Freds-Troubleshootin-Logs", ) - assert output.startswith("Purged 1 log records") + assert output.startswith("Purged 1 log record") marker = _audit_markers().get() assert "Purge Job ID: Freds-Troubleshootin-Logs" in marker.log @@ -1292,7 +1292,7 @@ def test_purge_all_logs_with_cutoff_filters_unattached_logs(): "purge_log_records", "--purge-all-logs", "--date", "2024-01-01" ) - assert output.startswith("Purged 1 log records globally older than") + assert output.startswith("Purged 1 log record globally older than") assert not models.RulebookProcessLog.objects.filter(pk=old_id).exists() assert models.RulebookProcessLog.objects.filter(pk=recent_id).exists() assert not _audit_markers().exists() @@ -1334,3 +1334,26 @@ def fail_second_delete(queryset): ) marker = _audit_markers().get() assert "Purged 1 log record globally." in marker.log + + +@pytest.mark.django_db(transaction=True) +def test_purge_all_unattached_failure_raises_command_error_with_count( + default_activation_instance, monkeypatch +): + """LogPurgeError from purge_unattached_logs propagates deleted_count.""" + models.RulebookProcessLog.objects.create( + activation_instance=default_activation_instance, + log="old-log", + log_timestamp=1, + ) + + from aap_eda.core.management.commands import purge_log_records as cmd_mod + + monkeypatch.setattr( + cmd_mod, + "purge_unattached_logs", + mock.Mock(side_effect=RuntimeError("disk full")), + ) + + with pytest.raises(CommandError, match="failed after 1 committed rows"): + call_command("purge_log_records", "--purge-all-logs") diff --git a/tests/integration/tasks/test_management.py b/tests/integration/tasks/test_management.py index 26edc4ac6..e7a2479e2 100644 --- a/tests/integration/tasks/test_management.py +++ b/tests/integration/tasks/test_management.py @@ -72,14 +72,12 @@ def test_submit_log_purge_forwards_scope_when_audit_is_disabled(): before_date="2020-01-01", audit_trail=False, activation_ids=[9], - activation_names=["production"], ) assert submit_task.call_args.kwargs["args"][2] == { "date": "2020-01-01", "audit_trail": False, "activation-ids": [9], - "activation-names": ["production"], "internal-job-uuid": job_id, } From d83f5bf3b4edaa4f5c1131da97e714cd48b0e186 Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Wed, 28 Oct 2026 16:00:04 -0400 Subject: [PATCH 14/15] fix(logs): wrap purge delete and audit marker in transaction Catch case where audit marker creation failed. Wrapped operations in transaction.atomic() to ensure a clean roll back, keeping the audit trail count accurate. Assisted by: Claude --- src/aap_eda/core/utils/delete_log_util.py | 20 ++++---- .../commands/test_purge_log_records.py | 47 +++++++++++++++++++ 2 files changed, 58 insertions(+), 9 deletions(-) diff --git a/src/aap_eda/core/utils/delete_log_util.py b/src/aap_eda/core/utils/delete_log_util.py index 049be3d6c..1828b8db7 100644 --- a/src/aap_eda/core/utils/delete_log_util.py +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -16,6 +16,7 @@ from datetime import datetime, timezone from math import ceil +from django.db import transaction from django.db.models import Max from aap_eda.core import models @@ -208,15 +209,16 @@ def _purge_process_logs(process: tuple, options: _PurgeOptions) -> int: logs = logs.filter( activation_instance__activation_id__in=options.selected_ids ) - deleted_count, _ = logs.delete() - if options.audit_trail and deleted_count: - _write_audit_marker( - process_id, - activation_id, - tracking_id, - deleted_count, - options, - ) + with transaction.atomic(): + deleted_count, _ = logs.delete() + if options.audit_trail and deleted_count: + _write_audit_marker( + process_id, + activation_id, + tracking_id, + deleted_count, + options, + ) return deleted_count diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index a1e679fd3..84097b7bf 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -1336,6 +1336,53 @@ def fail_second_delete(queryset): assert "Purged 1 log record globally." in marker.log +@pytest.mark.django_db(transaction=True) +def test_marker_failure_rolls_back_process_deletion( + default_activation_instances, monkeypatch +): + """If audit marker creation fails, that process's log deletion + rolls back and the error reports only prior committed rows.""" + models.RulebookProcessLog.objects.bulk_create( + [ + models.RulebookProcessLog( + activation_instance=process, + log=f"old-{index}", + log_timestamp=1, + ) + for index, process in enumerate(default_activation_instances) + ] + ) + original_create = models.RulebookProcessLog.objects.create + calls = {"marker": 0} + + def fail_second_marker(**kwargs): + if kwargs.get("log", "").startswith("Purged "): + calls["marker"] += 1 + if calls["marker"] == 2: + raise RuntimeError("injected marker failure") + return original_create(**kwargs) + + monkeypatch.setattr( + models.RulebookProcessLog.objects, + "create", + fail_second_marker, + ) + with pytest.raises(CommandError, match="failed after 1 committed rows"): + call_command("purge_log_records", "--purge-all-logs") + + assert ( + models.RulebookProcessLog.objects.filter( + log__startswith="old-" + ).count() + == 1 + ) + markers = models.RulebookProcessLog.objects.filter( + log__startswith="Purged " + ) + assert markers.count() == 1 + assert "Purged 1 log record globally." in markers.get().log + + @pytest.mark.django_db(transaction=True) def test_purge_all_unattached_failure_raises_command_error_with_count( default_activation_instance, monkeypatch From 6e0dc7f421483c8a475bea775399a8ec009e4d87 Mon Sep 17 00:00:00 2001 From: B-Whitt <34513926+B-Whitt@users.noreply.github.com> Date: Wed, 28 Oct 2026 16:28:27 -0400 Subject: [PATCH 15/15] Update poetry.lock --- poetry.lock | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/poetry.lock b/poetry.lock index 1a115d379..d72c53aae 100644 --- a/poetry.lock +++ b/poetry.lock @@ -1,4 +1,4 @@ -# This file is automatically @generated by Poetry 2.4.1 and should not be changed by hand. +# This file is automatically @generated by Poetry 2.3.4 and should not be changed by hand. [[package]] name = "adal" @@ -3648,4 +3648,4 @@ dev = ["psycopg-binary"] [metadata] lock-version = "2.1" python-versions = ">=3.12,<3.13" -content-hash = "9681770ca45339d4af6cdc82588f70fec852a8b305c0d034056d8a767bc12560" +content-hash = "471e617d209875a3d38ef5868a94eec8c6e44696d1d9876d1a247119d36d3214"