diff --git a/docs/development.md b/docs/development.md index 852e19f3a..59334dbe3 100644 --- a/docs/development.md +++ b/docs/development.md @@ -457,10 +457,34 @@ task docker:purge && EDA_SECRET_KEY=insecure task docker:up |----------|---------| | `EDA_SECRET_KEY` | Sets `settings.SECRET_KEY` via dynaconf. Used by Django for encryption at rest. | | `EDA_DB_ROTATION_KEY` | Provides the new key for `rotate_db_encryption_key --use-custom-key`. Operator-set, ad-hoc only. | +| `EDA_LOG_RETENTION_DAYS` | Days of rulebook process logs to retain. An automated task purges older logs every hour. Default: `30`. Set to `0` to disable. | +| `EDA_MAX_LOG_LINES_PER_INSTANCE` | Maximum log lines stored per activation instance. Oldest lines are trimmed when exceeded. Default: `500000`. Set to `0` to disable. | Do **not** confuse the two — see the command docstring in `src/aap_eda/core/management/commands/rotate_db_encryption_key.py`. +### Log retention + +Rulebook process logs are automatically purged every hour based on `EDA_LOG_RETENTION_DAYS`. +A per-instance safety valve (`EDA_MAX_LOG_LINES_PER_INSTANCE`) trims the oldest log lines +when an individual activation instance exceeds the cap. + +For ad-hoc purging, use the management command: + +```shell +# Purge logs older than LOG_RETENTION_DAYS (default 30) +task manage -- purge_log_records + +# Purge logs older than a specific date +task manage -- purge_log_records --date 2024-06-01 + +# Include audit trail entries recording the purge +task manage -- purge_log_records --date 2024-06-01 --audit-trail + +# Scope the audit trail to specific activations +task manage -- purge_log_records --date 2024-06-01 --audit-trail --activation-ids 1 2 3 +``` + ### Running linters The project uses `flake8` with a set of plugins, `black`, `isort` and `ruff` (experimental), diff --git a/src/aap_eda/api/pagination.py b/src/aap_eda/api/pagination.py index 32713159e..704b04e10 100644 --- a/src/aap_eda/api/pagination.py +++ b/src/aap_eda/api/pagination.py @@ -20,6 +20,12 @@ class DefaultPagination(pagination.PageNumberPagination): page_size_query_param = "page_size" + +class LogPagination(DefaultPagination): + """Pagination for log endpoints, capped at 1000 results per page.""" + + max_page_size = 1000 + def get_next_link(self): if not self.page.has_next(): return None diff --git a/src/aap_eda/api/views/activation.py b/src/aap_eda/api/views/activation.py index 357f7580e..7bcc60104 100644 --- a/src/aap_eda/api/views/activation.py +++ b/src/aap_eda/api/views/activation.py @@ -31,6 +31,7 @@ from rest_framework.response import Response from aap_eda.api import exceptions as api_exc, filters, serializers +from aap_eda.api.pagination import LogPagination 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 @@ -815,7 +816,10 @@ def filter_queryset(self, queryset): return super().filter_queryset(queryset) @extend_schema( - description="List Activation instance logs", + description=( + "List Activation instance logs. " + "Results are paginated with a maximum page_size of 1000." + ), request=None, responses={ status.HTTP_200_OK: serializers.ActivationInstanceLogSerializer( @@ -828,13 +832,20 @@ def filter_queryset(self, queryset): type=int, location=OpenApiParameter.PATH, description="A unique integer value identifying this Activation Instance.", # noqa: E501 - ) + ), + OpenApiParameter( + name="page_size", + type=int, + location=OpenApiParameter.QUERY, + description="Number of results per page (default: 20, max: 1000).", # noqa: E501 + ), ], extensions={ "x-ai-description": ( "List logs for an activation instance by ID. " "Returns log records with timestamps and levels. " - "Supports filtering and pagination." + "Supports filtering and pagination. " + "Maximum page_size is 1000." ) }, ) @@ -846,6 +857,7 @@ def filter_queryset(self, queryset): url_path="(?P[^/.]+)/logs", ) def logs(self, request, id): + self.pagination_class = LogPagination instance_exists = ( models.RulebookProcess.access_qs(request.user) .filter(pk=id) 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 1ff898cb9..88eb4c6be 100644 --- a/src/aap_eda/core/management/commands/purge_log_records.py +++ b/src/aap_eda/core/management/commands/purge_log_records.py @@ -12,17 +12,21 @@ # See the License for the specific language governing permissions and # limitations under the License. -from datetime import datetime +from datetime import datetime, timedelta +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 django.utils import timezone -from aap_eda.core import models +from aap_eda.core.utils.delete_log_util import ( + create_audit_trail, + delete_logs_older_than, +) class Command(BaseCommand): @@ -30,9 +34,9 @@ class Command(BaseCommand): help = ( "Purge log records from rulebook processes. " - "Always purges ALL log records older than the cutoff date globally. " - "If activation ids or names are specified, detailed reporting is " - "provided for those activations and orphaned records." + "Uses --date for a specific cutoff or defaults to " + "LOG_RETENTION_DAYS. Use --audit-trail to record " + "the purge in activation logs." ) def add_arguments(self, parser: CommandParser) -> None: @@ -42,8 +46,8 @@ def add_arguments(self, parser: CommandParser) -> None: type=int, dest="activation-ids", help=( - "Specify the activation ids which you want to clear their " - "records (e.g., ActivationID1 ActivationID2)" + "Scope audit trail to these activation ids " + "(e.g., 1 2 3). Only used with --audit-trail." ), ) parser.add_argument( @@ -52,108 +56,67 @@ def add_arguments(self, parser: CommandParser) -> None: type=str, dest="activation-names", help=( - "Specify the activation names which you want to clear their " - "records (e.g., ActivationName1 ActivationName2)" + "Scope audit trail to these activation names " + "(e.g., name1 name2). Only used with --audit-trail." ), ) parser.add_argument( "--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" + "Purge records older than this date (YYYY-MM-DD). " + "Defaults to LOG_RETENTION_DAYS if omitted." ), ) - - 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( + "--audit-trail", + dest="audit_trail", + action="store_true", + default=False, + help="Create audit trail log entries recording the purge.", ) - deleted_count = old_logs.count() - if deleted_count == 0: + @transaction.atomic + def handle(self, *args, **options): + cutoff_date = options.get("date") + + if cutoff_date: + try: + cutoff = datetime.strptime(cutoff_date, "%Y-%m-%d") + except ValueError as e: + raise CommandError(f"{e}") from e + else: + retention_days = settings.LOG_RETENTION_DAYS + if retention_days <= 0: + self.stdout.write("LOG_RETENTION_DAYS is 0; nothing to purge.") + return + cutoff = timezone.now() - timedelta(days=retention_days) + + deleted = delete_logs_older_than(cutoff) + + if deleted == 0: self.stdout.write( self.style.SUCCESS( f"No log records found older than " - f"{cutoff_timestamp.strftime('%Y-%m-%d')}." + f"{cutoff.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." + f"Purged {deleted} log records older than " + f"{cutoff.strftime('%Y-%m-%d')} globally." ) ) - # 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, - ) - ) - - if audit_logs: - models.RulebookProcessLog.objects.bulk_create(audit_logs) - self.stdout.write( - f"Created {len(audit_logs)} audit trail log entries." + if options.get("audit_trail"): + ids = options.get("activation-ids") or [] + names = options.get("activation-names") or [] + count = create_audit_trail( + cutoff, + activation_ids=ids, + activation_names=names, ) - - @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") - - try: - ts = datetime.strptime(cutoff_date, "%Y-%m-%d") - except ValueError as e: - raise CommandError(f"{e}") from e - - self.purge_log_records( - ids=input_ids, names=input_names, cutoff_timestamp=ts - ) + self.stdout.write(f"Created {count} audit trail log entries.") 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..7b1bab8de --- /dev/null +++ b/src/aap_eda/core/utils/delete_log_util.py @@ -0,0 +1,79 @@ +# Copyright 2025 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.models import Q +from django.utils import timezone + +from aap_eda.core import models + + +def delete_logs_older_than(cutoff: datetime) -> int: + """Delete all RulebookProcessLog records older than the cutoff. + + Returns the number of records deleted. + """ + cutoff_ts = int(cutoff.timestamp()) + deleted, _ = models.RulebookProcessLog.objects.filter( + log_timestamp__lt=cutoff_ts, + ).delete() + return deleted + + +def create_audit_trail( + cutoff: datetime, + activation_ids: list[int] | None = None, + activation_names: list[str] | None = None, +) -> int: + """Create audit trail log entries recording a purge operation. + + If activation_ids or activation_names are provided, audit entries + are scoped to those activations plus orphaned records. Otherwise, + audit entries are created for all RulebookProcess instances. + + Returns the number of audit entries created. + """ + ids = activation_ids or [] + names = activation_names or [] + + if not ids and not names: + instances = models.RulebookProcess.objects.all() + else: + instances = models.RulebookProcess.objects.filter( + Q(activation__id__in=ids) + | Q(activation__name__in=names) + | Q(activation__isnull=True), + ) + + dt = timezone.now().strftime("%Y-%m-%d %H:%M:%S") + cutoff_ts = int(cutoff.timestamp()) + + audit_logs = [ + models.RulebookProcessLog( + log=( + f"All log records older than " + f"{cutoff.strftime('%Y-%m-%d')} " + f"were purged at {dt}." + ), + activation_instance_id=instance.id, + log_timestamp=cutoff_ts, + ) + for instance in instances + ] + + if audit_logs: + models.RulebookProcessLog.objects.bulk_create(audit_logs) + + return len(audit_logs) diff --git a/src/aap_eda/services/activation/db_log_handler.py b/src/aap_eda/services/activation/db_log_handler.py index beef7d7d0..a8274edd5 100644 --- a/src/aap_eda/services/activation/db_log_handler.py +++ b/src/aap_eda/services/activation/db_log_handler.py @@ -83,6 +83,7 @@ def flush(self) -> None: models.RulebookProcessLog.objects.bulk_create( self.activation_instance_log_buffer ) + self._enforce_max_log_lines() except IntegrityError: message = ( f"Instance id: {self.activation_instance_id} is not present." @@ -91,6 +92,31 @@ def flush(self) -> None: self.activation_instance_log_buffer = [] + def _enforce_max_log_lines(self) -> None: + max_lines = settings.MAX_LOG_LINES_PER_INSTANCE + if not max_lines: + return + + total = self.num_of_log_lines() + if total <= max_lines: + return + + excess = total - max_lines + oldest_ids = ( + models.RulebookProcessLog.objects.filter( + activation_instance_id=self.activation_instance_id, + ) + .order_by("id") + .values_list("id", flat=True)[:excess] + ) + models.RulebookProcessLog.objects.filter(id__in=oldest_ids).delete() + LOGGER.warning( + "Trimmed %d oldest log lines for instance %d (cap: %d)", + excess, + self.activation_instance_id, + max_lines, + ) + def get_log_read_at(self) -> Optional[datetime]: try: activation_instance = models.RulebookProcess.objects.get( diff --git a/src/aap_eda/settings/core.py b/src/aap_eda/settings/core.py index 28d81da2e..706788ac8 100644 --- a/src/aap_eda/settings/core.py +++ b/src/aap_eda/settings/core.py @@ -159,6 +159,7 @@ DISPATCHERD_SCHEDULE_TASKS = { "aap_eda.tasks.orchestrator.monitor_rulebook_processes": {"schedule": 5}, "aap_eda.tasks.project.monitor_project_tasks": {"schedule": 30}, + "aap_eda.tasks.log_cleanup.purge_old_log_records": {"schedule": 3600}, } diff --git a/src/aap_eda/settings/defaults.py b/src/aap_eda/settings/defaults.py index 6625ab001..b8fcee36c 100644 --- a/src/aap_eda/settings/defaults.py +++ b/src/aap_eda/settings/defaults.py @@ -186,6 +186,12 @@ ANSIBLE_RULEBOOK_LOG_LEVEL: str = "error" ANSIBLE_RULEBOOK_FLUSH_AFTER: int = 100 +# --------------------------------------------------------- +# RULEBOOK PROCESS LOG RETENTION +# --------------------------------------------------------- +LOG_RETENTION_DAYS: int = 30 +MAX_LOG_LINES_PER_INSTANCE: int = 500000 + # --------------------------------------------------------- # DJANGO ANSIBLE BASE JWT SETTINGS # --------------------------------------------------------- diff --git a/src/aap_eda/tasks/log_cleanup.py b/src/aap_eda/tasks/log_cleanup.py new file mode 100644 index 000000000..cb85121c8 --- /dev/null +++ b/src/aap_eda/tasks/log_cleanup.py @@ -0,0 +1,55 @@ +# Copyright 2025 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 +from datetime import timedelta + +from ansible_base.lib.utils.db import advisory_lock +from django.conf import settings +from django.utils import timezone + +from aap_eda.core.utils.delete_log_util import delete_logs_older_than + +LOGGER = logging.getLogger(__name__) + + +def purge_old_log_records() -> None: + """Purge log records older than the configured retention period. + + Ensures only one task is executed at a time. + """ + with advisory_lock("purge_old_log_records", wait=False) as acquired: + if not acquired: + LOGGER.debug( + "purge_old_log_records already running, exiting", + ) + return + + _purge_old_log_records() + + +def _purge_old_log_records() -> None: + retention_days = settings.LOG_RETENTION_DAYS + if retention_days <= 0: + return + + cutoff = timezone.now() - timedelta(days=retention_days) + deleted = delete_logs_older_than(cutoff) + + if deleted: + LOGGER.info( + "Purged %d log records older than %d days", + deleted, + retention_days, + ) diff --git a/tests/integration/api/test_activation_instance.py b/tests/integration/api/test_activation_instance.py index 07562e09a..2bc62ffd0 100644 --- a/tests/integration/api/test_activation_instance.py +++ b/tests/integration/api/test_activation_instance.py @@ -154,6 +154,22 @@ def test_list_activation_instance_logs_filter_non_existent( assert data == [] +@pytest.mark.django_db +def test_logs_page_size_capped_at_max( + default_activation_instances: List[models.RulebookProcess], + default_activation_instance_logs: List[models.RulebookProcessLog], + admin_client: APIClient, +): + instance = default_activation_instances[0] + + response = admin_client.get( + f"{api_url_v1}/activation-instances/{instance.id}" + f"/logs/?page_size=999999" + ) + assert response.status_code == status.HTTP_200_OK + assert response.data["page_size"] == 1000 + + def assert_activation_instance_data( data: Dict[str, Any], instance: models.RulebookProcess ): diff --git a/tests/integration/commands/test_purge_log_records.py b/tests/integration/commands/test_purge_log_records.py index 3be676240..8b64dbad6 100644 --- a/tests/integration/commands/test_purge_log_records.py +++ b/tests/integration/commands/test_purge_log_records.py @@ -18,6 +18,7 @@ from django.core.management import call_command from django.core.management.base import CommandError from django.db import connection, transaction +from django.test import override_settings from django.utils import timezone from aap_eda.core import enums, models @@ -158,30 +159,37 @@ 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_invalid_date(): + with pytest.raises(CommandError): + call_command("purge_log_records", "--date", "not-a-date") @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) +@override_settings(LOG_RETENTION_DAYS=0) +def test_purge_log_records_no_date_retention_disabled(capsys): + call_command("purge_log_records") captured = capsys.readouterr() + assert "nothing to purge" in captured.out - # 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 - ) - args = ("--activation-names", "na", "--date", "2024-10-01") - call_command("purge_log_records", args) +@pytest.mark.django_db +@override_settings(LOG_RETENTION_DAYS=15) +def test_purge_log_records_defaults_to_retention_days( + prepare_log_records, capsys +): + assert models.RulebookProcessLog.objects.count() == 8 + + call_command("purge_log_records") + + captured = capsys.readouterr() + assert "Purged 4 log records" in captured.out + assert models.RulebookProcessLog.objects.count() == 4 + + +@pytest.mark.django_db +def test_purge_log_records_with_nonexist_activation(capsys): + args = ("--activation-ids", "42", "--date", "2024-10-01") + call_command("purge_log_records", *args) captured = capsys.readouterr() assert ( @@ -191,76 +199,73 @@ def test_purge_log_records_with_nonexist_activation(capsys): @pytest.mark.parametrize( - "identifiers, cutoff_days", - [("ids", 15), ("names", 5), ("none", 15), ("none", 5)], + "cutoff_days, expected_remaining", + [(15, 4), (5, 0)], ) @pytest.mark.django_db -def test_purge_log_records( - prepare_log_records, capsys, identifiers, cutoff_days +def test_purge_log_records_with_date( + prepare_log_records, capsys, cutoff_days, expected_remaining ): - activations = prepare_log_records - assert models.RulebookProcessLog.objects.count() == 8 - command = "purge_log_records" - ts = timezone.now() - timedelta(days=cutoff_days) date_str = ts.strftime("%Y-%m-%d") - if identifiers == "ids": - args = ( - "--activation-ids", - activations[0].id, - activations[1].id, - "--date", - date_str, - ) - elif identifiers == "names": - args = ( - "--activation-names", - activations[0].name, - activations[1].name, - "--date", - date_str, - ) - else: - args = ( - "--date", - date_str, - ) + call_command("purge_log_records", "--date", date_str) + + assert models.RulebookProcessLog.objects.count() == expected_remaining + assert "Purged" in capsys.readouterr().out + - call_command(command, args) +@pytest.mark.django_db +def test_purge_log_records_with_audit_trail(prepare_log_records, capsys): + activations = prepare_log_records + assert models.RulebookProcessLog.objects.count() == 8 + + ts = timezone.now() - timedelta(days=15) + date_str = ts.strftime("%Y-%m-%d") + + call_command( + "purge_log_records", + "--date", + date_str, + "--audit-trail", + "--activation-ids", + str(activations[0].id), + str(activations[1].id), + ) captured = capsys.readouterr() - if cutoff_days < 10: - # Global purge: all original logs deleted, audit logs created for - # all 4 RulebookProcess instances - 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 - ) - 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 - - # 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" - ) - assert audit_logs.count() == 4 + assert "Purged" in captured.out + assert "audit trail" in captured.out - # Check that 10-day logs still exist (not purged) - original_logs = models.RulebookProcessLog.objects.exclude( - log__contains="purged" - ) - assert original_logs.count() == 4 + audit_logs = models.RulebookProcessLog.objects.filter( + log__contains="were purged at" + ) + assert audit_logs.count() == 4 - assert "Purged" in captured.out and "globally" in captured.out + original_logs = models.RulebookProcessLog.objects.exclude( + log__contains="purged" + ) + assert original_logs.count() == 4 + + +@pytest.mark.django_db +def test_purge_log_records_without_audit_trail(prepare_log_records, capsys): + assert models.RulebookProcessLog.objects.count() == 8 + + ts = timezone.now() - timedelta(days=5) + date_str = ts.strftime("%Y-%m-%d") + + call_command("purge_log_records", "--date", date_str) + + captured = capsys.readouterr() + + assert "Purged" in captured.out + assert "audit trail" not in captured.out + + assert models.RulebookProcessLog.objects.count() == 0 @pytest.fixture @@ -273,7 +278,6 @@ def null_activation_test_data( ): """Setup test data including a RulebookProcess with NULL activation.""" - # Create a normal activation activation = models.Activation.objects.create( name="test-activation-null-bug", description="Test activation", @@ -286,7 +290,6 @@ def null_activation_test_data( log_level="debug", ) - # Create RulebookProcess with normal activation normal_process = models.RulebookProcess.objects.create( name="normal-process-null-test", activation=activation, @@ -294,8 +297,6 @@ def null_activation_test_data( organization=default_organization, ) - # Create RulebookProcess with NULL activation using raw SQL - # This bypasses the model validation with transaction.atomic(): cursor = connection.cursor() cursor.execute( @@ -312,22 +313,18 @@ def null_activation_test_data( enums.ProcessParentType.ACTIVATION, timezone.now(), default_organization.id, - None, # NULL activation + None, ], ) - # Get the null process object null_process = models.RulebookProcess.objects.get( name="null-activation-process-test" ) - # Create timestamp for old logs (20 days ago) old_timestamp = timezone.now() - timedelta(days=20) - # Create log records for both processes models.RulebookProcessLog.objects.bulk_create( [ - # Logs for normal process models.RulebookProcessLog( log="Normal process log for null test 1", activation_instance=normal_process, @@ -338,7 +335,6 @@ def null_activation_test_data( activation_instance=normal_process, log_timestamp=int(old_timestamp.timestamp()), ), - # Logs for NULL activation process models.RulebookProcessLog( log="NULL activation process log for null test 1", activation_instance=null_process, @@ -363,48 +359,27 @@ def null_activation_test_data( def test_purge_without_activation_filter_handles_null_correctly( null_activation_test_data, capsys ): - """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" + assert initial_log_count == 4 - # 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) - - captured = capsys.readouterr() + call_command("purge_log_records", "--date", cutoff_date) - # 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 and "globally" in captured.out + ) + assert remaining_test_logs.count() == 0 + captured = capsys.readouterr() + assert "Purged" in captured.out @pytest.mark.django_db -def test_purge_with_activation_filter_now_includes_null_fix( +def test_purge_with_audit_trail_includes_null_activation( null_activation_test_data, capsys ): - """Purge includes NULL records with filters.""" - - # 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 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 @@ -414,61 +389,24 @@ def test_purge_with_activation_filter_now_includes_null_fix( str(activation_id), "--date", cutoff_date, - verbosity=3, + "--audit-trail", ) captured = capsys.readouterr() - # Check what logs remain remaining_test_logs = models.RulebookProcessLog.objects.filter( log__contains="for null test" ).exclude(log__contains="purged") + assert remaining_test_logs.count() == 0 - # 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" - ) - - # 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" - - # Verify that the command output mentions orphaned records - assert ( - "Audit trail will include" in captured.out - and "orphaned" in captured.out - ), "Should mention orphaned records in output" + assert "Purged" in captured.out + assert "audit trail" in captured.out @pytest.mark.django_db -def test_purge_with_activation_name_filter_also_includes_null_fix( +def test_purge_with_audit_trail_by_name_includes_null( 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) cutoff_date = (timezone.now() - timedelta(days=10)).strftime("%Y-%m-%d") activation_name = null_activation_test_data["activation"].name @@ -478,32 +416,15 @@ def test_purge_with_activation_name_filter_also_includes_null_fix( activation_name, "--date", cutoff_date, - verbosity=3, + "--audit-trail", ) captured = capsys.readouterr() - # Check what logs remain remaining_test_logs = models.RulebookProcessLog.objects.filter( log__contains="for null test" ).exclude(log__contains="purged") + assert remaining_test_logs.count() == 0 - # 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" - ) - - # Verify that the command output mentions orphaned records - assert ( - "Audit trail will include" in captured.out - and "orphaned" in captured.out - ), "Should mention orphaned records in output" + assert "Purged" in captured.out + assert "audit trail" in captured.out diff --git a/tests/integration/services/activation/test_db_log_handler.py b/tests/integration/services/activation/test_db_log_handler.py new file mode 100644 index 000000000..c1300b714 --- /dev/null +++ b/tests/integration/services/activation/test_db_log_handler.py @@ -0,0 +1,147 @@ +# Copyright 2025 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 pytest +from django.test import override_settings + +from aap_eda.core import enums, models +from aap_eda.services.activation.db_log_handler import DBLogger + + +@pytest.fixture +def rulebook_process( + default_decision_environment: models.DecisionEnvironment, + default_project: models.Project, + default_rulebook: models.Rulebook, + default_extra_var_data: str, + default_organization: models.Organization, + default_user: models.User, +) -> models.RulebookProcess: + activation = models.Activation.objects.create( + name="test-activation", + decision_environment=default_decision_environment, + project=default_project, + rulebook=default_rulebook, + extra_var=default_extra_var_data, + organization=default_organization, + user=default_user, + ) + + return models.RulebookProcess.objects.create( + name="test-instance", + activation=activation, + git_hash=default_project.git_hash, + status=enums.ActivationStatus.RUNNING, + status_message=enums.ACTIVATION_STATUS_MESSAGE_MAP[ + enums.ActivationStatus.RUNNING + ], + organization=default_organization, + ) + + +@pytest.mark.django_db +@override_settings( + ANSIBLE_RULEBOOK_FLUSH_AFTER="end", + MAX_LOG_LINES_PER_INSTANCE=10, +) +def test_enforce_max_log_lines_trims_oldest(rulebook_process): + logger = DBLogger(rulebook_process.id) + + for i in range(15): + logger.write(f"log line {i}", flush=False) + + logger.flush() + + assert ( + models.RulebookProcessLog.objects.filter( + activation_instance=rulebook_process, + ).count() + == 10 + ) + + remaining = list( + models.RulebookProcessLog.objects.filter( + activation_instance=rulebook_process, + ) + .order_by("id") + .values_list("log", flat=True) + ) + assert remaining[0] == "log line 5" + assert remaining[-1] == "log line 14" + + +@pytest.mark.django_db +@override_settings( + ANSIBLE_RULEBOOK_FLUSH_AFTER="end", + MAX_LOG_LINES_PER_INSTANCE=0, +) +def test_enforce_max_log_lines_disabled_when_zero(rulebook_process): + logger = DBLogger(rulebook_process.id) + + for i in range(20): + logger.write(f"log line {i}", flush=False) + + logger.flush() + + assert ( + models.RulebookProcessLog.objects.filter( + activation_instance=rulebook_process, + ).count() + == 20 + ) + + +@pytest.mark.django_db +@override_settings( + ANSIBLE_RULEBOOK_FLUSH_AFTER="end", + MAX_LOG_LINES_PER_INSTANCE=50, +) +def test_enforce_max_log_lines_no_trim_when_under_cap(rulebook_process): + logger = DBLogger(rulebook_process.id) + + for i in range(10): + logger.write(f"log line {i}", flush=False) + + logger.flush() + + assert ( + models.RulebookProcessLog.objects.filter( + activation_instance=rulebook_process, + ).count() + == 10 + ) + + +@pytest.mark.django_db +@override_settings( + ANSIBLE_RULEBOOK_FLUSH_AFTER="end", + MAX_LOG_LINES_PER_INSTANCE=10, +) +def test_enforce_max_log_lines_preserves_newest(rulebook_process): + logger = DBLogger(rulebook_process.id) + + for i in range(25): + logger.write(f"line {i}", flush=False) + + logger.flush() + + remaining = list( + models.RulebookProcessLog.objects.filter( + activation_instance=rulebook_process, + ) + .order_by("id") + .values_list("log", flat=True) + ) + assert len(remaining) == 10 + assert remaining == [f"line {i}" for i in range(15, 25)] diff --git a/tests/integration/tasks/test_log_cleanup.py b/tests/integration/tasks/test_log_cleanup.py new file mode 100644 index 000000000..abd65b56d --- /dev/null +++ b/tests/integration/tasks/test_log_cleanup.py @@ -0,0 +1,219 @@ +# Copyright 2025 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 timedelta + +import pytest +from django.test import override_settings +from django.utils import timezone + +from aap_eda.core import enums, models +from aap_eda.core.utils.delete_log_util import create_audit_trail +from aap_eda.tasks.log_cleanup import _purge_old_log_records + + +@pytest.fixture +def activation_with_logs( + default_decision_environment: models.DecisionEnvironment, + default_project: models.Project, + default_rulebook: models.Rulebook, + default_extra_var_data: str, + default_organization: models.Organization, + default_user: models.User, +): + activation = models.Activation.objects.create( + name="test-activation", + decision_environment=default_decision_environment, + project=default_project, + rulebook=default_rulebook, + extra_var=default_extra_var_data, + organization=default_organization, + user=default_user, + ) + + instance = models.RulebookProcess.objects.create( + name="test-instance", + activation=activation, + git_hash=default_project.git_hash, + status=enums.ActivationStatus.RUNNING, + status_message=enums.ACTIVATION_STATUS_MESSAGE_MAP[ + enums.ActivationStatus.RUNNING + ], + organization=default_organization, + ) + + now = timezone.now() + + old_logs = models.RulebookProcessLog.objects.bulk_create( + [ + models.RulebookProcessLog( + log=f"old log line {i}", + activation_instance=instance, + log_timestamp=int((now - timedelta(days=45 - i)).timestamp()), + ) + for i in range(5) + ] + ) + + recent_logs = models.RulebookProcessLog.objects.bulk_create( + [ + models.RulebookProcessLog( + log=f"recent log line {i}", + activation_instance=instance, + log_timestamp=int((now - timedelta(days=5 - i)).timestamp()), + ) + for i in range(5) + ] + ) + + return { + "activation": activation, + "instance": instance, + "old_logs": old_logs, + "recent_logs": recent_logs, + } + + +@pytest.mark.django_db +@override_settings(LOG_RETENTION_DAYS=30) +def test_purge_deletes_old_logs(activation_with_logs): + assert models.RulebookProcessLog.objects.count() == 10 + + _purge_old_log_records() + + assert models.RulebookProcessLog.objects.count() == 5 + remaining = models.RulebookProcessLog.objects.values_list("log", flat=True) + for log in remaining: + assert "recent" in log + + +@pytest.mark.django_db +@override_settings(LOG_RETENTION_DAYS=30) +def test_purge_preserves_recent_logs(activation_with_logs): + recent_ids = {log.id for log in activation_with_logs["recent_logs"]} + + _purge_old_log_records() + + remaining_ids = set( + models.RulebookProcessLog.objects.values_list("id", flat=True) + ) + assert recent_ids == remaining_ids + + +@pytest.mark.django_db +@override_settings(LOG_RETENTION_DAYS=0) +def test_purge_disabled_when_zero(activation_with_logs): + _purge_old_log_records() + + assert models.RulebookProcessLog.objects.count() == 10 + + +@pytest.mark.django_db +@override_settings(LOG_RETENTION_DAYS=30) +def test_purge_no_logs_to_delete( + default_decision_environment, + default_project, + default_rulebook, + default_extra_var_data, + default_organization, + default_user, +): + activation = models.Activation.objects.create( + name="test-activation", + decision_environment=default_decision_environment, + project=default_project, + rulebook=default_rulebook, + extra_var=default_extra_var_data, + organization=default_organization, + user=default_user, + ) + + instance = models.RulebookProcess.objects.create( + name="test-instance", + activation=activation, + git_hash=default_project.git_hash, + status=enums.ActivationStatus.RUNNING, + status_message=enums.ACTIVATION_STATUS_MESSAGE_MAP[ + enums.ActivationStatus.RUNNING + ], + organization=default_organization, + ) + + now = timezone.now() + models.RulebookProcessLog.objects.create( + log="recent log", + activation_instance=instance, + log_timestamp=int((now - timedelta(days=1)).timestamp()), + ) + + _purge_old_log_records() + + assert models.RulebookProcessLog.objects.count() == 1 + + +@pytest.mark.django_db +def test_create_audit_trail_all_instances(activation_with_logs): + instance = activation_with_logs["instance"] + cutoff = timezone.now() - timedelta(days=30) + + count = create_audit_trail(cutoff) + + assert count == 1 + audit_log = models.RulebookProcessLog.objects.filter( + activation_instance=instance, + log__contains="were purged at", + ) + assert audit_log.count() == 1 + + +@pytest.mark.django_db +def test_create_audit_trail_scoped_by_activation_id(activation_with_logs): + activation = activation_with_logs["activation"] + cutoff = timezone.now() - timedelta(days=30) + + count = create_audit_trail( + cutoff, + activation_ids=[activation.id], + ) + + assert count == 1 + audit_log = models.RulebookProcessLog.objects.filter( + log__contains="were purged at", + ) + assert audit_log.count() == 1 + + +@pytest.mark.django_db +def test_create_audit_trail_scoped_by_name(activation_with_logs): + activation = activation_with_logs["activation"] + cutoff = timezone.now() - timedelta(days=30) + + count = create_audit_trail( + cutoff, + activation_names=[activation.name], + ) + + assert count == 1 + + +@pytest.mark.django_db +def test_create_audit_trail_no_match(activation_with_logs): + cutoff = timezone.now() - timedelta(days=30) + + count = create_audit_trail( + cutoff, + activation_ids=[99999], + ) + + assert count == 0