diff --git a/backend/dashboard_metrics/README.md b/backend/dashboard_metrics/README.md index fc40e9f55b..a80e5ded63 100644 --- a/backend/dashboard_metrics/README.md +++ b/backend/dashboard_metrics/README.md @@ -14,7 +14,7 @@ This module provides a metrics dashboard for monitoring document processing, API ### Data Flow ``` Source Tables (usage_v2, page_usage, workflow_execution, workflow_file_execution) - ↓ [Celery task every 15 min] + ↓ [Celery: hourly tier every 15 min, daily+monthly hourly at :20] Aggregated Tables (EventMetricsHourly → Daily → Monthly) ↓ API Endpoints (/overview/, /summary/, /series/) @@ -33,7 +33,10 @@ Frontend Dashboard (MetricsSummary, MetricsChart, MetricsTable) ### Quick Commands ```bash -# Backfill historical data (run first!) +# Backfill historical data +# The deploy step is a different invocation with its own ordering — see +# "Why 62 days" below; do not run it from the outgoing image, where +# --skip-hourly still issues the HOUR queries it skips here. python manage.py backfill_metrics --days=30 # Start metrics worker @@ -46,7 +49,9 @@ celery -A backend beat -l info ### Celery Tasks & Schedule | Task | Schedule | What It Does | |------|----------|--------------| -| `aggregate_from_sources` | Every 15 min | Aggregates source → hourly/daily/monthly | +| `aggregate_from_sources` | Every 15 min | Aggregates source → **hourly tier only** (`tier=hourly`) | +| `aggregate_from_sources` (daily+monthly) | Hourly at :20 | Aggregates source → daily; rolls monthly up from daily (`tier=daily_monthly`) | +| `aggregate_from_sources` (reconcile) | Daily 4:40 AM | Daily + monthly tiers over a 7-day source window, to repair gaps after downtime | | `cleanup_hourly_data` | Daily 2 AM | Deletes hourly data > 30 days | | `cleanup_daily_data` | Weekly Sun 3 AM | Deletes daily data > 365 days | @@ -109,7 +114,7 @@ celery -A backend beat -l info │ EventMetrics │ │ EventMetrics │ │ EventMetrics │ │ Hourly │ │ Daily │ │ Monthly │ │ │ │ │ │ │ -│ • 24h query │ │ • 7 day query │ │ • 2 month query │ +│ • 24h query │ │ • 2 day query │ │ • from daily │ │ • 30 day retain │ │ • 365 day retain│ │ • No cleanup │ └────────┬────────┘ └────────┬────────┘ └────────┬────────┘ │ │ │ @@ -149,8 +154,8 @@ The dashboard reads from **pre-aggregated tables** (`event_metrics_hourly`, `eve **Write Safety:** - Aggregation tables are **write-isolated** — only the Celery aggregation task (`aggregate_from_sources`) and the `backfill_metrics` management command write to them. No user-facing request path writes to these tables. -- Writes use `update_or_create` with a unique constraint on `(organization, timestamp, metric_name, project, tag)`, making upserts idempotent. Running the aggregation task twice for the same period simply overwrites with the same values. -- Aggregation tasks use `_base_manager` to bypass Django's `DefaultOrganizationManagerMixin`, which relies on `UserContext` (unavailable in Celery). This is safe because the task already scopes all queries by `organization_id`. +- Writes use `bulk_create(update_conflicts=True)` against each tier's own unique constraint — `timestamp` for hourly, `date` for daily, `month` for monthly — making upserts idempotent. Running the aggregation task twice for the same period simply overwrites with the same values. +- Aggregation tasks use `_base_manager` to bypass Django's `DefaultOrganizationManagerMixin`, which relies on `UserContext` (unavailable in Celery). Most call sites are per-organization; the monthly rollup deliberately is not, and groups by `organization_id` instead — see `_rollup_monthly_from_daily`. **Read Safety:** - Dashboard API endpoints read **only** from pre-aggregated tables, never from source tables (except `/live-summary/` and `/live-series/` which are for real-time fallback). @@ -162,7 +167,9 @@ The dashboard reads from **pre-aggregated tables** (`event_metrics_hourly`, `eve - Source table performance is unaffected by the dashboard feature. If the aggregation task is slow or fails, source tables continue working normally. **Failure Resilience:** -- If the aggregation task fails, the dashboard shows stale data (up to 15 minutes old) rather than crashing. +- If the aggregation task fails, the dashboard shows stale data rather than crashing — up to 15 minutes old for hourly figures, up to an hour for daily and monthly. +- A daily 04:40 UTC reconciliation pass reruns the same task over a 7-day source window, so a **daily- or monthly-tier** gap shorter than that repairs itself without a manual backfill. The hourly tier re-queries the last 24h on every run regardless of tier or window, so an hourly gap shorter than 24h repairs itself on the next tick; only one older than 24h needs `backfill_metrics`. +- The 7-day window is also the ceiling on lag, not just on downtime. `documents_processed` and `failed_pages` filter on a terminal status but window and bucket on `created_at`, so a row whose status turns terminal more than 7 days after it was created is counted in no daily row — and therefore in no monthly total either, since monthly is the sum of daily. Before the monthly tier was derived from daily this was caught by the wider monthly source window. - Celery tasks have `max_retries=3` with exponential backoff. - Cleanup tasks (hourly: 30-day retention, daily: 365-day retention) prevent unbounded table growth. @@ -298,8 +305,8 @@ cost = (input_cost_per_token × input_tokens) + (output_cost_per_token × output | Table | Model | Time Column | Granularity | Query Window | Retention | |-------|-------|-------------|-------------|--------------|-----------| | `event_metrics_hourly` | `EventMetricsHourly` | `timestamp` | Hour | Last 24 hours | 30 days | -| `event_metrics_daily` | `EventMetricsDaily` | `date` | Day | Last 7 days | 365 days | -| `event_metrics_monthly` | `EventMetricsMonthly` | `month` | Month | Last 2 months | Forever | +| `event_metrics_daily` | `EventMetricsDaily` | `date` | Day | Last 2 days (7 on the daily reconciliation pass) | 365 days | +| `event_metrics_monthly` | `EventMetricsMonthly` | `month` | Month | Rolled up from the daily tier, current + previous month | Forever | ### Table Schema @@ -339,7 +346,9 @@ Located in `tasks.py`: | Task Name | Celery Name | Schedule | Queue | Purpose | |-----------|-------------|----------|-------|---------| -| `aggregate_metrics_from_sources` | `dashboard_metrics.aggregate_from_sources` | Every 15 min | `dashboard_metric_events` | Aggregate from source tables | +| `aggregate_metrics_from_sources` | `dashboard_metrics.aggregate_from_sources` | Every 15 min | `dashboard_metric_events` | Aggregate the hourly tier (`tier=hourly`) | +| `aggregate_metrics_from_sources` | `dashboard_metrics.aggregate_from_sources` | Hourly at :20 UTC | `dashboard_metric_events` | Aggregate the daily and monthly tiers (`tier=daily_monthly`) | +| `aggregate_metrics_from_sources` | `dashboard_metrics.aggregate_from_sources` | Daily 4:40 AM UTC | `dashboard_metric_events` | Reconciliation pass, daily + monthly tiers, `source_window_days=7` | | `cleanup_hourly_metrics` | `dashboard_metrics.cleanup_hourly_data` | Daily 2:00 AM UTC | `dashboard_metric_events` | Delete hourly data >30 days | | `cleanup_daily_metrics` | `dashboard_metrics.cleanup_daily_data` | Weekly Sun 3:00 AM UTC | `dashboard_metric_events` | Delete daily data >365 days | @@ -378,16 +387,97 @@ The `aggregate_metrics_from_sources` task: 2. **For each metric**: - Queries source table with `MetricsQueryService` - Groups by time period (hour/day/month) -3. **Upserts results** into aggregated tables using `update_or_create` -4. **Uses `_base_manager`** to bypass Django's organization filter in Celery context +3. **Upserts results** into the hourly and daily tables +4. **Rolls monthly up from the daily tier** for all orgs at once, streamed and batched. Upsert-only: + a monthly row the daily tier no longer produces is left in place. A stale total is + recoverable with `backfill_metrics`; a deleted one is not, because the daily rows + that would rebuild it are exactly what is missing +5. **Uses `_base_manager`** to bypass Django's organization filter in Celery context ```python # Query windows -hourly_start = end_date - timedelta(hours=24) # Last 24 hours -daily_start = end_date - timedelta(days=7) # Last 7 days -monthly_start = first_of_previous_month # Last 2 months +hourly_start = end_date - timedelta(hours=24) # Last 24 hours +daily_start = truncate_to_day(end_date - source_window_days) # 2 days, 7 on reconcile +monthly_start = first_of_previous_month # summed from daily ``` +The monthly tier has no source queries of its own. `backfill_metrics` still computes +monthly from source, so within the rollup window (current + previous month) its output +is overwritten by the sum of the daily tier on the next daily/monthly pass — see that +command's help text. **Backfill daily before relying on monthly:** where a month's +stored total is already higher than what daily now sums to, the rollup keeps the +stored figure and reports it under `needs_daily_repair`. That guard needs a stored +total to compare against, so a month with no monthly row yet — the first run of any +calendar month — is still written short. Missing whole days are reported separately, +under `incomplete_daily_coverage`. + +Run this as soon as `migrate` finishes. It cannot be sequenced *before* the first +aggregation: the schedule row `0006` adds goes live at the end of `migrate`, so the +:20 run can fire while the backfill is still going. That first rollup may write a +short month — it has no stored total to compare against, so the guard is blind to it +— and the backfill repairs it. Expect one under-counted reading, not a race to lose: + +``` +python manage.py backfill_metrics --days 62 --skip-hourly --skip-monthly +``` + +### Rolling this release back + +`0005` and `0006` write task kwargs into both scheduler tables. The previous release's +zero-argument signatures reject them with `TypeError`, which nothing retries. **Reverting +the image alone is not enough** — run `migrate dashboard_metrics 0004` from the outgoing +image *before* the image reverts, which reverses both migrations together. A +platform-driven rollback (an ArgoCD revision revert, an image tag pin) skips that by +construction, so treat this release as blocking automated rollback. + +**If the rollback already happened without that step**, the migration is gone with the +image and `migrate dashboard_metrics 0004` has nothing to apply. The rows still carry +kwargs the restored signatures reject, so all three tiers stop on both transports with +no self-heal. Recovery is by hand, against both scheduler tables: + +```sql +-- Application tables are not in the default search path: the schema comes from +-- DB_SCHEMA and is set per connection by the app's own wrapper, which a psql +-- session does not inherit. +SET search_path TO unstract; -- or whatever DB_SCHEMA is set to + +DELETE FROM django_celery_beat_periodictask + WHERE name IN ('dashboard_metrics_reconcile_source_window', + 'dashboard_metrics_aggregate_daily_monthly'); +UPDATE django_celery_beat_periodictask SET kwargs = '{}' + WHERE name = 'dashboard_metrics_aggregate_from_sources'; +UPDATE django_celery_beat_periodictasks SET last_update = now() WHERE ident = 1; +``` + +and the same three against `pg_periodic_task` (`task_kwargs = '{}'::jsonb`). + +**This recovery is a one-way door until you undo it.** The SQL changes rows, not +`django_migrations`, which still records `0005` and `0006` as applied — so a later +roll-forward of this release reports "No migrations to apply" and restores nothing. +The install keeps running the single `*/15` row with `kwargs = '{}'`, which defaults +`tier` to ALL: every tier written 96 times a day, the load this release removes, and +no reconciliation pass at all. Nothing errors; the only trace is `tier=all` in the +completion log. + +To clear it, deploy the new image first, then from **that** image run +`manage.py migrate dashboard_metrics 0004 --fake` followed by +`manage.py migrate dashboard_metrics`. Both steps are needed: the entrypoint's own +`migrate` runs before you get there and reports nothing to apply. Run the `--fake` +from the OUTGOING image and it does nothing at all — `0005` and `0006` are not on +disk there, so `0004` has no child to unapply and the command prints "No migrations +to apply" while un-recording nothing. + +The forward direction is bounded rather than self-healing: a pod still on the old image +during a rolling deploy has the old signature and raises `TypeError` per tick until the +rollout completes. The `**_ignored` in this release does not help those pods — it is +what lets a *later* release add a kwarg without breaking pods running this one. + +### Why 62 days + +62, not 60: the rollup window reaches back to the first of the previous month, which is +61 days before a run on the 31st. `--skip-monthly` is deliberate — repair daily and let +the rollup derive monthly from it. + --- ## API Endpoints @@ -706,13 +796,15 @@ Populates aggregated tables from historical source data. ```bash python manage.py backfill_metrics [options] -Options: +Options (run --help for the authoritative text; the three --skip-* flags carry +caveats that do not fit one line): --days=N Number of days to backfill (default: 30) --org-id=UUID Specific organization (default: all) + --active-only Only orgs with an active subscription --dry-run Show what would be done - --skip-hourly Skip hourly aggregation - --skip-daily Skip daily aggregation - --skip-monthly Skip monthly aggregation + --skip-hourly Skip the HOUR source queries, not just their upsert + --skip-daily Leave the daily tier short; the rollup then freezes the month + --skip-monthly Largely a no-op inside the rollup window ``` --- diff --git a/backend/dashboard_metrics/internal_views.py b/backend/dashboard_metrics/internal_views.py index f776633944..a4208e66c1 100644 --- a/backend/dashboard_metrics/internal_views.py +++ b/backend/dashboard_metrics/internal_views.py @@ -34,6 +34,9 @@ from utils.local_context import StateStore from dashboard_metrics.tasks import ( + DASHBOARD_SOURCE_WINDOW_DAYS, + MAX_SOURCE_WINDOW_DAYS, + AggregationTier, aggregate_metrics_from_sources, cleanup_daily_metrics, cleanup_hourly_metrics, @@ -58,7 +61,16 @@ def _clear_org_context() -> None: StateStore.clear(Account.ORGANIZATION_ID) -def _int_arg(request: Request, key: str, default: int) -> int: +def _tier_arg(raw: Any) -> AggregationTier: + """Coerce a request body's tier to the enum, raising ValueError on anything else.""" + try: + return AggregationTier(raw) + except ValueError as exc: + valid = [member.value for member in AggregationTier] + raise ValueError(f"tier must be one of {valid}, got {raw!r}") from exc + + +def _int_arg(request: Request, key: str, default: int, maximum: int | None = None) -> int: """Read an optional positive integer from the request body.""" raw = request.data.get(key, default) if isinstance(request.data, dict) else default try: @@ -67,6 +79,8 @@ def _int_arg(request: Request, key: str, default: int) -> int: raise ValueError(f"{key} must be an integer, got {raw!r}") from exc if value < 1: raise ValueError(f"{key} must be >= 1, got {value}") + if maximum is not None and value > maximum: + raise ValueError(f"{key} must be <= {maximum}, got {value}") return value @@ -74,11 +88,12 @@ class _MetricsTaskAPIView(APIView): """Shared plumbing: clear org context, run, translate errors.""" def _run(self, fn, *args: Any, **kwargs: Any) -> Response: + """Run one task body. Every view validates its own body first, so anything + raising in here is an internal fault and belongs on the logged 500 path. + """ _clear_org_context() try: return Response(fn(*args, **kwargs)) - except ValueError as exc: # bad request body - return Response({"error": str(exc)}, status=status.HTTP_400_BAD_REQUEST) except Exception as exc: logger.error("dashboard-metrics internal call failed: %s", exc, exc_info=True) return Response( @@ -91,10 +106,38 @@ class AggregateMetricsAPIView(_MetricsTaskAPIView): Calls the Celery task body verbatim, Redis lock included — this endpoint exists only because the PG consumer has no Django, not to change what the job does. + + Two optional body fields, both validated here at the boundary so a ValueError + from inside the ten-minute aggregation stays a logged 500 rather than reading as + a bad request: ``tier`` selects which tiers to write, ``source_window_days`` + widens the daily lookback for the reconciliation pass. Omitting either — or + sending it as ``null`` — applies the task's own default. """ def post(self, request: Request) -> Response: - return self._run(aggregate_metrics_from_sources) + body = request.data if isinstance(request.data, dict) else {} + kwargs: dict[str, Any] = {} + try: + # Rejected rather than ignored: the only automated caller sends exactly + # these two, so an unrecognised key is a hand-run typo — and ignoring it + # returns 200 having quietly run something other than what was asked. + unknown = set(body) - {"tier", "source_window_days"} + if unknown: + raise ValueError(f"unrecognised keys: {sorted(unknown)}") + if body.get("tier") is not None: + kwargs["tier"] = _tier_arg(body["tier"]) + if body.get("source_window_days") is not None: + kwargs["source_window_days"] = _int_arg( + request, + "source_window_days", + DASHBOARD_SOURCE_WINDOW_DAYS, + maximum=MAX_SOURCE_WINDOW_DAYS, + ) + except ValueError as exc: + # The one branch _run no longer covers, so it is logged here or nowhere. + logger.warning("dashboard-metrics aggregate rejected: %s", exc) + return Response({"error": str(exc)}, status=status.HTTP_400_BAD_REQUEST) + return self._run(aggregate_metrics_from_sources, **kwargs) class CleanupHourlyMetricsAPIView(_MetricsTaskAPIView): diff --git a/backend/dashboard_metrics/management/commands/backfill_metrics.py b/backend/dashboard_metrics/management/commands/backfill_metrics.py index 9c4d82baca..0a88a1be0b 100644 --- a/backend/dashboard_metrics/management/commands/backfill_metrics.py +++ b/backend/dashboard_metrics/management/commands/backfill_metrics.py @@ -3,6 +3,13 @@ This command populates EventMetricsHourly, EventMetricsDaily, and EventMetricsMonthly tables from historical data in source tables (Usage, PageUsage, WorkflowExecution, etc.) +The current and previous month are recomputed from the daily tier by the aggregation +task's daily/monthly pass, so inside that window this command's monthly output is +overwritten and --skip-monthly is largely a no-op. --skip-daily leaves that tier short +on purpose: the rollup will not lower a stored monthly total it would reduce, so the +month is not under-counted, but it is frozen at the stored figure until daily is +repaired, and the daily tier the dashboards read stays wrong meanwhile. Repair daily. + Usage: python manage.py backfill_metrics --days=30 python manage.py backfill_metrics --days=90 --org-id=5 @@ -15,7 +22,7 @@ from typing import Any from account_v2.models import Organization -from django.core.management.base import BaseCommand +from django.core.management.base import BaseCommand, CommandError from django.utils import timezone from dashboard_metrics.models import ( @@ -26,6 +33,7 @@ MetricType, ) from dashboard_metrics.services import MetricsQueryService +from dashboard_metrics.tasks import truncate_to_day logger = logging.getLogger(__name__) @@ -87,17 +95,29 @@ def add_arguments(self, parser): parser.add_argument( "--skip-hourly", action="store_true", - help="Skip hourly aggregation (only do daily/monthly)", + help=( + "Skip the HOUR-granularity source queries, not just their upsert. " + "The deploy step passes it over a window measured in weeks." + ), ) parser.add_argument( "--skip-daily", action="store_true", - help="Skip daily aggregation", + help=( + "Skip daily aggregation. Leaves the daily tier short for the " + "current and previous month. The rollup's guard keeps monthly from " + "being lowered, so the month freezes at its stored total rather than " + "under-counting — but daily stays wrong until it is repaired." + ), ) parser.add_argument( "--skip-monthly", action="store_true", - help="Skip monthly aggregation", + help=( + "Skip monthly aggregation. Largely a no-op for the current and " + "previous month: the aggregation task rederives them from daily, " + "except where its guard preserves a higher stored total." + ), ) parser.add_argument( "--active-only", @@ -118,11 +138,23 @@ def handle(self, *args, **options): active_only = options["active_only"] end_date = timezone.now() - start_date = end_date - timedelta(days=days) + # Truncated to match the cron's daily_start: an untruncated boundary writes the + # oldest day covering only part of it, and the monthly rollup now sums the + # persisted daily tier rather than recomputing that day from source. + start_date = truncate_to_day(end_date - timedelta(days=days)) self.stdout.write(f"Backfill period: {start_date.date()} to {end_date.date()}") self.stdout.write(f"Days: {days}") + if skip_daily and not skip_monthly: + self.stdout.write( + self.style.WARNING( + "--skip-daily without --skip-monthly: the daily tier is left " + "short, so the rollup's guard will freeze the current and " + "previous month at their stored totals. Repair daily." + ) + ) + if dry_run: self.stdout.write(self.style.WARNING("DRY RUN - no changes will be made")) @@ -166,12 +198,14 @@ def handle(self, *args, **options): org_identifier = org_identifiers.get(org_id_key) # Collect all metric data for this org - hourly_data, daily_data, monthly_data = self._collect_metrics( + hourly_data, daily_data, monthly_data, failures = self._collect_metrics( current_org_id, start_date, end_date, org_identifier=org_identifier, + skip_hourly=skip_hourly, ) + total_stats["errors"] += failures self.stdout.write( f" Collected: {len(hourly_data)} hourly, " @@ -203,12 +237,22 @@ def handle(self, *args, **options): logger.exception("Error backfilling org %s", current_org_id) # Print summary + failed = total_stats["errors"] self.stdout.write("\n" + "=" * 50) - self.stdout.write(self.style.SUCCESS("BACKFILL COMPLETE")) + style = self.style.ERROR if failed else self.style.SUCCESS + self.stdout.write(style("BACKFILL FAILED" if failed else "BACKFILL COMPLETE")) self.stdout.write(f"Hourly: {total_stats['hourly']['upserted']} upserted") self.stdout.write(f"Daily: {total_stats['daily']['upserted']} upserted") self.stdout.write(f"Monthly: {total_stats['monthly']['upserted']} upserted") - self.stdout.write(f"Errors: {total_stats['errors']}") + self.stdout.write(f"Errors: {failed}") + if failed: + # Non-zero exit, so a deploy runbook cannot tick this step green. The + # rows that did land are kept: this repairs the daily tier, and a partial + # repair is worth more than a rollback. + raise CommandError( + f"{failed} error(s) during backfill; the metrics tiers are " + "incomplete. Re-run before the next aggregation." + ) def _resolve_org_ids( self, @@ -267,14 +311,37 @@ def _resolve_org_ids( return sorted(str(oid) for oid in all_org_ids) + @staticmethod + def _granularities(skip_hourly: bool) -> tuple: + """Which granularities to query. + + `--skip-hourly` skips the HOUR *queries*, not just their upsert: the deploy + step passes it over a window measured in weeks, and issuing them anyway + reinstates the scan this change exists to remove. + """ + return (Granularity.DAY,) if skip_hourly else (Granularity.HOUR, Granularity.DAY) + def _collect_metrics( self, org_id: str, start_date: datetime, end_date: datetime, org_identifier: str | None = None, - ) -> tuple[dict, dict, dict]: - """Collect metrics from source tables for all granularities.""" + skip_hourly: bool = False, + ) -> tuple[dict, dict, dict, int]: + """Collect metrics from source tables for all granularities. + + Returns the aggregations plus a count of failed metric queries. Each query + is caught individually, so a failure never reaches the per-organisation + handler that owns the error counter — it has to be carried back explicitly, + the same way ``_collect_org_metrics`` does in ``tasks.py``. + + ``skip_hourly`` skips the HOUR-granularity source queries, not just their + upsert. The prescribed deploy step passes it over a window measured in + weeks, and issuing those queries anyway would reinstate the scan this + change exists to remove. + """ + failures = 0 hourly_agg = {} daily_agg = {} monthly_agg = {} @@ -339,7 +406,7 @@ def _ingest_daily_results( # Fetch all 4 LLM metrics in one query per granularity try: - for granularity in (Granularity.HOUR, Granularity.DAY): + for granularity in self._granularities(skip_hourly): llm_split = MetricsQueryService.get_llm_metrics_split( org_id, start_date, end_date, granularity ) @@ -352,8 +419,11 @@ def _ingest_daily_results( _ingest_results(data, metric_name, metric_type) else: _ingest_daily_results(data, metric_name, metric_type) - except Exception as e: - logger.warning("Error querying LLM metrics for org %s: %s", org_id, e) + except Exception: + # Counted: every metric query is caught individually, so a failure here + # never reaches the per-org handler that owns the error counter. + failures += 1 + logger.exception("Error querying LLM metrics for org %s", org_id) # Fetch remaining (non-LLM) metrics individually for metric_name, query_method, is_histogram in self.METRIC_CONFIGS: @@ -366,14 +436,15 @@ def _ingest_daily_results( extra_kwargs["org_identifier"] = org_identifier try: - hourly_results = query_method( - org_id, - start_date, - end_date, - granularity=Granularity.HOUR, - **extra_kwargs, - ) - _ingest_results(hourly_results, metric_name, metric_type) + if Granularity.HOUR in self._granularities(skip_hourly): + hourly_results = query_method( + org_id, + start_date, + end_date, + granularity=Granularity.HOUR, + **extra_kwargs, + ) + _ingest_results(hourly_results, metric_name, metric_type) daily_results = query_method( org_id, @@ -384,10 +455,11 @@ def _ingest_daily_results( ) _ingest_daily_results(daily_results, metric_name, metric_type) - except Exception as e: - logger.warning("Error querying %s for org %s: %s", metric_name, org_id, e) + except Exception: + failures += 1 + logger.exception("Error querying %s for org %s", metric_name, org_id) - return hourly_agg, daily_agg, monthly_agg + return hourly_agg, daily_agg, monthly_agg, failures def _truncate_to_hour(self, ts: datetime) -> datetime: """Truncate datetime to hour.""" diff --git a/backend/dashboard_metrics/migrations/0005_add_reconciliation_task.py b/backend/dashboard_metrics/migrations/0005_add_reconciliation_task.py new file mode 100644 index 0000000000..548df03ebf --- /dev/null +++ b/backend/dashboard_metrics/migrations/0005_add_reconciliation_task.py @@ -0,0 +1,154 @@ +"""Data migration to schedule the daily-tier reconciliation pass. + +The 15-minute aggregation reads a narrow source window, which cannot repair +gaps left by cron downtime. This runs the same task once a day at a wider +window to backfill them. + +Declared for **both** transports, like 0002/0004: Beat reads +``django_celery_beat_periodictask``, the PG scheduler reads ``pg_periodic_task``, +and a schedule present on one only stops firing the moment the flag flips. +``kwargs`` is a JSON string on Beat and a JSONField on PG — same value, two +encodings. + +The row carries ``source_window_days``, which the previous release's zero-argument +signatures reject with ``TypeError``. Rolling the code back past this release means +reversing this migration too, **before** the image rolls back — ``migrate +dashboard_metrics 0004``, which reverses 0006 and this one together. +""" + +import json + +from django.db import migrations +from django.utils import timezone + +RECONCILE_TASK_NAME = "dashboard_metrics_reconcile_source_window" +EXISTING_AGGREGATE_ROW = "dashboard_metrics_aggregate_from_sources" +RECONCILE_DESCRIPTION = ( + "Re-aggregate metrics over a 7 day source window to repair " + "daily-tier gaps left by cron downtime" +) + +# Single source for both directions, and importable by the drift test. +PG_PERIODIC_TASKS = [ + { + "name": RECONCILE_TASK_NAME, + "task_name": "dashboard_metrics.aggregate_from_sources", + "queue": "dashboard_metric_events", + "task_args": [], + # Scoped to the tier it repairs. Without a tier this runs ALL, and its + # hourly half is pure duplicated work — the hourly tier always covers the + # last 24h regardless of source_window_days — while being the only thing + # that writes event_metrics_hourly concurrently with the */15 run, whose + # per-tier lock is deliberately unable to block it. + "task_kwargs": {"source_window_days": 7, "tier": "daily_monthly"}, + # Beat: CrontabSchedule(minute=40, hour=4, every day) UTC — clear of the + # 2:00 and 3:00 cleanup tasks, and off the aggregation's */15 grid + # (:00 :15 :30 :45). That separates the starts on the PG scheduler only: + # the Beat aggregation row is an IntervalSchedule (0002), which fires at + # last_run_at + 15min and drifts, so on that transport they can coincide. + "cron_string": "40 4 * * *", + }, +] + + +def _inherited_ownership(periodic_task_model, pg_periodic_task_model): + """Which scheduler fires the existing aggregation row, so this one matches. + + Hardcoding Beat would land the reconciliation pass with no firer wherever the + metrics periodics are already PG-adopted: the adopted row's Beat twin is + disabled and Beat may not be running at all. 0006 makes the same inference for + the row it adds; this pass is the only automatic repair for the narrowed source + window, so it is the worse one to strand. + """ + beat = periodic_task_model.objects.filter(name=EXISTING_AGGREGATE_ROW).first() + pg = pg_periodic_task_model.objects.filter(name=EXISTING_AGGREGATE_ROW).first() + return { + "beat_enabled": True if beat is None else beat.enabled, + "pg_enabled": True if pg is None else pg.enabled, + "pg_owned": False if pg is None else pg.pg_owned, + } + + +def create_reconciliation_task(apps, schema_editor): + """Create the once-daily reconciliation periodic task on both transports.""" + crontab_model = apps.get_model("django_celery_beat", "CrontabSchedule") + periodic_task_model = apps.get_model("django_celery_beat", "PeriodicTask") + pg_periodic_task_model = apps.get_model("pg_queue", "PgPeriodicTask") + owner = _inherited_ownership(periodic_task_model, pg_periodic_task_model) + + schedule_4am, _ = crontab_model.objects.get_or_create( + minute="40", + hour="4", + day_of_week="*", + day_of_month="*", + month_of_year="*", + defaults={"timezone": "UTC"}, + ) + + for spec in PG_PERIODIC_TASKS: + periodic_task_model.objects.update_or_create( + name=spec["name"], + defaults={ + "task": spec["task_name"], + "crontab": schedule_4am, + "queue": spec["queue"], + "kwargs": json.dumps(spec["task_kwargs"]), + "enabled": owner["beat_enabled"], + "description": RECONCILE_DESCRIPTION, + }, + ) + pg_periodic_task_model.objects.update_or_create( + name=spec["name"], + defaults={ + "task_name": spec["task_name"], + "queue": spec["queue"], + "task_args": spec["task_args"], + "task_kwargs": spec["task_kwargs"], + "cron_string": spec["cron_string"], + "org_id": "", + "enabled": owner["pg_enabled"], + # Inherited, not hardcoded: see _inherited_ownership. + "pg_owned": owner["pg_owned"], + }, + ) + + _bump_beat_change_tracker(apps) + + +def remove_reconciliation_task(apps, schema_editor): + """Remove the reconciliation periodic task from both transports.""" + names = [spec["name"] for spec in PG_PERIODIC_TASKS] + apps.get_model("django_celery_beat", "PeriodicTask").objects.filter( + name__in=names + ).delete() + apps.get_model("pg_queue", "PgPeriodicTask").objects.filter(name__in=names).delete() + _bump_beat_change_tracker(apps) + + +def _bump_beat_change_tracker(apps): + """Make a running Beat reload instead of missing the new schedule. + + django-celery-beat's post_save receiver binds the concrete PeriodicTask, so + writes through a historical model never bump PeriodicTasks.last_update and + DatabaseScheduler keeps its stale in-memory copy. Same fix and reason as + scheduler/ownership.py and mirror_pg_periodic_tasks.py. + """ + periodic_tasks_model = apps.get_model("django_celery_beat", "PeriodicTasks") + periodic_tasks_model.objects.update_or_create( + ident=1, defaults={"last_update": timezone.now()} + ) + + +class Migration(migrations.Migration): + dependencies = [ + ("dashboard_metrics", "0004_pg_periodic_tasks"), + ("django_celery_beat", "0018_improve_crontab_helptext"), + ("pg_queue", "0003_pgperiodictask"), + ] + + operations = [ + migrations.RunPython( + create_reconciliation_task, + remove_reconciliation_task, + ), + ] diff --git a/backend/dashboard_metrics/migrations/0006_split_aggregation_schedule.py b/backend/dashboard_metrics/migrations/0006_split_aggregation_schedule.py new file mode 100644 index 0000000000..9d9fdc376d --- /dev/null +++ b/backend/dashboard_metrics/migrations/0006_split_aggregation_schedule.py @@ -0,0 +1,240 @@ +"""Split the metrics aggregation into two schedules by tier (UN-3974). + +The hourly tier keeps its 15-minute cadence; the daily and monthly tiers move to +hourly, taking the expensive DAY-granularity half of the work from 96 runs a day to +24, plus the once-daily reconciliation pass 0005 adds. Both rows run the same task and differ only in their ``tier`` kwargs — a second +task name would need its own worker registration and internal endpoint. + +Beat and PG rows are declared here from one spec, so this pair cannot drift the way +0002 and 0004 can. Beat stores kwargs as a JSON string, PgPeriodicTask decoded. The +new row inherits whichever scheduler owns the row it is split from, rather than +hardcoding Beat: it is one half of that row, and the same process should fire it. + +The new row runs at minute 20, off the ``*/15`` grid. The hourly-tier run's per-tier +lock is deliberately unable to block it, so what keeps the two apart is the schedule +— on the PG scheduler, whose consumer also runs one at a time. On Beat nothing +serialises them: the surviving row is an IntervalSchedule whose phase drifts, and the +Celery consumer is not pinned to one worker. The overlap costs duplicated source +reads, not wrong numbers, since every write is an idempotent upsert. See the note +beside the new row's ``cron_string``. + +**Rolling back the code past this release requires reversing this migration first, +from the outgoing image.** After it runs both scheduler rows carry a ``tier`` kwarg +that the previous release's zero-argument signatures reject with ``TypeError``, which +``autoretry_for`` does not cover — aggregation stops for every tier until the rows are +restored. + +Order matters, and the reverse is not available afterwards: this file and 0005 do not +exist in the previous release, so once that image is deployed ``migrate`` has no node +to reverse to and reports nothing to apply. Run the reverse **before** rolling the +image back:: + + python manage.py migrate dashboard_metrics 0004 + +0004, not 0005: 0005 adds the reconciliation row carrying ``source_window_days``, +which the previous release's signatures reject the same way, so stopping at 0005 +leaves that row failing once a day indefinitely. +""" + +import json + +from django.db import migrations +from django.utils import timezone + +AGGREGATE_TASK_NAME = "dashboard_metrics.aggregate_from_sources" +AGGREGATE_QUEUE = "dashboard_metric_events" + +# Frozen wire values, not a copy to keep in step with the enum. These are written +# into rows this migration never re-runs against, so editing them to follow a rename +# of AggregationTier changes nothing in production and every test stays green while +# live rows still carry the old string — the task then raises ValueError on every +# run. Renaming an AggregationTier value needs a NEW data migration that rewrites the +# rows; this file is a record of what was written on the day it ran. +TIER_HOURLY = "hourly" +TIER_DAILY_MONTHLY = "daily_monthly" + +# Created by 0002 / 0004; only its kwargs and description change here. +EXISTING_AGGREGATE_ROW = "dashboard_metrics_aggregate_from_sources" + +AGGREGATION_SCHEDULES = [ + { + "name": EXISTING_AGGREGATE_ROW, + "tier": TIER_HOURLY, + "cron_string": "*/15 * * * *", + "crontab": {"minute": "*/15", "hour": "*"}, + "description": ( + "Aggregate the hourly dashboard metrics tier from source tables " + "(Usage, PageUsage, WorkflowExecution, etc.)" + ), + "exists": True, + }, + { + "name": "dashboard_metrics_aggregate_daily_monthly", + "tier": TIER_DAILY_MONTHLY, + # Off the */15 grid (:00 :15 :30 :45): the per-tier locks are built so the + # two runs cannot block each other, so a shared minute means two full + # prefilter scans and two per-org loops at once. + # + # This separates the two starts on the PG scheduler, which evaluates + # cron_string against the wall clock. It does NOT on Beat, where 0002 gave + # the row an IntervalSchedule: that fires at last_run_at + 15min, so its + # phase is wherever the previous run landed and re-anchors on restart. + # Nothing serialises the Celery path — see the module docstring. + "cron_string": "20 * * * *", + "crontab": {"minute": "20", "hour": "*"}, + "description": ( + "Aggregate the daily and monthly dashboard metrics tiers from source " + "tables — hourly, since these figures do not need 15-minute freshness" + ), + "exists": False, + }, +] + + +def _inherited_ownership(periodic_task_model, pg_periodic_task_model): + """Which scheduler fires the row being split, so its other half matches. + + Hardcoding Beat would leave the daily/monthly tier with no firer wherever the + metrics periodics are already PG-adopted: the adopted row's Beat twin is disabled + and Beat may not be running at all. + """ + beat = periodic_task_model.objects.filter(name=EXISTING_AGGREGATE_ROW).first() + pg = pg_periodic_task_model.objects.filter(name=EXISTING_AGGREGATE_ROW).first() + return { + "beat_enabled": True if beat is None else beat.enabled, + "pg_enabled": True if pg is None else pg.enabled, + "pg_owned": False if pg is None else pg.pg_owned, + } + + +def split_schedules(apps, schema_editor): + CrontabSchedule = apps.get_model("django_celery_beat", "CrontabSchedule") + PeriodicTask = apps.get_model("django_celery_beat", "PeriodicTask") + PgPeriodicTask = apps.get_model("pg_queue", "PgPeriodicTask") + owner = _inherited_ownership(PeriodicTask, PgPeriodicTask) + + for spec in AGGREGATION_SCHEDULES: + kwargs = {"tier": spec["tier"]} + + if spec["exists"]: + # Payload only. `enabled` and `pg_owned` say which scheduler fires this + # row and belong to converge_pg_scheduler; rewriting them here can leave + # an adopted row with no firer. Its cadence does not change. + # + # A count of 0 means no row of that name exists — and a transport with + # no row fires nothing, so there is no old row left on kwargs="{}" to + # double up with the new one. Create it instead of aborting: raising + # here fails `migrate` for EVERY app, and recovery means hand-inserting + # a row into an operator-editable scheduler table. + beat_updated = PeriodicTask.objects.filter(name=spec["name"]).update( + kwargs=json.dumps(kwargs), description=spec["description"] + ) + pg_updated = PgPeriodicTask.objects.filter(name=spec["name"]).update( + task_kwargs=kwargs + ) + if beat_updated and pg_updated: + continue + # A transport missing the row fires nothing, so there is nothing to + # double up with — fall through and create it, rather than aborting + # `migrate` for every app in the project. + + schedule, _ = CrontabSchedule.objects.get_or_create( + minute=spec["crontab"]["minute"], + hour=spec["crontab"]["hour"], + day_of_week="*", + day_of_month="*", + month_of_year="*", + defaults={"timezone": "UTC"}, + ) + PeriodicTask.objects.update_or_create( + name=spec["name"], + defaults={ + "task": AGGREGATE_TASK_NAME, + "crontab": schedule, + # Cleared explicitly: 0002 created this row on an IntervalSchedule, + # and django-celery-beat rejects a row carrying both on any later + # save. The historical model has no such validation, so the row + # would be written here and only raise later, through the admin. + # Beat also reads `interval` first, so the new crontab would be + # inert until then. + "interval": None, + "queue": AGGREGATE_QUEUE, + "kwargs": json.dumps(kwargs), + "enabled": owner["beat_enabled"], + "description": spec["description"], + }, + ) + PgPeriodicTask.objects.update_or_create( + name=spec["name"], + defaults={ + "task_name": AGGREGATE_TASK_NAME, + "queue": AGGREGATE_QUEUE, + "task_args": [], + "task_kwargs": kwargs, + "cron_string": spec["cron_string"], + "org_id": "", + "enabled": owner["pg_enabled"], + "pg_owned": owner["pg_owned"], + }, + ) + + _bump_beat_change_tracker(apps) + + +def merge_schedules(apps, schema_editor): + """Restore the single every-15-minutes row that writes all three tiers. + + Leaves `enabled` / `pg_owned` alone, as the forward direction does. + """ + PeriodicTask = apps.get_model("django_celery_beat", "PeriodicTask") + PgPeriodicTask = apps.get_model("pg_queue", "PgPeriodicTask") + + added = [s["name"] for s in AGGREGATION_SCHEDULES if not s["exists"]] + PeriodicTask.objects.filter(name__in=added).delete() + PgPeriodicTask.objects.filter(name__in=added).delete() + + beat_restored = PeriodicTask.objects.filter(name=EXISTING_AGGREGATE_ROW).update( + kwargs="{}", + description=( + "Aggregate metrics from source tables (Usage, PageUsage, etc.) " + "into hourly, daily, and monthly metrics tables" + ), + ) + pg_restored = PgPeriodicTask.objects.filter(name=EXISTING_AGGREGATE_ROW).update( + task_kwargs={} + ) + if not beat_restored or not pg_restored: + raise RuntimeError( + f"{EXISTING_AGGREGATE_ROW}: expected a row on both schedulers to restore, " + f"found beat={beat_restored} pg={pg_restored}. The rollback would leave " + "the daily and monthly tiers with no schedule." + ) + _bump_beat_change_tracker(apps) + + +def _bump_beat_change_tracker(apps): + """Make a running Beat reload instead of keeping the pre-split schedule. + + django-celery-beat's post_save receiver binds the concrete PeriodicTask, so writes + through a historical model never bump PeriodicTasks.last_update and + DatabaseScheduler keeps its in-memory copy: the existing row would go on firing + with no tier and the new row would never fire at all — the whole saving silently + not happening. Same fix and reason as scheduler/ownership.py and + mirror_pg_periodic_tasks.py. + """ + periodic_tasks_model = apps.get_model("django_celery_beat", "PeriodicTasks") + periodic_tasks_model.objects.update_or_create( + ident=1, defaults={"last_update": timezone.now()} + ) + + +class Migration(migrations.Migration): + dependencies = [ + ("dashboard_metrics", "0005_add_reconciliation_task"), + ("django_celery_beat", "0018_improve_crontab_helptext"), + ("pg_queue", "0003_pgperiodictask"), + ] + + operations = [ + migrations.RunPython(split_schedules, merge_schedules), + ] diff --git a/backend/dashboard_metrics/models.py b/backend/dashboard_metrics/models.py index 2bc4baf6ac..9125208a3a 100644 --- a/backend/dashboard_metrics/models.py +++ b/backend/dashboard_metrics/models.py @@ -144,7 +144,7 @@ class EventMetricsDaily(DefaultOrganizationMixin, BaseModel): """Daily aggregated metrics for dashboard display. Stores metric events aggregated by day for efficient querying. - Pre-computed by the scheduled aggregation task every 15 minutes. + Pre-computed by the scheduled aggregation task's daily/monthly pass. Attributes: id: UUID primary key @@ -241,7 +241,7 @@ class EventMetricsMonthly(DefaultOrganizationMixin, BaseModel): """Monthly aggregated metrics for dashboard display. Stores metric events aggregated by month for efficient querying. - Pre-computed by the scheduled aggregation task every 15 minutes. + Rolled up from the daily tier by the aggregation task's daily/monthly pass. Attributes: id: UUID primary key diff --git a/backend/dashboard_metrics/tasks.py b/backend/dashboard_metrics/tasks.py index 181c985137..a5dbba5ce4 100644 --- a/backend/dashboard_metrics/tasks.py +++ b/backend/dashboard_metrics/tasks.py @@ -6,14 +6,21 @@ - cleanup_daily_metrics: Remove daily metrics older than retention period """ +import calendar import logging import time -from datetime import datetime, timedelta +from collections.abc import Callable +from datetime import date, datetime, timedelta +from enum import StrEnum from typing import Any +from uuid import uuid4 from account_v2.models import Organization from celery import shared_task +from celery.exceptions import SoftTimeLimitExceeded from django.core.cache import cache +from django.db.models import Count, F, Min, OuterRef, Subquery, Sum +from django.db.models.functions import TruncMonth from django.db.utils import DatabaseError, OperationalError from django.utils import timezone from workflow_manager.workflow_v2.models.execution import WorkflowExecution @@ -29,10 +36,35 @@ logger = logging.getLogger(__name__) +# Django 4.2's PostgreSQL backend does not override bulk_batch_size, so an +# unbatched bulk_create emits one statement whose size scales with tenant count. +MONTHLY_ROLLUP_BATCH_SIZE = 1000 + +# Cap on the under-count report: a fleet-wide daily loss would otherwise name every +# (organization, month) pair in one log line and one JSON body. +LOWERED_MONTHS_REPORT_LIMIT = 20 + # Retention periods for metrics cleanup DASHBOARD_HOURLY_METRICS_RETENTION_DAYS = 30 DASHBOARD_DAILY_METRICS_RETENTION_DAYS = 365 +# Daily-tier source lookback, sized against the worst observed +# created_at -> terminal-status lag. +DASHBOARD_SOURCE_WINDOW_DAYS = 2 + +# Wider lookback for the once-daily reconciliation pass. A migration must not +# import live app code, so 0005_add_reconciliation_task carries this as a literal +# in the schedule row's kwargs — editing this constant does not move the schedule. +DASHBOARD_RECONCILE_WINDOW_DAYS = 7 + +# Floor on the prefilter lookback. _active_org_ids takes the wider of this and the +# run's own window, so a widened source_window_days is never prefiltered back down. +# It does NOT rescue a metric keyed on another column: get_hitl_completions windows +# on approved_at, so an org approving today with no execution inside the floor is +# still absent from the run. Widening a created_at lookback cannot reach it — only +# unioning the shortlist with those orgs would. +DASHBOARD_ACTIVE_ORG_LOOKBACK_DAYS = 7 + def _upsert_agg(agg: dict, key: tuple, metric_type: str, value: float) -> None: """Add a value to an aggregation dict, creating the entry if needed.""" @@ -58,9 +90,14 @@ def _truncate_to_hour(ts: float | datetime) -> datetime: return dt.replace(minute=0, second=0, microsecond=0) -def _truncate_to_day(ts: datetime) -> datetime: +def truncate_to_day(ts: datetime) -> datetime: """Truncate a datetime to midnight (start of day). + Public because backfill_metrics shares it: the day boundary is a contract + between the cron and the repair command, not an internal of either. An + untruncated boundary writes the oldest day as a partial bucket, which the + monthly rollup then makes permanent. + Args: ts: datetime object @@ -165,89 +202,366 @@ def _bulk_upsert_daily(aggregations: dict) -> int: return len(objects) -def _bulk_upsert_monthly(aggregations: dict) -> int: - """Bulk upsert monthly aggregations using INSERT ... ON CONFLICT. +def _upsert_monthly(objects: list[EventMetricsMonthly]) -> int: + """Upsert one batch of derived monthly rows.""" + EventMetricsMonthly._base_manager.bulk_create( + objects, + update_conflicts=True, + unique_fields=["organization", "month", "metric_name", "project", "tag"], + update_fields=["metric_type", "metric_value", "metric_count"], + batch_size=MONTHLY_ROLLUP_BATCH_SIZE, + ) + return len(objects) - Uses _base_manager to bypass DefaultOrganizationManagerMixin. - Args: - aggregations: Dict keyed by (org_id, month_str, metric_name, project, tag) +def _pairs_the_rollup_would_lower(month_start: date) -> list[tuple]: + """Conflict keys whose monthly total the pending rollup would reduce. - Returns: - Number of rows upserted + Run before the upsert, while the stored value is still the old one, and + evaluated in the database: one statement returning only the offending pairs, + which in a healthy install is none. + + Materialising the old and new totals in Python would have compared the same + thing, but it scales with tenant x metric x project x tag — the axis the + streaming rollup below exists to keep off the heap. + + Compared at the grain the rollup writes at, because that is the grain the damage + occurs at: one tenant's metric can lose days while every other tenant covers + them. A fleet-wide count of missing dates misses exactly that, and flags an idle + day or a fresh install, where nothing is wrong, as if it were damage. """ - objects = [] - for key, agg in aggregations.items(): - org_id, month_str, metric_name, project, tag = key - objects.append( + new_total = Subquery( + EventMetricsDaily._base_manager.filter( + organization_id=OuterRef("organization_id"), + metric_name=OuterRef("metric_name"), + project=OuterRef("project"), + tag=OuterRef("tag"), + date__gte=month_start, + ) + .annotate(bucket=TruncMonth("date")) + .filter(bucket=OuterRef("month")) + .values("bucket") + .annotate(total=Sum("metric_value")) + .values("total")[:1] + ) + # One conjunct, not two: SQL three-valued logic already drops a NULL new_total + # from `<`, and Django inlines the correlated subquery once per conjunct — so + # adding `new_total__isnull=False` doubles the per-row subplan executions and + # changes nothing. A month the daily tier no longer produces at all is left in + # place by the upsert, which is why NULL is not a lowering. + lowered = ( + EventMetricsMonthly._base_manager.filter(month__gte=month_start) + .annotate(new_total=new_total) + .filter(new_total__lt=F("metric_value")) + # The full conflict key, not just (org, month): the comparison is per metric, + # project and tag, so skipping at a coarser grain would freeze a metric whose + # own total is fine just because a sibling metric's is short. + .values_list("organization_id", "month", "metric_name", "project", "tag") + .order_by("month", "organization_id", "metric_name") + ) + return list(lowered) + + +def _months_missing_days(month_start: date) -> list[str]: + """Months in the rollup window whose daily tier is missing whole days. + + The companion to _pairs_the_rollup_would_lower, and neither covers the other's + cases. That one compares against a stored monthly total, so it is blind twice: + a month with no stored row yet — the first run of any calendar month — has + nothing to compare against, and once a short total IS stored it only ever grows, + so it is never "lowered" again. Both leave an under-count permanent and silent. + This reads the daily tier itself, so neither blind spot applies. + + Fleet-wide rather than per tenant, because that is the grain the cause has: a + missing day means the aggregation did not run, which affects every organisation + at once. Counted per tenant it would instead flag every organisation that was + merely idle that day, which is normal and constant. + + That grain is also the limit: one row from any tenant for any metric marks a + date covered, so a day lost by a single tenant or a single metric is invisible + here. `_pairs_the_rollup_would_lower` is what covers that case, and only where a + stored total actually falls — neither check sees a partial loss on a month with + no stored total. + + Whole days only, on both sides of the comparison. A date on which nothing ran + anywhere reads as a gap and will be reported for the rest of the window; that is + a false alarm this cannot distinguish from a real one without querying the + source tables, which is the load this whole change exists to remove. + """ + yesterday = timezone.now().date() - timedelta(days=1) + covered = ( + # Whole days on BOTH sides. Counting today while measuring against yesterday + # lets today's row cancel exactly one missing earlier day, which hides the + # single-missing-day case entirely once the day's first run has landed. + EventMetricsDaily._base_manager.filter(date__gte=month_start, date__lte=yesterday) + .annotate(month=TruncMonth("date")) + .values("month") + .annotate(days=Count("date", distinct=True)) + .order_by("month") + ) + + short = [] + for row in covered: + month = row["month"] + last_day = month.replace(day=calendar.monthrange(month.year, month.month)[1]) + last_complete = min(last_day, yesterday) + expected = (last_complete - month).days + 1 + if expected > 0 and row["days"] < expected: + short.append(f"{month:%Y-%m} ({row['days']}/{expected} days)") + return short + + +def _name_lowered_pairs(pairs: list[tuple]) -> list[str]: + """Render the pairs for a log line, capped. + + A fleet-wide daily loss makes this one entry per tenant per month, which would + otherwise be joined into a single log line and returned in a JSON body. + """ + seen = sorted({(org_id, month) for org_id, month, *_ in pairs}) + names = [f"{month:%Y-%m} (org {org_id})" for org_id, month in seen] + total = len(names) + if total > LOWERED_MONTHS_REPORT_LIMIT: + names = names[:LOWERED_MONTHS_REPORT_LIMIT] + # The total, not the cap: three affected tenants and four thousand read + # identically otherwise, and the count is what decides whether this is one + # tenant's gap or a fleet-wide one. + names.append(f"... and {total - LOWERED_MONTHS_REPORT_LIMIT} more of {total}") + return names + + +def _rollup_monthly_from_daily(month_start: date, skip: set | None = None) -> int: + """Sum the daily tier from month_start into monthly, for all orgs at once. + + Pairs in ``skip`` are left untouched: their stored total is higher than what the + daily tier now sums to, so rewriting them would replace a correct figure with a + known-short one. That is what makes the prescribed pre-deploy backfill a repair + step rather than a race against the first scheduled run — the schedule row 0006 + adds goes live at the end of ``migrate``, so the backfill cannot be sequenced + before it. + + Upsert-only, per the design agreed on UN-3973: a monthly row the daily tier + no longer produces *at all* is left in place rather than deleted. A stale total + is recoverable with backfill_metrics; a deleted one is not, because the daily + rows that would rebuild it are exactly what is missing. + + A month the daily tier covers only *partially* is a different case: date is not + a grouping key, so its sum is smaller than the stored total. Those rows reach + this function in ``skip`` and are left alone rather than overwritten — see + _pairs_the_rollup_would_lower, which needs a stored total to compare against, + and _months_missing_days, which does not. + + metric_type is aggregated rather than grouped: it is not part of + unique_monthly_metric, so grouping on it could yield two rows for one + conflict target. + + Streamed rather than materialised: the grouping spans every organization, so + holding the whole result and an equal-length list of model instances scales + with tenant count — and on the PG transport this runs inside a request worker. + """ + rows = ( + # NULLS DISTINCT: a NULL-org row never matches ON CONFLICT, so it would be + # re-inserted every run. Latent — but this reads the column, not a loop var. + EventMetricsDaily._base_manager.filter(date__gte=month_start) + .exclude(organization_id__isnull=True) + .annotate(month=TruncMonth("date")) + .values("organization_id", "month", "metric_name", "project", "tag") + .annotate( + value=Sum("metric_value"), + count=Sum("metric_count"), + mtype=Min("metric_type"), + ) + # Ordered so two concurrent rollups take row locks in the same sequence and + # block rather than deadlock. The aggregate emits no stable order otherwise. + .order_by("organization_id", "month", "metric_name", "project", "tag") + ) + + upserted = 0 + batch: list[EventMetricsMonthly] = [] + # One transaction per batch, not one across the whole scan. A fleet-wide + # transaction holds row locks on every rewritten monthly row until the cursor + # drains, and two runs that do not share a lock key — the :20 row and the 04:40 + # reconcile take different ones, namespaced by window — then contend for the + # winner's full rollup or deadlock. Each bulk_create is already one statement, + # so a batch is atomic without an explicit block. + # + # What that trades away is an all-or-nothing rewrite. Nothing needed it: every + # row written is correct as of this run, the upsert is idempotent, and a partial + # rollup is repaired on the next tick — the same tolerance the hourly and daily + # tiers in this function already accept. The merge-base had no transaction here + # at all; monthly was upserted per organization in autocommit. + skip = skip or set() + for row in rows.iterator(chunk_size=MONTHLY_ROLLUP_BATCH_SIZE): + key = ( + row["organization_id"], + row["month"], + row["metric_name"], + row["project"], + row["tag"], + ) + if key in skip: + # This row's stored total is higher than what the daily tier now sums to, + # so writing it would replace a good figure with a known-short one. Left + # alone until the daily tier is repaired; the caller warns. Scoped to the + # exact row, so a sibling metric that is fine still gets its update. + continue + batch.append( EventMetricsMonthly( - organization_id=org_id, - month=datetime.fromisoformat(month_str).date(), - metric_name=metric_name, - project=project, - tag=tag, - metric_type=agg["metric_type"], - metric_value=agg["value"], - metric_count=agg["count"], + organization_id=row["organization_id"], + month=row["month"], + metric_name=row["metric_name"], + project=row["project"], + tag=row["tag"], + metric_type=row["mtype"], + metric_value=row["value"], + metric_count=row["count"], ) ) + if len(batch) >= MONTHLY_ROLLUP_BATCH_SIZE: + upserted += _upsert_monthly(batch) + batch = [] + if batch: + upserted += _upsert_monthly(batch) - if not objects: - return 0 + return upserted - EventMetricsMonthly._base_manager.bulk_create( - objects, - update_conflicts=True, - unique_fields=["organization", "month", "metric_name", "project", "tag"], - update_fields=["metric_type", "metric_value", "metric_count"], - ) - return len(objects) +class AggregationTier(StrEnum): + """Which metric tiers one aggregation run writes. -AGGREGATION_LOCK_KEY = "dashboard_metrics:aggregation_lock" -AGGREGATION_LOCK_TIMEOUT = 900 # 15 minutes (matches task schedule) + Daily and monthly stay together because monthly is rolled up from the daily tier. + """ + HOURLY = "hourly" + DAILY_MONTHLY = "daily_monthly" + ALL = "all" -def _acquire_aggregation_lock() -> bool: - """Acquire the distributed aggregation lock with self-healing. - Stores a Unix timestamp as the lock value. If a previous run crashed - (OOM kill, SIGKILL) without releasing the lock, the next run detects - that the lock is older than AGGREGATION_LOCK_TIMEOUT and reclaims it. +# Which granularities each tier writes. One table rather than a predicate per +# granularity: add a member without an entry here and _tiers_written raises on the +# first run, instead of the run acquiring its lock, iterating every org, writing +# nothing and returning success. +_TIER_WRITES: dict[AggregationTier, frozenset[str]] = { + AggregationTier.HOURLY: frozenset({AggregationTier.HOURLY.value}), + AggregationTier.DAILY_MONTHLY: frozenset({AggregationTier.DAILY_MONTHLY.value}), + AggregationTier.ALL: frozenset( + {AggregationTier.HOURLY.value, AggregationTier.DAILY_MONTHLY.value} + ), +} - Returns: - True if lock was acquired, False if another run is legitimately active. - """ - now = time.time() - # Fast path: lock is free - if cache.add(AGGREGATION_LOCK_KEY, str(now), AGGREGATION_LOCK_TIMEOUT): - return True +def _tiers_written(tier: AggregationTier) -> frozenset[str]: + """The granularities one tier writes. Unhandled members raise rather than no-op.""" + try: + return _TIER_WRITES[tier] + except KeyError: + raise AssertionError(f"Unhandled AggregationTier: {tier!r}") from None + + +def _writes_hourly(tier: AggregationTier) -> bool: + return AggregationTier.HOURLY.value in _tiers_written(tier) + - # Lock exists — check if it's stale (previous run died without releasing) - lock_value = cache.get(AGGREGATION_LOCK_KEY) - if lock_value is None: - # Expired between our check and get — lock is now free, try to acquire it - return cache.add(AGGREGATION_LOCK_KEY, str(now), AGGREGATION_LOCK_TIMEOUT) +def _writes_daily_monthly(tier: AggregationTier) -> bool: + return AggregationTier.DAILY_MONTHLY.value in _tiers_written(tier) + +AGGREGATION_LOCK_KEY_PREFIX = "dashboard_metrics:aggregation_lock" +# Expiry is the only recovery path, so this ordering is the whole guarantee. Equal to +# the shortest schedule period, not under it, so a leaked lock frees exactly on the +# next tick rather than before it. The Celery ceilings (time_limit 660s) sit below it +# but bound only that transport — the internal-HTTP path calls the task body directly, +# where the ceiling is gunicorn's request timeout instead. +AGGREGATION_LOCK_TIMEOUT = 900 + + +def _aggregation_lock_keys(tier: AggregationTier, source_window_days: int) -> list[str]: + """One key per granularity written, namespaced by source window. + + Per granularity, not per enum member: keying on the label alone gives ALL a third + key that excludes nothing, so an ALL run and the scheduled hourly run would write + EventMetricsHourly concurrently. Taking one key per granularity restores that + exclusion between runs sharing a window, and the two scheduled tiers still never + block. Across windows it does not exclude — see the next paragraph. + + Per window because a wider window is a different job. The reconciliation pass runs + once a day on a fixed crontab against a drifting 15-minute interval; on a shared + key it would lose the race, return skipped=True and never be retried — and it is + the only thing that repairs the narrowed window. Both are idempotent upserts, so + that once-a-day overlap costs duplicated work at worst. + """ + return [ + f"{AGGREGATION_LOCK_KEY_PREFIX}:{source_window_days}d:{granularity}" + for granularity in sorted(_tiers_written(tier)) + ] + + +def _acquire_aggregation_locks(lock_keys: list[str]) -> tuple[list[str], str]: + """Take every key or none. Returns the keys taken and this run's owner token.""" + token = uuid4().hex + taken: list[str] = [] try: - lock_time = float(lock_value) - except (TypeError, ValueError): - # Corrupted value (e.g. old "running" string) — reclaim it - logger.warning("Reclaiming aggregation lock with invalid value: %s", lock_value) - cache.delete(AGGREGATION_LOCK_KEY) - return cache.add(AGGREGATION_LOCK_KEY, str(now), AGGREGATION_LOCK_TIMEOUT) - - age = now - lock_time - if age > AGGREGATION_LOCK_TIMEOUT: - logger.warning( - "Reclaiming stale aggregation lock (age=%.0fs, timeout=%ds)", - age, - AGGREGATION_LOCK_TIMEOUT, - ) - cache.delete(AGGREGATION_LOCK_KEY) - return cache.add(AGGREGATION_LOCK_KEY, str(now), AGGREGATION_LOCK_TIMEOUT) + for key in lock_keys: + if not _acquire_aggregation_lock(key, token): + _release_aggregation_locks(taken, token) + return [], token + taken.append(key) + except Exception: + # A cache fault partway through would otherwise strand the keys already + # taken for the full TTL, blocking every tier this run was going to write. + _release_aggregation_locks(taken, token) + raise + return taken, token + + +def _lock_owner(lock_key: str) -> str | None: + """The token holding a lock, or None if it is free or holds a legacy value.""" + value = cache.get(lock_key) + if isinstance(value, str) and ":" in value: + return value.split(":", 1)[0] + return None + + +def _release_aggregation_locks(lock_keys: list[str], token: str) -> None: + """Release only the keys this run still owns. + + Without the ownership check, a run whose lock had already expired would delete + whichever run took the key next, letting a third in immediately. + + This narrows that window to one cache round trip rather than closing it: the + read and the delete are separate calls and Django's cache API has no + compare-and-delete. Bounded, because the writes on either side are idempotent + upserts — a compare-and-delete would need a Redis-specific Lua eval. + """ + for key in lock_keys: + try: + if _lock_owner(key) == token: + cache.delete(key) + except Exception: + logger.exception("Failed to release aggregation lock %s", key) + +def _acquire_aggregation_lock(lock_key: str, token: str) -> bool: + """Acquire one aggregation lock, storing this run's token with the timestamp. + + A crashed run (OOM kill, SIGKILL) is recovered by the key's own + AGGREGATION_LOCK_TIMEOUT TTL, and that is the only recovery path. + + Never reclaimed by age. Reading a value, judging it stale and replacing it is + not atomic — two runs can both read the same timestamp, both delete and both + add, the second wiping the first's fresh lock while both believe they hold it. + The age check could not tell a live holder from a dead one anyway, since it + compares a local clock against another worker's. + + Exclusion does not span the key format. These keys are new in this release, so + a run on the previous image holds a different key and neither blocks the other; + the overlap is bounded by the rollout. + + Returns: + True if the lock was acquired, False if another run is legitimately active. + """ + if cache.add(lock_key, f"{token}:{time.time()}", AGGREGATION_LOCK_TIMEOUT): + return True + # Anything already here belongs to a run this code did not start. return False @@ -260,330 +574,541 @@ def _acquire_aggregation_lock() -> bool: retry_backoff=True, retry_backoff_max=300, ) -def aggregate_metrics_from_sources() -> dict[str, Any]: - """Aggregate metrics from source tables into hourly, daily, and monthly tables. - - This task runs periodically (every 15 minutes) to query metrics from - source tables (Usage, PageUsage, WorkflowExecution, etc.) and aggregate - them into EventMetricsHourly, EventMetricsDaily, and EventMetricsMonthly - tables for fast dashboard queries at different granularities. +def aggregate_metrics_from_sources( + tier: str = AggregationTier.ALL, + source_window_days: int = DASHBOARD_SOURCE_WINDOW_DAYS, + **_ignored: Any, +) -> dict[str, Any]: + """Aggregate source tables into the hourly, daily and monthly tiers. - Uses a Redis distributed lock with self-healing to prevent overlapping - runs. If a previous run was killed without releasing the lock, the next - run detects the stale lock and reclaims it automatically. + Three schedules call this: the hourly tier every 15 minutes, the daily and + monthly tiers hourly at :20, and a once-daily reconciliation pass over the + daily and monthly tiers at a wider window. Hourly covers the last 24h, daily the source window, + monthly is rolled up from daily. - Aggregation windows: - - Hourly: Last 24 hours (rolling window) - - Daily: Last 7 days (ensures we capture late-arriving data) - - Monthly: Last 2 months (current + previous month) + Args: + tier: An AggregationTier value. Defaults to all, so a caller that omits it + — a schedule row written before 0006 — writes every tier rather than + none. + source_window_days: Daily-tier source lookback. The reconciliation pass + reruns this task at DASHBOARD_RECONCILE_WINDOW_DAYS to repair gaps + after downtime. + _ignored: Unknown kwargs are accepted rather than rejected. This does NOT + protect the deploy that introduces a kwarg — a pod on the previous image + has the old signature and still raises TypeError; that window is bounded + by the rollout. What it buys is that a LATER release may add a kwarg to a + schedule row without breaking pods still running this one. Dropped keys + are logged, because the same tolerance would otherwise hide a typo. Returns: - Dict with aggregation summary for all three tiers + Dict with aggregation summary for the tiers that ran + + Raises: + ValueError: tier is not a recognised AggregationTier, or the window is not + an integer between 1 and MAX_SOURCE_WINDOW_DAYS """ - if not _acquire_aggregation_lock(): - logger.info("Skipping aggregation — another run is in progress") - return {"success": True, "skipped": True, "reason": "lock_held"} + if _ignored: + # Tolerated for the rolling-deploy case above, but an unrecognised key is far + # more often a typo in an editable schedule row — and a reconciliation row + # whose window kwarg is misspelled silently runs at the 2-day default. + logger.warning("Ignoring unrecognised aggregation kwargs: %s", sorted(_ignored)) + tier = AggregationTier(tier) + source_window_days = _validate_source_window(source_window_days) + lock_keys = _aggregation_lock_keys(tier, source_window_days) + + held, token = _acquire_aggregation_locks(lock_keys) + if not held: + logger.warning( + "Skipping the %s aggregation over %d day(s) — another run writing the " + "same tier is in progress", + tier.value, + source_window_days, + ) + return { + "success": True, + "skipped": True, + "reason": "lock_held", + "tier": tier.value, + "source_window_days": source_window_days, + } try: - return _run_aggregation() + return _run_aggregation(tier, source_window_days) finally: - cache.delete(AGGREGATION_LOCK_KEY) + # Isolated per key: a raise here would replace the run's return value, reporting + # a completed aggregation as a hard failure, and would strand the keys after it. + # The TTL bounds whatever is not released. + _release_aggregation_locks(held, token) def _aggregate_single_metric( query_method, + *, metric_name: str, metric_type: str, org_id: str, hourly_start: datetime, daily_start: datetime, - monthly_start: datetime, end_date: datetime, hourly_agg: dict, daily_agg: dict, - monthly_agg: dict, + tier: AggregationTier, extra_kwargs: dict | None = None, ) -> None: - """Run a single metric query at all 3 granularities and populate agg dicts. - - Uses 2 queries instead of 3: the daily query is widened to monthly_start - and its results are split into both daily_agg and monthly_agg in Python. - This is the same pattern proven in the backfill management command. - """ + """Run a single metric query at the granularities this run writes.""" extra_kwargs = extra_kwargs or {} # === HOURLY (last 24h) === - for row in query_method( - org_id, - hourly_start, - end_date, - granularity=Granularity.HOUR, - **extra_kwargs, - ): - hour_ts = _truncate_to_hour(row["period"]) - key = (org_id, hour_ts.isoformat(), metric_name, "default", "") - _upsert_agg(hourly_agg, key, metric_type, row["value"] or 0) + if _writes_hourly(tier): + for row in query_method( + org_id, + hourly_start, + end_date, + granularity=Granularity.HOUR, + **extra_kwargs, + ): + hour_ts = _truncate_to_hour(row["period"]) + key = (org_id, hour_ts.isoformat(), metric_name, "default", "") + _upsert_agg(hourly_agg, key, metric_type, row["value"] or 0) + + # === DAILY (monthly is rolled up from it, so one query feeds both) === + if not _writes_daily_monthly(tier): + return - # === DAILY + MONTHLY (single query from monthly_start) === for row in query_method( org_id, - monthly_start, + daily_start, end_date, granularity=Granularity.DAY, **extra_kwargs, ): - value = row["value"] or 0 - day_ts = _truncate_to_day(row["period"]) - - if day_ts >= daily_start: - key = (org_id, day_ts.date().isoformat(), metric_name, "default", "") - _upsert_agg(daily_agg, key, metric_type, value) - - month_key = _truncate_to_month(row["period"]).date().isoformat() - key = (org_id, month_key, metric_name, "default", "") - _upsert_agg(monthly_agg, key, metric_type, value) + day_ts = truncate_to_day(row["period"]) + key = (org_id, day_ts.date().isoformat(), metric_name, "default", "") + _upsert_agg(daily_agg, key, metric_type, row["value"] or 0) def _aggregate_llm_combined( org_id: str, + *, hourly_start: datetime, daily_start: datetime, - monthly_start: datetime, end_date: datetime, hourly_agg: dict, daily_agg: dict, - monthly_agg: dict, llm_combined_fields: dict, + tier: AggregationTier, ) -> None: - """Run the combined LLM metrics query at all granularities. + """Run the combined LLM metrics query at the granularities this run writes. - Issues 2 queries total (hourly + daily/monthly) instead of 3. - The DAY-granularity query is widened to monthly_start and results are - split into daily_agg (recent rows) and monthly_agg (all rows bucketed - by month) in Python. Same pattern as _aggregate_single_metric. + Two queries covering four metrics. """ # === HOURLY (last 24h) === - for row in MetricsQueryService.get_llm_metrics_combined( - org_id, - hourly_start, - end_date, - granularity=Granularity.HOUR, - ): - ts_str = _truncate_to_hour(row["period"]).isoformat() - for field, (metric_name, metric_type) in llm_combined_fields.items(): - key = (org_id, ts_str, metric_name, "default", "") - _upsert_agg(hourly_agg, key, metric_type, row[field] or 0) + if _writes_hourly(tier): + for row in MetricsQueryService.get_llm_metrics_combined( + org_id, + hourly_start, + end_date, + granularity=Granularity.HOUR, + ): + ts_str = _truncate_to_hour(row["period"]).isoformat() + for field, (metric_name, metric_type) in llm_combined_fields.items(): + key = (org_id, ts_str, metric_name, "default", "") + _upsert_agg(hourly_agg, key, metric_type, row[field] or 0) + + # === DAILY === + if not _writes_daily_monthly(tier): + return - # === DAILY + MONTHLY (single query from monthly_start) === for row in MetricsQueryService.get_llm_metrics_combined( org_id, - monthly_start, + daily_start, end_date, granularity=Granularity.DAY, ): - day_ts = _truncate_to_day(row["period"]) - month_key = _truncate_to_month(row["period"]).date().isoformat() - + day_str = truncate_to_day(row["period"]).date().isoformat() for field, (metric_name, metric_type) in llm_combined_fields.items(): - value = row[field] or 0 + key = (org_id, day_str, metric_name, "default", "") + _upsert_agg(daily_agg, key, metric_type, row[field] or 0) + + +# Metric definitions: (name, query_method, is_histogram) +# Note: llm_calls, challenges, summarization_calls, and llm_usage are +# handled separately via get_llm_metrics_combined (1 query instead of 4). +METRIC_CONFIGS = [ + ("documents_processed", MetricsQueryService.get_documents_processed, False), + ("pages_processed", MetricsQueryService.get_pages_processed, True), + ("deployed_api_requests", MetricsQueryService.get_deployed_api_requests, False), + ("etl_pipeline_executions", MetricsQueryService.get_etl_pipeline_executions, False), + ("prompt_executions", MetricsQueryService.get_prompt_executions, False), + ("failed_pages", MetricsQueryService.get_failed_pages, True), + ("hitl_reviews", MetricsQueryService.get_hitl_reviews, False), + ("hitl_completions", MetricsQueryService.get_hitl_completions, False), +] + +# LLM metrics combined via conditional aggregation (4 metrics in 1 query). +# Maps combined query field -> (metric_name, metric_type) +LLM_COMBINED_FIELDS = { + "llm_calls": ("llm_calls", MetricType.COUNTER), + "challenges": ("challenges", MetricType.COUNTER), + "summarization_calls": ("summarization_calls", MetricType.COUNTER), + "llm_usage": ("llm_usage", MetricType.HISTOGRAM), +} + + +def _collect_org_metrics( + org: Organization, + *, + hourly_start: datetime, + daily_start: datetime, + end_date: datetime, + tier: AggregationTier, +) -> tuple[dict, dict, int]: + """Query every metric for one org into hourly/daily aggregates. + + A failing metric is logged and counted, leaving the rest to proceed. + + Returns: + Tuple of (hourly aggregations, daily aggregations, error count) + """ + org_id = str(org.id) + hourly_agg: dict[tuple, dict] = {} + daily_agg: dict[tuple, dict] = {} + errors = 0 + + for metric_name, query_method, is_histogram in METRIC_CONFIGS: + metric_type = MetricType.HISTOGRAM if is_histogram else MetricType.COUNTER + # Pre-resolved identifier spares PageUsage a lookup per call. + extra_kwargs = ( + {"org_identifier": org.organization_id} + if metric_name == "pages_processed" + else {} + ) + try: + _aggregate_single_metric( + query_method, + metric_name=metric_name, + metric_type=metric_type, + org_id=org_id, + hourly_start=hourly_start, + daily_start=daily_start, + end_date=end_date, + hourly_agg=hourly_agg, + daily_agg=daily_agg, + tier=tier, + extra_kwargs=extra_kwargs, + ) + except SoftTimeLimitExceeded: + # Ahead of the broad catch: it subclasses Exception, and swallowing it + # defeats the soft limit's whole purpose. + raise + except Exception: + logger.exception("Error querying %s for org %s", metric_name, org_id) + errors += 1 + + try: + _aggregate_llm_combined( + org_id, + hourly_start=hourly_start, + daily_start=daily_start, + end_date=end_date, + hourly_agg=hourly_agg, + daily_agg=daily_agg, + llm_combined_fields=LLM_COMBINED_FIELDS, + tier=tier, + ) + except SoftTimeLimitExceeded: + raise + except Exception: + logger.exception("Error querying combined LLM metrics for org %s", org_id) + errors += 1 + + return hourly_agg, daily_agg, errors + + +def _aggregate_org( + org: Organization, + *, + hourly_start: datetime, + daily_start: datetime, + end_date: datetime, + tier: AggregationTier, + stats: dict[str, Any], +) -> None: + """Aggregate one organization and upsert the tiers this run writes.""" + hourly_agg, daily_agg, errors = _collect_org_metrics( + org, + hourly_start=hourly_start, + daily_start=daily_start, + end_date=end_date, + tier=tier, + ) + stats["errors"] += errors - if day_ts >= daily_start: - key = (org_id, day_ts.date().isoformat(), metric_name, "default", "") - _upsert_agg(daily_agg, key, metric_type, value) + if hourly_agg: + stats["hourly"]["upserted"] += _bulk_upsert_hourly(hourly_agg) - key = (org_id, month_key, metric_name, "default", "") - _upsert_agg(monthly_agg, key, metric_type, value) + if daily_agg: + stats["daily"]["upserted"] += _bulk_upsert_daily(daily_agg) + stats["orgs_processed"] += 1 -def _run_aggregation() -> dict[str, Any]: - """Execute the actual aggregation logic. - Separated from the task function to keep the lock management clean. +def _active_org_ids(end_date: datetime, window_start: datetime) -> set: + """Organizations with execution activity in the prefilter lookback. + + Never narrower than the caller's own query window: a widened + source_window_days must not be prefiltered back down to the default + lookback, or the reconciliation pass skips the orgs it exists to repair. """ - end_date = timezone.now() + cutoff = min( + window_start, + end_date - timedelta(days=DASHBOARD_ACTIVE_ORG_LOOKBACK_DAYS), + ) + return set( + WorkflowExecution.objects.filter(created_at__gte=cutoff) + .values_list("workflow__organization_id", flat=True) + .distinct() + ) - # Query windows for each granularity - # - Hourly: Last 24 hours (rolling window, matches retention of 30 days) - # - Daily: Last 7 days (ensures we capture late-arriving data) - # - Monthly: Last 2 months (current + previous, ensures month transitions are captured) - hourly_start = end_date - timedelta(hours=24) - daily_start = _truncate_to_day(end_date - timedelta(days=7)) - # Include previous month to handle month boundaries - if end_date.month == 1: - monthly_start = end_date.replace( - year=end_date.year - 1, - month=12, - day=1, - hour=0, - minute=0, - second=0, - microsecond=0, - ) - else: - monthly_start = end_date.replace( - month=end_date.month - 1, day=1, hour=0, minute=0, second=0, microsecond=0 + +def _build_result( + stats: dict[str, Any], + hourly_start: datetime, + daily_start: datetime, + monthly_start: date, + end_date: datetime, + tier: AggregationTier, + skipped_reason: str | None = None, +) -> dict[str, Any]: + """Shape the task's return value from the accumulated stats.""" + result = { + "tier": tier.value, + # Reported, not enforced: _run answers 200 for any dict, so this does not + # fail the call. `errors` is what the worker alerts on and what switches the + # completion line to WARNING. + "success": stats["errors"] == 0, + "organizations_processed": stats["orgs_processed"], + "hourly": stats["hourly"], + "daily": stats["daily"], + "monthly": stats["monthly"], + "errors": stats["errors"], + "period": { + "hourly": {"start": hourly_start.isoformat(), "end": end_date.isoformat()}, + "daily": {"start": daily_start.isoformat(), "end": end_date.isoformat()}, + "monthly": {"start": monthly_start.isoformat(), "end": end_date.isoformat()}, + }, + } + if skipped_reason: + result["skipped_reason"] = skipped_reason + return result + + +# An upper sanity guard on a value that arrives as JSON from an editable schedule row, +# not a bound derived from the run budget: 90 days is itself wider than the 32-62 day +# scan this change removed, so a window near it is a manual repair, not a routine run. +MAX_SOURCE_WINDOW_DAYS = 90 + + +def _validate_source_window(source_window_days: int) -> int: + """Coerce and bound the window. It arrives as JSON from an editable Beat row.""" + try: + days = int(source_window_days) + except (TypeError, ValueError) as exc: + raise ValueError( + f"source_window_days must be an integer, got {source_window_days!r}" + ) from exc + if not 1 <= days <= MAX_SOURCE_WINDOW_DAYS: + raise ValueError( + f"source_window_days must be between 1 and {MAX_SOURCE_WINDOW_DAYS}, " + f"got {days}" ) + return days + + +def _run_diagnostic( + check: Callable[[date], list], + month_start: date, + stats: dict[str, Any], + key: str, + what: str, +) -> list: + """Run one pre-rollup check, returning [] if it fails rather than aborting. + + The rollup is the job and these only inform it, so a failing check must not + skip the upsert. It is still counted: `[]` alone reads as "checked, nothing + found", and a failed lowering check means the upsert runs with that guard off. + One call each, so one failing does not disable the other. The soft time limit + is the exception and does propagate. + """ + try: + return check(month_start) + except SoftTimeLimitExceeded: + # Swallowing it would hand an empty `skip` to the rollup, guard off. + raise + except Exception: + logger.exception("Could not %s", what) + stats["monthly"][key] = "unavailable" + stats["errors"] += 1 + return [] + + +_KEPT_MSG = ( + "Monthly rollup left %s unchanged — the daily tier now sums lower than the " + "stored total, so the figures were kept rather than overwritten. Repair daily " + "for those months with `backfill_metrics`" +) - # Metric definitions: (name, query_method, is_histogram) - # Note: llm_calls, challenges, summarization_calls, and llm_usage are - # handled separately via get_llm_metrics_combined (1 query instead of 4). - metric_configs = [ - ("documents_processed", MetricsQueryService.get_documents_processed, False), - ("pages_processed", MetricsQueryService.get_pages_processed, True), - ("deployed_api_requests", MetricsQueryService.get_deployed_api_requests, False), - ( - "etl_pipeline_executions", - MetricsQueryService.get_etl_pipeline_executions, - False, - ), - ("prompt_executions", MetricsQueryService.get_prompt_executions, False), - ("failed_pages", MetricsQueryService.get_failed_pages, True), - ("hitl_reviews", MetricsQueryService.get_hitl_reviews, False), - ("hitl_completions", MetricsQueryService.get_hitl_completions, False), - ] +_SHORT_TIER_MSG = ( + "Monthly rollup ran against an incomplete daily tier for %s — those totals are " + "under-counted whether or not they were lowered. Repair with `backfill_metrics` " + "if the source tables hold those days; a date on which nothing ran anywhere " + "reads the same and needs no action" +) - # LLM metrics combined via conditional aggregation (4 metrics in 1 query). - # Maps combined query field -> (metric_name, metric_type) - llm_combined_fields = { - "llm_calls": ("llm_calls", MetricType.COUNTER), - "challenges": ("challenges", MetricType.COUNTER), - "summarization_calls": ("summarization_calls", MetricType.COUNTER), - "llm_usage": ("llm_usage", MetricType.HISTOGRAM), - } + +def _report(stats: dict[str, Any], key: str, names: list[str], message: str) -> None: + """Record one monthly-tier gap in the result and the log, if there is one.""" + if not names: + return + stats["monthly"][key] = names + logger.warning(message, ", ".join(names)) + + +def _roll_up_monthly(monthly_start: date, stats: dict[str, Any]) -> None: + """Derive the monthly tier from daily, recording a failure distinctly.""" + # Before the upsert, while the stored values are still the old ones. + lowered_pairs = _run_diagnostic( + _pairs_the_rollup_would_lower, + monthly_start, + stats, + "lowered_check", + "check whether the rollup lowers monthly totals", + ) + missing_days = _run_diagnostic( + _months_missing_days, + monthly_start, + stats, + "coverage_check", + "check whether the daily tier is missing whole days", + ) + + try: + stats["monthly"]["upserted"] = _rollup_monthly_from_daily( + monthly_start, skip=set(lowered_pairs) + ) + except SoftTimeLimitExceeded: + raise + except Exception: + # Counted, not raised: autoretry_for is a no-op on the internal-HTTP path, + # where Task.retry re-raises under called_directly. errors > 0 is the signal. + logger.exception("Error rolling up monthly metrics from %s", monthly_start) + stats["monthly"]["failed"] = True + stats["errors"] += 1 + return + + _report(stats, "needs_daily_repair", _name_lowered_pairs(lowered_pairs), _KEPT_MSG) + # Reported, not skipped: refusing to write a short month leaves dashboards empty + # rather than slightly low, and there is no stored total here to preserve. + _report(stats, "incomplete_daily_coverage", missing_days, _SHORT_TIER_MSG) + + +def _run_aggregation( + tier: AggregationTier = AggregationTier.ALL, + source_window_days: int = DASHBOARD_SOURCE_WINDOW_DAYS, +) -> dict[str, Any]: + """Execute the aggregation, separately from the task's lock handling.""" + tier = AggregationTier(tier) + source_window_days = _validate_source_window(source_window_days) + end_date = timezone.now() + + # Monthly spans the current and previous month. + hourly_start = end_date - timedelta(hours=24) + daily_start = truncate_to_day(end_date - timedelta(days=source_window_days)) + monthly_start = _truncate_to_month( + _truncate_to_month(end_date) - timedelta(days=1) + ).date() stats = { "hourly": {"upserted": 0}, "daily": {"upserted": 0}, - "monthly": {"upserted": 0}, + "monthly": {"upserted": 0, "failed": False}, "errors": 0, "orgs_processed": 0, } # Pre-filter to orgs with recent activity to reduce DB load. - # Uses daily_start (7 days) instead of monthly_start (2 months) because: - # - Hourly/daily queries only need recent data (24h / 7d windows) - # - Monthly totals for dormant orgs were already written by previous - # runs when the org was active — re-running just overwrites same values - # - This avoids 28 queries per dormant org that had activity 2-8 weeks ago - active_org_ids = set( - WorkflowExecution.objects.filter( - created_at__gte=daily_start, - ) - .values_list("workflow__organization_id", flat=True) - .distinct() - ) - total_orgs = Organization.objects.count() - logger.info( - "Aggregation: %d active orgs out of %d total", - len(active_org_ids), - total_orgs, - ) - - if not active_org_ids: - return { - "success": True, - "organizations_processed": 0, - "hourly": stats["hourly"], - "daily": stats["daily"], - "monthly": stats["monthly"], - "errors": 0, - "skipped_reason": "no_active_orgs", - } + active_org_ids = _active_org_ids(end_date, daily_start) + # No total_orgs here: a full count of the organization table, on every run of + # every tier, whose only consumer was this log line. + logger.info("Aggregation (%s): %d active orgs", tier.value, len(active_org_ids)) + # No early return on an empty shortlist: the monthly rollup is org-agnostic, so + # it must still run. An empty id__in issues no query, so the loop below is free. organizations = Organization.objects.filter(id__in=active_org_ids).only( "id", "organization_id" ) for org in organizations: - org_id = str(org.id) - org_identifier = org.organization_id # Pre-resolved for PageUsage queries - hourly_agg: dict[tuple, dict] = {} - daily_agg: dict[tuple, dict] = {} - monthly_agg: dict[tuple, dict] = {} - try: - for metric_name, query_method, is_histogram in metric_configs: - metric_type = MetricType.HISTOGRAM if is_histogram else MetricType.COUNTER - - # Pass org_identifier to PageUsage-based metrics to - # avoid redundant Organization lookups per call. - extra_kwargs = {} - if metric_name == "pages_processed": - extra_kwargs["org_identifier"] = org_identifier - - try: - _aggregate_single_metric( - query_method, - metric_name, - metric_type, - org_id, - hourly_start, - daily_start, - monthly_start, - end_date, - hourly_agg, - daily_agg, - monthly_agg, - extra_kwargs, - ) - except Exception: - logger.exception("Error querying %s for org %s", metric_name, org_id) - stats["errors"] += 1 - - # Combined LLM metrics: 1 query per granularity instead of 4 - try: - _aggregate_llm_combined( - org_id, - hourly_start, - daily_start, - monthly_start, - end_date, - hourly_agg, - daily_agg, - monthly_agg, - llm_combined_fields, - ) - except Exception: - logger.exception("Error querying combined LLM metrics for org %s", org_id) - stats["errors"] += 1 - - # Bulk upsert all three tiers (single INSERT...ON CONFLICT each) - if hourly_agg: - stats["hourly"]["upserted"] += _bulk_upsert_hourly(hourly_agg) - - if daily_agg: - stats["daily"]["upserted"] += _bulk_upsert_daily(daily_agg) - - if monthly_agg: - stats["monthly"]["upserted"] += _bulk_upsert_monthly(monthly_agg) - - stats["orgs_processed"] += 1 - + _aggregate_org( + org, + hourly_start=hourly_start, + daily_start=daily_start, + end_date=end_date, + tier=tier, + stats=stats, + ) + except SoftTimeLimitExceeded: + raise except Exception: - logger.exception("Error processing org %s", org_id) + logger.exception("Error processing org %s", org.id) stats["errors"] += 1 - logger.info( - f"Aggregation completed: {stats['orgs_processed']} orgs, " - f"hourly={stats['hourly']['upserted']}, " - f"daily={stats['daily']['upserted']}, " - f"monthly={stats['monthly']['upserted']}, " - f"errors={stats['errors']}" + if _writes_daily_monthly(tier): + _roll_up_monthly(monthly_start, stats) + + # A tier with orgs to process, no error and nothing written is the regression + # signature of narrowing the source window. Raised here rather than only in the + # worker proxy, which the Celery transport never loads. + # + # Daily/monthly only. The prefilter shortlists orgs active in the last + # DASHBOARD_ACTIVE_ORG_LOOKBACK_DAYS days while the hourly tier queries 24h, so an + # org quiet for 2-7 days is shortlisted and contributes nothing — on the */15 row + # that would warn 96 times a day about a healthy weekend. + wrote_nothing = ( + _writes_daily_monthly(tier) + and active_org_ids + and not stats["errors"] + and not any( + stats[granularity]["upserted"] + for granularity in ("hourly", "daily", "monthly") + ) + ) + log = logger.warning if stats["errors"] or wrote_nothing else logger.info + # tier and window are named because three schedules now emit this line and they + # can overlap: without them a reconcile run is indistinguishable from a routine + # one, and the window this change turns on appears in no successful run's logs. + log( + "Aggregation completed (tier=%s window=%dd): %d orgs, " + "hourly=%d, daily=%d, monthly=%d, errors=%d", + tier.value, + source_window_days, + stats["orgs_processed"], + stats["hourly"]["upserted"], + stats["daily"]["upserted"], + stats["monthly"]["upserted"], + stats["errors"], ) - return { - "success": True, - "organizations_processed": stats["orgs_processed"], - "hourly": stats["hourly"], - "daily": stats["daily"], - "monthly": stats["monthly"], - "errors": stats["errors"], - "period": { - "hourly": {"start": hourly_start.isoformat(), "end": end_date.isoformat()}, - "daily": {"start": daily_start.isoformat(), "end": end_date.isoformat()}, - "monthly": {"start": monthly_start.isoformat(), "end": end_date.isoformat()}, - }, - } + return _build_result( + stats, + hourly_start, + daily_start, + monthly_start, + end_date, + tier, + skipped_reason="no_active_orgs" if not active_org_ids else None, + ) @shared_task( diff --git a/backend/dashboard_metrics/tests/test_active_org_prefilter.py b/backend/dashboard_metrics/tests/test_active_org_prefilter.py new file mode 100644 index 0000000000..1f2518401e --- /dev/null +++ b/backend/dashboard_metrics/tests/test_active_org_prefilter.py @@ -0,0 +1,147 @@ +"""The active-org prefilter can actually use we_created_at_idx (UN-3974, AC-3). + +AC-3 is worded as a production observation — "no longer appears in the top 10 by total +execution time in Query Insights" — and that half can only be read off production. The +half that is answerable here is the one underneath it: the prefilter bounds nothing but +`created_at`, and the index exists to serve exactly that shape. + +What this pins is the pairing. `workflow_manager/workflow_v2/tests/test_we_created_at_idx.py` +proves the index is declared and built safely; this proves the query still looks like +something it can serve. Either half can drift without the other noticing — someone +narrowing the prefilter to lead with a different column leaves the index built, valid, +and dead. + +Rows are inserted in ascending `created_at` order so the heap matches production, where +executions are appended as they happen. With them scattered the planner reads the whole +composite (workflow_id, created_at DESC) index instead, which is an artefact of the +fixture rather than anything about the query. + +**Not production evidence.** A few thousand rows in an otherwise-empty table on a +locally-configured Postgres is not the production planner's input: index-vs-seq-scan at +this selectivity is a cost-model output, sensitive to the PG major version, +`random_page_cost`, `effective_cache_size` and parallel workers, none of which are +pinned here. What the plan assertion below rules out is the *regression* — a prefilter +that has to read the executions table whatever the costs say. Whether production picks +the index is measured on production, and belongs to AC-3. + +DB-bound, so conftest marks it integration. +""" + +from __future__ import annotations + +import os + +import django +from django.apps import apps + +os.environ.setdefault("DJANGO_SETTINGS_MODULE", "backend.settings.test") +if not apps.ready: + django.setup() + +from account_v2.models import Organization # noqa: E402 +from django.db import connection # noqa: E402 +from django.test import TestCase # noqa: E402 +from django.test.utils import CaptureQueriesContext # noqa: E402 +from workflow_manager.workflow_v2.models.workflow import Workflow # noqa: E402 + +from dashboard_metrics.tasks import ( # noqa: E402 + DASHBOARD_ACTIVE_ORG_LOOKBACK_DAYS, + AggregationTier, + _run_aggregation, +) + +INDEX_NAME = "we_created_at_idx" + +_ROWS = 12000 +_SPAN_DAYS = 255 + + +class TestThePrefilterCanUseTheIndex(TestCase): + """Production ratios rather than production size: ~2.7% of rows in the 7-day window + is what decides whether the planner reaches for an index or scans. + """ + + def setUp(self) -> None: + self.org = Organization.objects.create( + organization_id="prefilter-org", name="prefilter", display_name="Prefilter" + ) + self.workflow = Workflow.objects.create( + workflow_name="prefilter-wf", organization=self.org + ) + with connection.cursor() as cur: + cur.execute( + """ + INSERT INTO workflow_execution ( + id, created_at, modified_at, workflow_id, execution_mode, + execution_method, execution_type, execution_log_id, status, + error_message, attempts, execution_time, result_acknowledged, + total_files) + SELECT gen_random_uuid(), ts, ts, %s, 'INSTANT', 'DIRECT', 'COMPLETE', + '', 'COMPLETED', '', 0, 1.0, false, 1 + FROM generate_series(1, %s) g + CROSS JOIN LATERAL ( + SELECT now() - (%s - (g::float / %s) * %s) * interval '1 day' + ) AS t(ts) + """, + [self.workflow.id, _ROWS, _SPAN_DAYS, _ROWS, _SPAN_DAYS], + ) + cur.execute("ANALYZE workflow_execution") + + def _prefilter_sql(self) -> str: + """The real query, taken from the task rather than rewritten here. + + A hand-copied queryset would keep passing after the prefilter changed, which is + the one thing this test is for. + """ + with CaptureQueriesContext(connection) as ctx: + _run_aggregation(AggregationTier.HOURLY) + candidates = [ + q["sql"] + for q in ctx.captured_queries + if "workflow_execution" in q["sql"] + and "DISTINCT" in q["sql"].upper() + and "created_at" in q["sql"] + ] + # The run issues nine further queries against this table, several of them + # joining it and filtering created_at. Index 0 is right today only by execution + # order, which nothing here states — so require the shape to be unambiguous. + assert candidates, "the aggregation issued no active-org prefilter query" + assert len(candidates) == 1, ( + f"{len(candidates)} queries match the prefilter shape; the match is no " + f"longer distinguishing:\n" + "\n\n".join(candidates) + ) + return str(candidates[0]) + + def test_the_window_is_the_selectivity_the_index_is_for(self) -> None: + """If the prefilter ever widened to most of the table, an index on created_at + would stop being the right answer — the planner would scan regardless. + """ + with connection.cursor() as cur: + cur.execute( + "SELECT count(*) FILTER (WHERE created_at >= now() - %s::interval)" + "::float / count(*) FROM workflow_execution", + [f"{DASHBOARD_ACTIVE_ORG_LOOKBACK_DAYS} days"], + ) + share = cur.fetchone()[0] + assert 0 < share < 0.10 + + def test_the_index_can_serve_the_prefilter(self) -> None: + """*Usable*, not *chosen*. + + Whether the planner picks the index on a synthetic table turns on + random_page_cost, effective_cache_size, the PG major version and how the + freshly-loaded visibility map looks — none of which this fixture pins, so + asserting the choice reds the build on a config change with no code change. + Disabling seqscan asks the question that is actually about the query: can this + shape be served from the index at all? A prefilter narrowed to lead with a + different column fails here whatever the cost model says. + """ + sql = self._prefilter_sql() + with connection.cursor() as cur: + cur.execute("SET LOCAL enable_seqscan = off") + cur.execute("EXPLAIN " + sql) + plan = "\n".join(row[0] for row in cur.fetchall()) + assert ( + f"Index Scan using {INDEX_NAME}" in plan + or f"Index Only Scan using {INDEX_NAME}" in plan + ), f"expected {INDEX_NAME} to be usable for the prefilter:\n{plan}" diff --git a/backend/dashboard_metrics/tests/test_aggregation_dispatch.py b/backend/dashboard_metrics/tests/test_aggregation_dispatch.py new file mode 100644 index 0000000000..f998c1f4d9 --- /dev/null +++ b/backend/dashboard_metrics/tests/test_aggregation_dispatch.py @@ -0,0 +1,158 @@ +"""Guard: the tier a schedule row declares reaches the task (UN-3974, AC-1). + +Two schedulers fire the same task name at two different implementations. Beat reads +``PeriodicTask.kwargs`` and calls the Django ``@shared_task`` directly; the PG scheduler +reads ``PgPeriodicTask.task_kwargs`` and goes through the worker proxy and the internal +endpoint to the same function. Both legs have to carry ``tier``, and a break in either is +invisible — the job still runs, still returns success, and just writes the wrong tiers. + +The worker half of the PG leg is pinned in ``workers/tests/test_dashboard_metrics_tasks.py``; +this covers the endpoint that receives it and the Beat leg's kwargs. + +DB-free: the task is mocked, and the Beat kwargs are read from the migration spec rather +than from a migrated database. +""" + +from __future__ import annotations + +import importlib +import inspect +import os +from typing import Any +from unittest import mock + +import django +import pytest +from django.apps import apps + +os.environ.setdefault("DJANGO_SETTINGS_MODULE", "backend.settings.test") +if not apps.ready: + django.setup() + +from rest_framework.test import APIRequestFactory # noqa: E402 + +from dashboard_metrics import internal_views # noqa: E402 +from dashboard_metrics.tasks import ( # noqa: E402 + AggregationTier, + aggregate_metrics_from_sources, +) + +_SPLIT_MIGRATION = "dashboard_metrics.migrations.0006_split_aggregation_schedule" +_ENDPOINT = "/internal/v1/dashboard-metrics/aggregate/" + + +def _post(body: dict[str, Any]) -> tuple[int, Any]: + """POST to the aggregate endpoint with the task mocked. + + Returns the status and the kwargs the task was called with, or ``None`` if it was + never reached — which is what a rejected body has to look like. + """ + view = internal_views.AggregateMetricsAPIView.as_view() + request = APIRequestFactory().post(_ENDPOINT, body, format="json") + with mock.patch.object( + internal_views, "aggregate_metrics_from_sources", return_value={"ok": True} + ) as task: + response = view(request) + return response.status_code, (task.call_args.kwargs if task.call_args else None) + + +def _named_parameters(func) -> set[str]: + """Parameter names a task actually reads, excluding a **kwargs catch-all. + + `signature.bind()` alone stopped being a guard the moment these tasks grew + `**_ignored`: it accepts any keyword, so a schedule row declaring a misspelled + kwarg binds cleanly and the run silently proceeds on defaults. + """ + return { + p.name + for p in inspect.signature(func).parameters.values() + if p.kind is not inspect.Parameter.VAR_KEYWORD + } + + +class TestThePgLegCarriesTheTier: + """The endpoint the worker proxy POSTs to.""" + + @pytest.mark.parametrize("tier", ["hourly", "daily_monthly", "all"]) + def test_the_endpoint_forwards_the_tier_to_the_task(self, tier: str) -> None: + status, called_with = _post({"tier": tier}) + assert status == 200 + assert called_with == {"tier": tier} + + def test_an_omitted_tier_leaves_the_task_default_in_place(self) -> None: + """Not 'hourly', and not nothing: the task's own default is `all`, and passing + anything here would override it during the window before 0006 applies. + """ + status, called_with = _post({}) + assert status == 200 + assert called_with == {} + + @pytest.mark.parametrize("body", [{}, {"tier": None}, "not-a-dict"]) + def test_an_absent_tier_leaves_the_task_default_in_place(self, body) -> None: + """An explicit null and a non-dict body both mean "omitted", not "no tiers".""" + status, called_with = _post(body) + assert status == 200 + assert called_with == {} + + def test_the_source_window_reaches_the_task(self) -> None: + """0005's reconciliation row dispatches this against the same task path.""" + status, called_with = _post({"source_window_days": 7}) + assert status == 200 + assert called_with == {"source_window_days": 7} + + def test_both_kwargs_survive_together(self) -> None: + status, called_with = _post({"tier": "hourly", "source_window_days": 7}) + assert status == 200 + assert called_with == {"tier": "hourly", "source_window_days": 7} + + def test_a_non_integer_window_is_rejected(self) -> None: + status, called_with = _post({"source_window_days": "seven"}) + assert status == 400 + assert called_with is None + + def test_an_unrecognised_tier_is_rejected_rather_than_ignored(self) -> None: + """A silent no-op would look like a successful run that wrote nothing. + + The 400 is raised at the boundary, before the task is entered, so it cannot be + confused with a ValueError from inside the aggregation — that one belongs on + the logged 500 path. + """ + status, called_with = _post({"tier": "houry"}) + assert status == 400 + assert called_with is None + + +class TestTheBeatLegCarriesTheTier: + """Beat passes the row's stored JSON kwargs straight into the task signature.""" + + @pytest.fixture(scope="class") + def declared_kwargs(self) -> dict[str, dict[str, Any]]: + mod = importlib.import_module(_SPLIT_MIGRATION) + return {s["name"]: {"tier": s["tier"]} for s in mod.AGGREGATION_SCHEDULES} + + def test_both_rows_declare_a_tier( + self, declared_kwargs: dict[str, dict[str, Any]] + ) -> None: + assert len(declared_kwargs) == 2 + assert all("tier" in kw for kw in declared_kwargs.values()) + + def test_every_declared_kwarg_set_binds_to_the_task_signature( + self, declared_kwargs: dict[str, dict[str, Any]] + ) -> None: + """A row declaring a kwarg the task does not accept fails at call time, inside + the worker, where it surfaces as a retrying task rather than a bad schedule. + """ + named = _named_parameters(aggregate_metrics_from_sources) + for row, kwargs in declared_kwargs.items(): + unknown = set(kwargs) - named + assert not unknown, f"{row} declares kwargs the task does not read: {unknown}" + + + def test_every_declared_tier_is_a_real_tier( + self, declared_kwargs: dict[str, dict[str, Any]] + ) -> None: + """The migration cannot import the enum, so it repeats the literals. A typo + there raises inside the task on every single run. + """ + for kwargs in declared_kwargs.values(): + AggregationTier(kwargs["tier"]) diff --git a/backend/dashboard_metrics/tests/test_aggregation_tier.py b/backend/dashboard_metrics/tests/test_aggregation_tier.py new file mode 100644 index 0000000000..8e5899448d --- /dev/null +++ b/backend/dashboard_metrics/tests/test_aggregation_tier.py @@ -0,0 +1,204 @@ +"""Guard: the tier a schedule row asks for is the tier that gets written. + +The split runs one task on two schedules that differ only in their ``tier`` kwarg, so +the gating predicates and the per-tier lock key are the whole mechanism. Each property +here is one way the split fails silently — writing nothing, writing both tiers from one +schedule, or the two schedules starving each other on the lock. + +DB-free, and the lock cases pin the cache to locmem, so this runs in the unit tier +alongside test_pg_periodic_task_declarations.py. Settings inherit the production +django_redis backend, which that tier provides no server for. +""" + +from __future__ import annotations + +import inspect +import os +import time + +import django +import pytest +from django.apps import apps + +os.environ.setdefault("DJANGO_SETTINGS_MODULE", "backend.settings.test") +if not apps.ready: + django.setup() + +from django.core.cache import cache # noqa: E402 +from django.test import override_settings # noqa: E402 + +from dashboard_metrics.tasks import ( # noqa: E402 + AGGREGATION_LOCK_TIMEOUT, + DASHBOARD_SOURCE_WINDOW_DAYS, + AggregationTier, + _acquire_aggregation_lock, + _acquire_aggregation_locks, + _aggregation_lock_keys, + _tiers_written, + _writes_daily_monthly, + _writes_hourly, + aggregate_metrics_from_sources, +) + + +def _keys(tier, window: int = DASHBOARD_SOURCE_WINDOW_DAYS) -> list[str]: + return _aggregation_lock_keys(tier, window) + + +class TestWhichTiersEachRunWrites: + @pytest.mark.parametrize( + "tier,hourly,daily_monthly", + [ + (AggregationTier.HOURLY, True, False), + (AggregationTier.DAILY_MONTHLY, False, True), + (AggregationTier.ALL, True, True), + ], + ) + def test_the_predicates_partition_the_work( + self, tier: AggregationTier, hourly: bool, daily_monthly: bool + ) -> None: + assert _writes_hourly(tier) is hourly + assert _writes_daily_monthly(tier) is daily_monthly + + def test_the_two_schedules_together_cover_every_tier(self) -> None: + """Neither schedule may leave a tier unwritten: hourly and daily_monthly are + the only two rows, so between them they have to do everything `all` does. + """ + scheduled = (AggregationTier.HOURLY, AggregationTier.DAILY_MONTHLY) + assert any(_writes_hourly(t) for t in scheduled) + assert any(_writes_daily_monthly(t) for t in scheduled) + + def test_no_tier_is_written_by_both_schedules(self) -> None: + """Overlap would mean duplicate work every hour on the hour. The upserts make + it harmless, not free. + """ + assert not _writes_daily_monthly(AggregationTier.HOURLY) + assert not _writes_hourly(AggregationTier.DAILY_MONTHLY) + + +class TestTheDefaultIsAll: + """The property that keeps the deploy window safe, pinned at the signature. + + Between the code deploying and migration 0006 running, the schedule row still + carries no tier kwarg. Every other test in the suite passes a tier explicitly or + mocks the task, so none of them can see what the default actually is. + """ + + def test_the_signature_default_is_all(self) -> None: + """Narrower and daily/monthly stop being written for the whole window; none + and nothing is written at all. Both look like successful runs. + """ + default = ( + inspect.signature(aggregate_metrics_from_sources).parameters["tier"].default + ) + assert default == AggregationTier.ALL + + def test_the_default_writes_everything_rather_than_nothing(self) -> None: + assert AggregationTier("all") is AggregationTier.ALL + assert _writes_hourly(AggregationTier.ALL) + assert _writes_daily_monthly(AggregationTier.ALL) + + def test_an_unrecognised_tier_raises(self) -> None: + """The internal view turns this into a 400. A silent no-op would look like a + successful run that wrote nothing. + """ + with pytest.raises(ValueError): + AggregationTier("houry") + + +class TestTheTierTableIsExhaustive: + """A member with no entry must raise, not write nothing and report success.""" + + def test_every_declared_tier_has_an_entry(self) -> None: + for tier in AggregationTier: + assert _tiers_written(tier) + + def test_an_unhandled_member_raises_rather_than_writing_nothing(self) -> None: + # Stands in for a member added to the enum without a _TIER_WRITES entry. + ghost = type("_Ghost", (), {"value": "weekly"})() + with pytest.raises(AssertionError, match="Unhandled AggregationTier"): + _tiers_written(ghost) + + +# The lock protocol needs a cache, not a server: add/get/delete semantics are identical +# on locmem, and pinning it here keeps these cases in the unit tier. +_LOCMEM_CACHE = { + "default": { + "BACKEND": "django.core.cache.backends.locmem.LocMemCache", + "LOCATION": "aggregation-lock-tests", + } +} + + +class TestTheLockCoversWhatIsWritten: + """Keyed by granularity written, not by enum member. + + Keying on the label alone gives ALL a third key that excludes nothing, so an ALL + run and the scheduled hourly run write EventMetricsHourly concurrently. These + exercise the lock rather than its key string: a version of + _acquire_aggregation_lock that ignored its argument would pass a key-shape test. + """ + + @pytest.fixture(autouse=True) + def _clear(self): + with override_settings(CACHES=_LOCMEM_CACHE): + cache.clear() + yield + cache.clear() + + def test_the_two_scheduled_tiers_never_block_each_other(self) -> None: + assert _acquire_aggregation_locks(_keys(AggregationTier.HOURLY))[0] + assert _acquire_aggregation_locks(_keys(AggregationTier.DAILY_MONTHLY))[0] + + def test_a_tier_blocks_itself(self) -> None: + assert _acquire_aggregation_locks(_keys(AggregationTier.HOURLY))[0] + assert not _acquire_aggregation_locks(_keys(AggregationTier.HOURLY))[0] + + def test_all_is_blocked_by_either_half(self) -> None: + """The exclusion a per-member key silently dropped.""" + assert _acquire_aggregation_locks(_keys(AggregationTier.HOURLY))[0] + assert not _acquire_aggregation_locks(_keys(AggregationTier.ALL))[0] + + def test_a_blocked_run_releases_whatever_it_took(self) -> None: + """Keys are taken in sorted order, so ALL takes daily_monthly first. + + Holding hourly is what makes ALL fail on its *second* key, with the first + already taken — the only ordering that exercises the rollback. + """ + assert _acquire_aggregation_locks(_keys(AggregationTier.HOURLY))[0] + assert not _acquire_aggregation_locks(_keys(AggregationTier.ALL))[0] + assert _acquire_aggregation_locks(_keys(AggregationTier.DAILY_MONTHLY))[0] + + def test_a_wider_window_is_a_different_job(self) -> None: + """The reconciliation pass is never retried, so it must not be starved by the + 15-minute schedule it races against. + """ + assert _acquire_aggregation_locks(_keys(AggregationTier.HOURLY, 2))[0] + assert _acquire_aggregation_locks(_keys(AggregationTier.ALL, 7))[0] + + +class TestTheLockBlocksWhileHeld: + """Recovery is the key's own TTL, and nothing else. + + The age-based reclaim these tests used to cover was removed: it could not tell a + live holder from a dead one (it compares a local clock against another worker's), + its read-judge-replace was not atomic, and it was unreachable anyway — the keys + this release uses are new, so no value predating tokens can appear under one. + """ + + @pytest.fixture(autouse=True) + def _clear(self): + with override_settings(CACHES=_LOCMEM_CACHE): + cache.clear() + yield + cache.clear() + + def test_a_held_key_blocks_however_old_it_looks(self) -> None: + key = _keys(AggregationTier.HOURLY)[0] + cache.set(key, f"someone-else:{time.time() - AGGREGATION_LOCK_TIMEOUT - 1}", 3600) + assert not _acquire_aggregation_lock(key, "tok") + + def test_a_free_key_is_taken_and_carries_the_token(self) -> None: + key = _keys(AggregationTier.HOURLY)[0] + assert _acquire_aggregation_lock(key, "tok") + assert cache.get(key).startswith("tok:") diff --git a/backend/dashboard_metrics/tests/test_backfill_metrics.py b/backend/dashboard_metrics/tests/test_backfill_metrics.py new file mode 100644 index 0000000000..1e2a77d32e --- /dev/null +++ b/backend/dashboard_metrics/tests/test_backfill_metrics.py @@ -0,0 +1,240 @@ +"""Tests for the backfill_metrics management command. + +This command is the documented repair path for the daily tier, and the monthly +tier is now derived from what it writes, so a regression here is not self-healing. +""" + +from datetime import timedelta +from io import StringIO +from unittest.mock import patch + +from account_v2.models import Organization +from django.core.management import call_command +from django.core.management.base import CommandError +from django.test import TestCase +from django.utils import timezone +from workflow_manager.file_execution.models import WorkflowFileExecution +from workflow_manager.workflow_v2.enums import ExecutionStatus +from workflow_manager.workflow_v2.models.execution import WorkflowExecution +from workflow_manager.workflow_v2.models.workflow import Workflow + +from dashboard_metrics.management.commands.backfill_metrics import Command +from dashboard_metrics.models import EventMetricsDaily, Granularity +from dashboard_metrics.tasks import truncate_to_day + + +def _explode(*args, **kwargs): + """Stand-in for a metric query that fails, e.g. on a statement timeout.""" + raise RuntimeError("metric query exploded") + + +class TestSkipHourlySkipsTheQueries(TestCase): + """--skip-hourly must skip the HOUR source queries, not just their upsert. + + The prescribed deploy step passes it over a window measured in weeks. Reading + the flag only at the upsert would reinstate, once at deploy time, the very + multi-week scan across the source tables this change exists to remove — while + the operator believes it was skipped. + """ + + def setUp(self): + self.requested = [] + self.now = timezone.now() + + def _recording_query(org_id, start, end, granularity=None, **kwargs): + self.requested.append(granularity) + return [] + + self.configs = [("documents_processed", _recording_query, False)] + + def _collect(self, skip_hourly): + command = Command() + with patch.object(Command, "METRIC_CONFIGS", self.configs): + with patch( + "dashboard_metrics.management.commands.backfill_metrics." + "MetricsQueryService.get_llm_metrics_split", + return_value={}, + ): + command._collect_metrics( + "1", + self.now - timedelta(days=3), + self.now, + skip_hourly=skip_hourly, + ) + + def test_skip_hourly_issues_no_hour_granularity_query(self): + self._collect(skip_hourly=True) + assert Granularity.HOUR not in self.requested + assert Granularity.DAY in self.requested + + def test_without_the_flag_both_granularities_are_queried(self): + """The control: the flag is what removes them, not the stub.""" + self._collect(skip_hourly=False) + assert Granularity.HOUR in self.requested + assert Granularity.DAY in self.requested + + +class TestLLMSplitHonoursSkipHourly(TestCase): + """The combined-LLM path is a second query site with the same flag.""" + + def setUp(self): + self.requested = [] + self.now = timezone.now() + + def _collect(self, skip_hourly): + def _recording_split(org_id, start, end, granularity): + self.requested.append(granularity) + return {} + + command = Command() + with patch.object(Command, "METRIC_CONFIGS", []): + with patch( + "dashboard_metrics.management.commands.backfill_metrics." + "MetricsQueryService.get_llm_metrics_split", + side_effect=_recording_split, + ): + command._collect_metrics( + "1", + self.now - timedelta(days=3), + self.now, + skip_hourly=skip_hourly, + ) + + def test_skip_hourly_issues_no_hour_granularity_query(self): + self._collect(skip_hourly=True) + assert self.requested == [Granularity.DAY] + + def test_without_the_flag_both_granularities_are_queried(self): + self._collect(skip_hourly=False) + assert self.requested == [Granularity.HOUR, Granularity.DAY] + + +class TestTheOldestBackfilledDayIsWhole(TestCase): + """The window boundary this PR changed, which had no exerciser. + + An untruncated start writes the oldest day as a partial bucket, and the monthly + rollup now sums the persisted daily tier rather than recomputing that day from + source — so the partial value becomes permanent once it ages past the reconcile + window. This is the mandatory pre-deploy step, so a regression here corrupts the + state everything else assumes. + """ + + def setUp(self): + self.org = Organization.objects.create( + organization_id="trunc-org", name="trunc", display_name="Trunc" + ) + self.workflow = Workflow.objects.create( + workflow_name="trunc-wf", organization=self.org + ) + self.now = timezone.now() + + def _seed(self, days_ago, hour): + stamp = (self.now - timedelta(days=days_ago)).replace(hour=hour, minute=30) + execution = WorkflowExecution.objects.create( + workflow=self.workflow, status=ExecutionStatus.COMPLETED + ) + fe = WorkflowFileExecution.objects.create( + workflow_execution=execution, + file_name=f"{days_ago}-{hour}.pdf", + status=ExecutionStatus.COMPLETED.value, + ) + WorkflowFileExecution.objects.filter(pk=fe.pk).update(created_at=stamp) + WorkflowExecution.objects.filter(pk=execution.pk).update(created_at=stamp) + + def _frozen(self): + """Mid-afternoon, so the untruncated boundary really does exclude hour 1. + + Read from the real clock this test passed with the bug present whenever CI + ran before 01:30 UTC — the boundary was already earlier than the seeded row. + """ + return self.now.replace(hour=15, minute=0, second=0, microsecond=0) + + def test_the_oldest_covered_day_counts_its_whole_day(self): + """Two rows on the boundary day, one before the run's hour and one after. + + Untruncated, the earlier row falls outside the window and the oldest day is + written short. + """ + frozen = self._frozen() + with patch("django.utils.timezone.now", return_value=frozen): + self.now = frozen + self._seed(days_ago=2, hour=1) + self._seed(days_ago=2, hour=23) + call_command("backfill_metrics", days=2, skip_hourly=True, skip_monthly=True) + + oldest_day = truncate_to_day(frozen - timedelta(days=2)).date() + row = EventMetricsDaily._base_manager.get( + organization=self.org, date=oldest_day, metric_name="documents_processed" + ) + assert row.metric_value == 2, "the oldest day was written as a partial bucket" + + +class TestSkipDailyWithoutSkipMonthlyWarns(TestCase): + """The combination that leaves the daily tier short on purpose. + + The rollup's guard keeps monthly from being lowered, so this freezes the month + at its stored total rather than under-counting it — but daily stays wrong, and + the month cannot be updated again until it is repaired. + """ + + def test_the_warning_is_emitted(self): + out = StringIO() + call_command("backfill_metrics", days=1, skip_daily=True, stdout=out) + assert "--skip-daily without --skip-monthly" in out.getvalue() + + +class TestAWholesaleQueryFailureIsNotReportedAsSuccess(TestCase): + """The pre-deploy step must not print green when every query failed. + + Each metric query is caught individually inside ``_collect_metrics``, so none + of them ever reaches the per-organisation handler that owns the error counter. + The command therefore used to print ``BACKFILL COMPLETE`` and exit 0 with the + daily tier untouched — and the monthly rollup, which now derives from that + tier, would then run against it. + """ + + def setUp(self): + self.org = Organization.objects.create( + organization_id="fail-org", name="fail", display_name="Fail" + ) + + def test_a_failing_metric_query_raises_and_exits_non_zero(self): + out = StringIO() + with patch.object( + Command, + "METRIC_CONFIGS", + [("documents_processed", _explode, False)], + ): + with self.assertRaises(CommandError) as caught: + call_command( + "backfill_metrics", + days=1, + skip_hourly=True, + skip_monthly=True, + stdout=out, + ) + assert "error(s) during backfill" in str(caught.exception) + assert "BACKFILL FAILED" in out.getvalue() + + def test_a_failing_llm_query_is_counted_too(self): + """The LLM split is caught in its own arm, separate from METRIC_CONFIGS.""" + out = StringIO() + with patch.object(Command, "METRIC_CONFIGS", []): + with patch( + "dashboard_metrics.management.commands.backfill_metrics." + "MetricsQueryService.get_llm_metrics_split", + side_effect=RuntimeError("llm query exploded"), + ): + with self.assertRaises(CommandError): + call_command( + "backfill_metrics", days=1, skip_monthly=True, stdout=out + ) + assert "BACKFILL FAILED" in out.getvalue() + + def test_a_clean_run_still_reports_complete(self): + """The control: without a failure the command stays green and returns.""" + out = StringIO() + call_command( + "backfill_metrics", days=1, skip_hourly=True, skip_monthly=True, stdout=out + ) + assert "BACKFILL COMPLETE" in out.getvalue() diff --git a/backend/dashboard_metrics/tests/test_calendar_probe.py b/backend/dashboard_metrics/tests/test_calendar_probe.py new file mode 100644 index 0000000000..ff2948c17b --- /dev/null +++ b/backend/dashboard_metrics/tests/test_calendar_probe.py @@ -0,0 +1,39 @@ +"""Probe: run the clock-sensitive suites at the boundaries that used to break them.""" + +from datetime import datetime, timezone as dt_timezone +from unittest.mock import patch + +# Imported under private aliases: pytest collects any TestCase subclass by name, so +# a bare import would re-run all three base classes here, unfrozen, under boundary ids. +from dashboard_metrics.tests.test_tasks import ( + TestMonthlyMatchesTheOldDerivation as _BaseMonthlyDerivation, + TestMonthlyThroughTheTask as _BaseMonthlyThroughTask, + TestSourceWindow as _BaseSourceWindow, +) + +_BOUNDARIES = [ + datetime(2026, 10, 1, 0, 0, 0, 100000, tzinfo=dt_timezone.utc), # 1st of a month + datetime(2026, 3, 31, 23, 59, 59, 900000, tzinfo=dt_timezone.utc), # month end, pre-midnight +] + + +def _at(when): + def _factory(cls): + class _Frozen(cls): + def setUp(self): + with patch("django.utils.timezone.now", return_value=when): + super().setUp() + self.now = when + _Frozen.__name__ = f"{cls.__name__}At{when:%Y%m%d%H%M}" + _Frozen.__qualname__ = _Frozen.__name__ + return _Frozen + return _factory + + +for _when in _BOUNDARIES: + for _cls in (_BaseSourceWindow, _BaseMonthlyThroughTask, _BaseMonthlyDerivation): + _frozen = _at(_when)(_cls) + globals()[_frozen.__name__] = _frozen + +# Loop variables would otherwise be collected as test classes themselves. +del _when, _cls, _frozen diff --git a/backend/dashboard_metrics/tests/test_migration_graph.py b/backend/dashboard_metrics/tests/test_migration_graph.py new file mode 100644 index 0000000000..c2a11135b9 --- /dev/null +++ b/backend/dashboard_metrics/tests/test_migration_graph.py @@ -0,0 +1,67 @@ +"""Guard: the migration graph builds (UN-3974). + +Django builds the **entire** graph before executing anything, so one migration +depending on a node that does not exist aborts `migrate`, `makemigrations` and +`showmigrations` for every app in the project — the deploy's migrate step fails, not +just this app's. + +Nothing else catches it. The backend suite runs with `--no-migrations`, so test-DB +creation never builds the graph, and every migration test in this app reaches its +module through `importlib.import_module`, which resolves a file path rather than a +graph node. GitHub also reports a stacked branch as mergeable, because a missing +dependency is not a textual conflict. + +DB-free: building the graph reads the migration files, not the database. +""" + +from __future__ import annotations + +import os + +import django +from django.apps import apps + +os.environ.setdefault("DJANGO_SETTINGS_MODULE", "backend.settings.test") +if not apps.ready: + django.setup() + +from django.db.migrations.loader import MigrationLoader # noqa: E402 +from django.test import SimpleTestCase, override_settings # noqa: E402 + + +def _build_graph() -> MigrationLoader: + """Build the real graph, whatever the suite's own flags say. + + `--no-migrations` works by pointing MIGRATION_MODULES at a mapping that returns + None for every app, so a loader built under it finds nothing and every assertion + below would pass against an empty graph. Restoring the setting is what makes this + guard mean anything in the tier it runs in. + """ + with override_settings(MIGRATION_MODULES={}): + loader = MigrationLoader(None, ignore_no_migrations=True) + loader.build_graph() + return loader + + +class MigrationGraphTests(SimpleTestCase): + def test_the_graph_builds(self) -> None: + """A dependency on an absent migration raises NodeNotFoundError here.""" + loader = _build_graph() + self.assertTrue(loader.graph.nodes, "no migrations loaded — the guard is inert") + + def test_every_app_has_exactly_one_leaf(self) -> None: + """Two leaves in one app block `migrate` for every app, not just that one. + + This is what a merge of two branches that each added a migration produces, and + it is invisible until deploy for the same `--no-migrations` reason. + """ + loader = _build_graph() + + leaves: dict[str, list[str]] = {} + for app_label, name in loader.graph.leaf_nodes(): + leaves.setdefault(app_label, []).append(name) + + conflicts = {app: names for app, names in leaves.items() if len(names) > 1} + self.assertEqual( + conflicts, {}, f"apps with multiple leaf migrations: {conflicts}" + ) diff --git a/backend/dashboard_metrics/tests/test_pg_periodic_task_declarations.py b/backend/dashboard_metrics/tests/test_pg_periodic_task_declarations.py index 85ea407899..4ca4b06121 100644 --- a/backend/dashboard_metrics/tests/test_pg_periodic_task_declarations.py +++ b/backend/dashboard_metrics/tests/test_pg_periodic_task_declarations.py @@ -1,113 +1,649 @@ """Drift guard between the Beat and PG declarations of the metrics periodics (UN-3796). -Two migrations declare the same three schedules — ``0002_setup_periodic_tasks`` for Celery -Beat and ``0004_pg_periodic_tasks`` for the PG scheduler. They are separate rows in -separate tables, so nothing stops someone editing one and forgetting the other. That is -the whole failure mode this file exists for: a schedule changed on Beat but not on PG means -the task silently runs on a different cadence the moment the flag flips. - -DB-free — both migration modules are imported and their declared specs compared directly, -so this runs in the unit tier rather than needing a migrated database. +Every schedule in this app is declared twice — once in +``django_celery_beat_periodictask`` for Celery Beat, once in ``pg_periodic_task`` for the +PG scheduler. They are separate rows in separate tables, so nothing stops someone editing +one and forgetting the other. That is the whole failure mode this file exists for: a +schedule changed on Beat but not on PG means the task silently runs on a different cadence +— or not at all — the moment the flag flips. + +**Every data migration in the app is replayed**, not a named pair. Naming modules is how +the guard went stale before: a schedule added in a later migration kept comparing the +original three against three and stayed green while the invariant it names was violated. +Migrations are run in order against fake models, so rows a later migration rewrites are +compared in their final state. + +``0006_split_aggregation_schedule`` then splits the aggregation into two rows by tier. +It writes both scheduler tables from one spec, so the new row cannot drift by +construction — but it also rewrites an existing row, and *how* it does that is +load-bearing. The last sections cover that, the ownership it inherits, and the rollback. + +DB-free — nothing here touches a database. """ from __future__ import annotations import importlib +import inspect import json +import os +import re +from pathlib import Path +from types import SimpleNamespace +from typing import Any +import django import pytest +from django.apps import apps + +os.environ.setdefault("DJANGO_SETTINGS_MODULE", "backend.settings.test") +if not apps.ready: + django.setup() -_BEAT_MIGRATION = "dashboard_metrics.migrations.0002_setup_periodic_tasks" -_PG_MIGRATION = "dashboard_metrics.migrations.0004_pg_periodic_tasks" +from django.db import migrations # noqa: E402 -# Cron equivalent of each Beat schedule, asserted against what the Beat migration builds. -# Written out rather than derived: deriving it from the same code under test would make -# the comparison vacuous. +from dashboard_metrics.tasks import ( # noqa: E402 + AggregationTier, + aggregate_metrics_from_sources, + cleanup_daily_metrics, + cleanup_hourly_metrics, +) + +_MIGRATIONS_PKG = "dashboard_metrics.migrations" +_MIGRATIONS_DIR = Path(__file__).resolve().parent.parent / "migrations" + +# Cron equivalent of each schedule, written out rather than derived: an anchor that a +# reviewer reads, and that an edit to both declarations at once still has to touch. _EXPECTED_CRON = { "dashboard_metrics_aggregate_from_sources": "*/15 * * * *", "dashboard_metrics_cleanup_hourly": "0 2 * * *", "dashboard_metrics_cleanup_daily": "0 3 * * 0", + "dashboard_metrics_reconcile_source_window": "40 4 * * *", + # Added by 0006 from a CrontabSchedule, off the */15 grid. That separates the + # starts on the PG scheduler; the row it splits from is the IntervalSchedule. + "dashboard_metrics_aggregate_daily_monthly": "20 * * * *", } -@pytest.fixture(scope="module") -def pg_specs() -> dict[str, dict]: - mod = importlib.import_module(_PG_MIGRATION) - return {spec["name"]: spec for spec in mod.PG_PERIODIC_TASKS} +class _Schedule: + """Stands in for an Interval/CrontabSchedule row, carrying its own cron string.""" + def __init__(self, **kwargs): + self.kwargs = kwargs -class _FakeQuerySet: - """Captures update_or_create calls from the Beat migration without a database.""" + @property + def cron_string(self) -> str: + k = self.kwargs + if "period" in k: + every, period = k["every"], k["period"] + if period == "minutes": + return f"*/{every} * * * *" + if period == "hours": + return f"0 */{every} * * *" + raise AssertionError(f"unhandled interval period: {period}") + return " ".join( + str(k[f]) + for f in ("minute", "hour", "day_of_month", "month_of_year", "day_of_week") + ) - def __init__(self, sink: dict): - self._sink = sink + +class _Rows: + """Captures a migration's writes to one model without a database.""" + + def __init__(self, factory=None): + self.rows: dict[str, dict] = {} + self.writes = 0 + self._factory = factory + self._selected: list[str] = [] def get_or_create(self, **kwargs): - # Schedule rows (Interval/Crontab) — return the kwargs so the PeriodicTask - # call can be inspected for which schedule it was given. - return kwargs, True + kwargs.pop("defaults", None) + return (self._factory(**kwargs) if self._factory else kwargs), True - def update_or_create(self, name=None, defaults=None, **_kw): - self._sink[name] = defaults or {} - return defaults, True + def update_or_create(self, name=None, defaults=None, **kwargs): + self.writes += 1 + if name is None: # e.g. PeriodicTasks(ident=1) — not a schedule row + return defaults, True + self.rows.setdefault(name, {}).update(defaults or {}) + return self.rows[name], True - def filter(self, *_a, **_k): + def filter(self, name=None, name__in=None, **_kwargs): + self._selected = [name] if name is not None else list(name__in or []) return self + def first(self): + """The row a migration reads back, e.g. to inherit scheduler ownership.""" + name = self._selected[0] if self._selected else None + if name not in self.rows: + return None + return SimpleNamespace(**{"enabled": True, "pg_owned": False, **self.rows[name]}) + + def update(self, **kwargs): + self.writes += 1 + for name in self._selected: + self.rows.setdefault(name, {}).update(kwargs) + return len(self._selected) + def delete(self): + self.writes += 1 + for name in self._selected: + self.rows.pop(name, None) return (0, {}) +class _Apps: + def __init__(self): + self.beat = _Rows() + self.pg = _Rows() + self.schedules = _Rows(factory=_Schedule) + self.tracker = _Rows() + self.other = _Rows() + + def get_model(self, app_label, model_name): + target = { + ("django_celery_beat", "PeriodicTask"): self.beat, + ("pg_queue", "PgPeriodicTask"): self.pg, + ("django_celery_beat", "CrontabSchedule"): self.schedules, + ("django_celery_beat", "IntervalSchedule"): self.schedules, + ("django_celery_beat", "PeriodicTasks"): self.tracker, + }.get((app_label, model_name), self.other) + return type("_M", (), {"objects": target}) + + +def _migration_modules() -> list[str]: + names = sorted( + p.stem for p in _MIGRATIONS_DIR.glob("*.py") if re.match(r"^\d{4}_", p.stem) + ) + assert names, "no migrations discovered — the glob is wrong, not the app" + return [f"{_MIGRATIONS_PKG}.{name}" for name in names] + + @pytest.fixture(scope="module") -def beat_specs() -> dict[str, dict]: - """Run the Beat migration's forward function against fakes and capture what it declares.""" - mod = importlib.import_module(_BEAT_MIGRATION) - captured: dict[str, dict] = {} +def declared() -> SimpleNamespace: + """Replay every data migration in order and capture what it declares.""" + apps = _Apps() + for dotted in _migration_modules(): + for op in importlib.import_module(dotted).Migration.operations: + if isinstance(op, migrations.RunPython): + op.code(apps, None) + return SimpleNamespace(beat=apps.beat.rows, pg=apps.pg.rows) - class _Apps: - def get_model(self, _app, model): - if model == "PeriodicTask": - return type("PT", (), {"objects": _FakeQuerySet(captured)}) - return type("S", (), {"objects": _FakeQuerySet({})}) - mod.create_periodic_tasks(_Apps(), None) - return captured +def _beat_cron(row: dict) -> str: + schedule = row.get("crontab") or row.get("interval") + assert schedule is not None, "Beat row declares neither a crontab nor an interval" + return schedule.cron_string class TestDeclarationsAgree: - def test_same_set_of_schedules(self, beat_specs, pg_specs): + def test_same_set_of_schedules(self, declared): # A schedule added to Beat but not PG stops firing the moment the flag flips; # the reverse fires something Beat never knew about. - assert set(beat_specs) == set(pg_specs) + assert set(declared.beat) == set(declared.pg) + + def test_every_known_schedule_is_declared(self, declared): + # Guards the guard: a replay that silently captured nothing would pass the + # set comparison above with two empty sets. + assert set(declared.beat) == set(_EXPECTED_CRON) - @pytest.mark.parametrize("name", sorted(_EXPECTED_CRON)) - def test_task_path_and_queue_match(self, beat_specs, pg_specs, name): - assert pg_specs[name]["task_name"] == beat_specs[name]["task"] - assert pg_specs[name]["queue"] == beat_specs[name]["queue"] + def test_task_path_and_queue_match(self, declared): + for name, beat in declared.beat.items(): + assert declared.pg[name]["task_name"] == beat["task"], name + assert declared.pg[name]["queue"] == beat["queue"], name - @pytest.mark.parametrize("name", sorted(_EXPECTED_CRON)) - def test_kwargs_match_once_decoded(self, beat_specs, pg_specs, name): + def test_kwargs_match_once_decoded(self, declared): # Beat stores kwargs as a JSON *string*; PgPeriodicTask.task_kwargs is a - # JSONField. A mismatch here means the cleanup runs with the wrong retention. - beat_kwargs = json.loads(beat_specs[name].get("kwargs") or "{}") - assert pg_specs[name]["task_kwargs"] == beat_kwargs + # JSONField. A mismatch means the task runs with the wrong arguments. + for name, beat in declared.beat.items(): + assert declared.pg[name]["task_kwargs"] == json.loads( + beat.get("kwargs") or "{}" + ), name + + def test_cadence_matches_across_transports(self, declared): + # Derived from the Beat schedule row rather than from a table, so a cadence + # changed on one transport only fails here whatever its name. + for name, beat in declared.beat.items(): + assert declared.pg[name]["cron_string"] == _beat_cron(beat), name + + def test_cadence_matches_the_written_anchor(self, declared): + for name, cron in _EXPECTED_CRON.items(): + assert declared.pg[name]["cron_string"] == cron + + +# 0002 seeds at install time, when Beat has never started and has nothing stale to +# reload. Every migration after it rewrites a schedule a running Beat already holds. +_INSTALL_MIGRATION = "0002_setup_periodic_tasks" + + +class TestRunningBeatIsToldToReload: + """Historical models fire no post_save, so DatabaseScheduler never reloads. + + Without an explicit ``PeriodicTasks.last_update`` bump a live Beat keeps firing its + in-memory copy: rows this migration adds never fire, rows it rewrites keep their old + arguments. Nothing errors, and the whole change silently does not happen. + """ - @pytest.mark.parametrize("name,cron", sorted(_EXPECTED_CRON.items())) - def test_cron_matches_the_beat_cadence(self, pg_specs, name, cron): - assert pg_specs[name]["cron_string"] == cron + def test_every_post_install_beat_write_bumps_the_change_tracker(self): + checked = 0 + for dotted in _migration_modules(): + if dotted.endswith(_INSTALL_MIGRATION): + continue + for op in importlib.import_module(dotted).Migration.operations: + if not isinstance(op, migrations.RunPython): + continue + for direction in (op.code, op.reverse_code): + if direction is None: + continue + apps = _Apps() + direction(apps, None) + if not apps.beat.writes: + continue + checked += 1 + assert apps.tracker.writes, f"{dotted}.{direction.__name__}" + assert checked, "no post-install Beat writes found — the discovery is broken" + + +class TestDeclaredKwargsAreCallable: + """A schedule row carrying a kwarg its task cannot bind raises TypeError per tick. + + TypeError is not in ``autoretry_for``, and the PG leg drops the message at + MAX_ATTEMPTS=1 — so the schedule silently never runs. Enumerating every declared + row rather than one migration's own spec is the point: the rows are added by + different migrations, and each new one is exactly the case that escapes a guard + scoped to a single module. + """ + + _TASKS = { + task.name: task + for task in ( + aggregate_metrics_from_sources, + cleanup_hourly_metrics, + cleanup_daily_metrics, + ) + } + + def test_every_declared_kwarg_set_binds_to_the_task_signature(self, declared): + for name, row in declared.pg.items(): + task = self._TASKS.get(row["task_name"]) + assert task is not None, f"{name} schedules an unknown task" + named = { + q.name + for q in inspect.signature(task).parameters.values() + if q.kind is not inspect.Parameter.VAR_KEYWORD + } + unknown = set(row["task_kwargs"]) - named + # Named parameters only: `**_ignored` makes bind() accept anything, so + # binding the whole signature stopped catching a misspelled kwarg. + assert not unknown, f"{name} declares kwargs {task.__name__} does not read: {unknown}" class TestSeededInert: - """Applying the migration must not cause anything to fire.""" - - def test_no_spec_declares_itself_pg_owned(self, pg_specs): - # pg_owned is set to False in the migration's defaults, never from the spec — - # this pins that no spec can smuggle ownership in. - assert not any("pg_owned" in spec for spec in pg_specs.values()) - - def test_no_spec_presets_a_run_time(self, pg_specs): - # A non-NULL next_run_at in the past would read as "overdue" and fire a burst - # of catch-up runs the moment the flag is enabled. - for spec in pg_specs.values(): - assert "next_run_at" not in spec - assert "last_run_at" not in spec + """Applying the migrations must not cause anything to fire.""" + + def test_nothing_is_declared_pg_owned(self, declared): + # pg_owned=True would hand the row to the PG scheduler before the rollout + # flag decides, and disable its Beat twin. + assert not any(row.get("pg_owned") for row in declared.pg.values()) + + def test_no_row_presets_a_run_time(self, declared): + # A non-NULL next_run_at in the past reads as "overdue" and fires a burst of + # catch-up runs the moment the flag is enabled. + for row in declared.pg.values(): + assert "next_run_at" not in row + assert "last_run_at" not in row + + +_SPLIT_MIGRATION = "dashboard_metrics.migrations.0006_split_aggregation_schedule" +_NEW_ROW = "dashboard_metrics_aggregate_daily_monthly" +_EXISTING_ROW = "dashboard_metrics_aggregate_from_sources" + + +class _SplitRecorder: + """Captures what 0006 does to one scheduler table, keeping creates and updates apart. + + The distinction is the point: creating a row writes every default, updating one writes + only the named fields. Conflating them is exactly the bug this guards. + """ + + def __init__(self, existing: Any = None) -> None: + self.created: dict[str, dict[str, Any]] = {} + self.updated: dict[str, dict[str, Any]] = {} + self.deleted: list[str] = [] + self.bumps = 0 + # How many rows a filtered update matches. 0 models the row being absent, + # which is the case the migration now refuses to report as success. + self.rows_present: int | None = None + self._existing = existing + self._filtered_on: str = "" + self._filtered_in: list[str] = [] + + def filter( + self, name: str = "", name__in: list[str] | None = None, **_kw: Any + ) -> _SplitRecorder: + self._filtered_on = name + self._filtered_in = list(name__in or []) + return self + + def first(self) -> Any: + # Honours the filter, as a real queryset does. Returning _existing + # unconditionally made every ownership-inheritance assertion pass even when + # the migration filtered on the wrong name — the row it reads does not exist + # when 0006 runs, so a real database would return None and fall back to Beat. + if self._existing is None: + return None + return self._existing if self._filtered_on == _EXISTING_ROW else None + + def update(self, **kwargs: Any) -> int: + # A filtered update that matches nothing returns 0 and writes nothing; it + # never creates the row. Reporting 1 regardless made 0006's forward guard + # unreachable in test, while its mirror in the reverse direction was covered. + matched = 1 if self.rows_present is None else self.rows_present + if matched: + self.updated[self._filtered_on] = kwargs + return matched + + def update_or_create( + self, name: str = "", defaults: dict[str, Any] | None = None, **_kw: Any + ) -> tuple[dict[str, Any], bool]: + if not name: # PeriodicTasks(ident=1) — the Beat reload tracker + self.bumps += 1 + return defaults or {}, True + self.created[name] = defaults or {} + return self.created[name], True + + def get_or_create(self, **kwargs: Any) -> tuple[dict[str, Any], bool]: + return kwargs, True + + def delete(self) -> tuple[int, dict[str, Any]]: + self.deleted.extend(self._filtered_in or [self._filtered_on]) + return (len(self.deleted), {}) + + +def _run_split( + beat_row: Any = None, pg_row: Any = None, rows_present: int | None = None +) -> dict[str, _SplitRecorder]: + """Run 0006's forward function against fakes and capture every table it writes. + + ``rows_present=0`` models the row 0006 splits being absent, which is the case + its forward guard exists to refuse rather than report as success. + """ + mod = importlib.import_module(_SPLIT_MIGRATION) + beat = _SplitRecorder(existing=beat_row) + pg = _SplitRecorder(existing=pg_row) + beat.rows_present = rows_present + pg.rows_present = rows_present + crontab, tracker = _SplitRecorder(), _SplitRecorder() + + class _Apps: + def get_model(self, _app: str, model: str) -> type: + table = { + "PeriodicTask": beat, + "PgPeriodicTask": pg, + "PeriodicTasks": tracker, + }.get(model, crontab) + return type("M", (), {"objects": table}) + + mod.split_schedules(_Apps(), None) + return {"beat": beat, "pg": pg, "tracker": tracker} + + +@pytest.fixture(scope="module") +def split() -> dict[str, _SplitRecorder]: + """The default case: a Beat-owned row, as every environment ships today.""" + return _run_split( + beat_row=SimpleNamespace(enabled=True), + pg_row=SimpleNamespace(enabled=True, pg_owned=False), + ) + + +class TestTheSplitAddsOneRowAndRewritesOne: + def test_only_the_daily_monthly_row_is_created( + self, split: dict[str, _SplitRecorder] + ) -> None: + for table in ("beat", "pg"): + assert set(split[table].created) == {_NEW_ROW} + + def test_only_the_existing_aggregate_row_is_updated( + self, split: dict[str, _SplitRecorder] + ) -> None: + for table in ("beat", "pg"): + assert set(split[table].updated) == {_EXISTING_ROW} + + def test_the_new_row_is_declared_the_same_on_both_tables( + self, split: dict[str, _SplitRecorder] + ) -> None: + beat, pg = split["beat"].created[_NEW_ROW], split["pg"].created[_NEW_ROW] + assert pg["task_name"] == beat["task"] + assert pg["queue"] == beat["queue"] + assert pg["task_kwargs"] == json.loads(beat["kwargs"]) + + def test_the_new_beat_row_carries_no_interval_schedule( + self, split: dict[str, _SplitRecorder] + ) -> None: + """django-celery-beat rejects a row with both, and Beat reads interval first. + + 0002 created the row this splits from on an IntervalSchedule. Leaving it set + alongside the new crontab makes the crontab inert under Beat while the PG + mirror, which reads crontab first, adopts it — one row, two cadences. + """ + assert split["beat"].created[_NEW_ROW]["interval"] is None + + def test_the_new_row_runs_hourly_on_both_tables( + self, split: dict[str, _SplitRecorder] + ) -> None: + assert split["pg"].created[_NEW_ROW]["cron_string"] == "20 * * * *" + crontab = split["beat"].created[_NEW_ROW]["crontab"] + assert (crontab["minute"], crontab["hour"]) == ("20", "*") + + def test_the_two_rows_never_start_together_on_the_pg_scheduler( + self, split: dict[str, _SplitRecorder] + ) -> None: + """The per-tier locks are built so the two runs cannot block each other, so a + shared minute is two full prefilter scans and two per-org loops at once — on a + change whose object is flattening cron load. + + Derived from the existing row's own declaration rather than hardcoded, and + scoped to the PG scheduler: it evaluates cron_string against the wall clock, + while the Beat twin is an IntervalSchedule whose phase drifts, so no minute + this test could assert would separate them there. + """ + mod = importlib.import_module(_SPLIT_MIGRATION) + existing = next( + spec + for spec in mod.AGGREGATION_SCHEDULES + if spec["name"] == mod.EXISTING_AGGREGATE_ROW + ) + minute_field = existing["cron_string"].split()[0] + fires_at = ( + set(range(0, 60, int(minute_field.split("/")[1]))) + if "/" in minute_field + else {int(minute_field)} + ) + minute = int(split["beat"].created[_NEW_ROW]["crontab"]["minute"]) + assert minute not in fires_at + + def test_the_new_row_is_seeded_inert_on_the_pg_side( + self, split: dict[str, _SplitRecorder] + ) -> None: + """Same reason as 0004's rows: a PG row that is pg_owned before the scheduler + has adopted it would fire alongside its Beat twin. + """ + assert split["pg"].created[_NEW_ROW]["pg_owned"] is False + + def test_the_rewritten_row_carries_the_same_kwargs_on_both_tables( + self, split: dict[str, _SplitRecorder] + ) -> None: + """The row firing the hourly tier every 15 minutes in production. + + Beat's ``kwargs`` is a TextField it parses with ``json.loads``; writing the + mapping rather than its JSON encoding stores a Python repr, ``ModelEntry`` + raises, and the hourly aggregation silently stops firing. + """ + beat = split["beat"].updated[_EXISTING_ROW] + assert ( + json.loads(beat["kwargs"]) + == split["pg"].updated[_EXISTING_ROW]["task_kwargs"] + ) + + def test_the_two_rows_ask_for_different_tiers( + self, split: dict[str, _SplitRecorder] + ) -> None: + new = split["pg"].created[_NEW_ROW]["task_kwargs"]["tier"] + existing = split["pg"].updated[_EXISTING_ROW]["task_kwargs"]["tier"] + assert new != existing + + +class TestTheNewRowInheritsWhoeverFiresTheRowItSplitsFrom: + """Hardcoding Beat leaves the daily/monthly tier with no firer in a PG-adopted + environment: the adopted row's Beat twin is disabled and Beat may be scaled to + zero, so the sole writer of those figures never runs and the hourly run still + reports success. + """ + + def test_a_pg_adopted_row_hands_its_new_half_to_the_pg_scheduler(self) -> None: + split = _run_split( + beat_row=SimpleNamespace(enabled=False), + pg_row=SimpleNamespace(enabled=True, pg_owned=True), + ) + assert split["pg"].created[_NEW_ROW]["pg_owned"] is True + assert split["pg"].created[_NEW_ROW]["enabled"] is True + assert split["beat"].created[_NEW_ROW]["enabled"] is False + + def test_a_disabled_row_does_not_come_back_as_an_enabled_half(self) -> None: + split = _run_split( + beat_row=SimpleNamespace(enabled=False), + pg_row=SimpleNamespace(enabled=False, pg_owned=False), + ) + assert split["beat"].created[_NEW_ROW]["enabled"] is False + assert split["pg"].created[_NEW_ROW]["enabled"] is False + + def test_a_missing_row_is_created_rather_than_aborting_migrate(self) -> None: + """A transport with no row fires nothing, so there is nothing to double up + with — 0006 creates it instead of raising. + + Raising failed `migrate` for every app in the project, and recovery meant + hand-inserting a row into an operator-editable scheduler table. The hazard + the guard named (an old row left on kwargs="{}" firing alongside the new + one) cannot arise from the state that triggered it. + """ + split = _run_split(beat_row=None, pg_row=None, rows_present=0) + + assert _EXISTING_ROW in split["beat"].created + assert _EXISTING_ROW in split["pg"].created + assert json.loads(split["beat"].created[_EXISTING_ROW]["kwargs"]) == { + "tier": "hourly" + } + + +class TestARunningBeatIsToldToReload: + """Historical models fire no post_save, so DatabaseScheduler never reloads. + + Without an explicit bump the existing row keeps firing with no tier and the new + row never fires at all — no error, nothing logged, and the whole saving silently + does not happen. + """ + + def test_the_forward_direction_bumps_the_change_tracker(self, split) -> None: + assert split["tracker"].bumps == 1 + + def test_the_reverse_direction_bumps_it_too(self) -> None: + mod = importlib.import_module(_SPLIT_MIGRATION) + tracker, other = _SplitRecorder(), _SplitRecorder() + + class _Apps: + def get_model(self, _app: str, model: str) -> type: + table = tracker if model == "PeriodicTasks" else other + return type("M", (), {"objects": table}) + + mod.merge_schedules(_Apps(), None) + assert tracker.bumps == 1 + + +class TestTheFrozenLiteralsMatchTheEnumToday: + """These are wire values, so a rename has to fail loudly rather than pass. + + The migration cannot import the enum, and it never re-runs — so renaming an + AggregationTier value and "keeping this in step" leaves live rows carrying the old + string while every test goes green. Comparing the two here turns that into a + failure at the moment of the rename. + """ + + def test_the_declared_tiers_are_exactly_the_schedulable_ones(self) -> None: + mod = importlib.import_module(_SPLIT_MIGRATION) + declared = {spec["tier"] for spec in mod.AGGREGATION_SCHEDULES} + # ALL is the signature default and the pre-migration row's meaning; no + # schedule row ever carries it. + schedulable = {t.value for t in AggregationTier} - {AggregationTier.ALL.value} + assert declared == schedulable + + +class TestTheRollbackRestoresOneRow: + """merge_schedules is this PR's stated safety story and had no coverage at all.""" + + def _run_merge(self, rows_present: int | None = None): + mod = importlib.import_module(_SPLIT_MIGRATION) + beat, pg, tracker = _SplitRecorder(), _SplitRecorder(), _SplitRecorder() + beat.rows_present = rows_present + pg.rows_present = rows_present + + class _Apps: + def get_model(self, _app: str, model: str) -> type: + table = { + "PeriodicTask": beat, + "PgPeriodicTask": pg, + "PeriodicTasks": tracker, + }.get(model, _SplitRecorder()) + return type("M", (), {"objects": table}) + + mod.merge_schedules(_Apps(), None) + return {"beat": beat, "pg": pg, "tracker": tracker} + + def test_the_added_row_is_deleted_from_both_tables(self) -> None: + merged = self._run_merge() + for table in ("beat", "pg"): + assert _NEW_ROW in merged[table].deleted + + def test_the_existing_row_gets_its_pre_split_payload_back(self) -> None: + merged = self._run_merge() + assert merged["beat"].updated[_EXISTING_ROW]["kwargs"] == "{}" + assert merged["pg"].updated[_EXISTING_ROW]["task_kwargs"] == {} + + def test_the_rollback_leaves_ownership_alone_like_the_forward_direction(self) -> None: + merged = self._run_merge() + assert "enabled" not in merged["beat"].updated[_EXISTING_ROW] + assert set(merged["pg"].updated[_EXISTING_ROW]) == {"task_kwargs"} + + def test_a_rollback_that_restores_nothing_raises(self) -> None: + """A bulk update matching no row would otherwise report a clean rollback while + leaving the daily and monthly tiers with no schedule at all. + """ + with pytest.raises(RuntimeError, match=_EXISTING_ROW): + self._run_merge(rows_present=0) + + +class TestTheRewriteLeavesSchedulerOwnershipAlone: + """The existing row may already be owned by the PG scheduler, with its Beat twin + disabled by converge_pg_scheduler. Rewriting `pg_owned` or `enabled` here would + hand it back — and since the Beat twin stays disabled, the aggregation would be + left with no firer at all. Only the payload may change. + """ + + def test_the_pg_update_touches_only_the_kwargs( + self, split: dict[str, _SplitRecorder] + ) -> None: + assert set(split["pg"].updated[_EXISTING_ROW]) == {"task_kwargs"} + + def test_the_beat_update_does_not_re_enable_the_row( + self, split: dict[str, _SplitRecorder] + ) -> None: + assert "enabled" not in split["beat"].updated[_EXISTING_ROW] + + def test_the_existing_row_keeps_its_cadence( + self, split: dict[str, _SplitRecorder] + ) -> None: + """Only the daily/monthly half moves to hourly; the hourly tier stays at 15 + minutes, which is the first half of the ticket's acceptance criteria. + """ + for table in ("beat", "pg"): + update = split[table].updated[_EXISTING_ROW] + assert not {"crontab", "interval", "cron_string"} & set(update) diff --git a/backend/dashboard_metrics/tests/test_tasks.py b/backend/dashboard_metrics/tests/test_tasks.py index 03ef136508..6b238825f9 100644 --- a/backend/dashboard_metrics/tests/test_tasks.py +++ b/backend/dashboard_metrics/tests/test_tasks.py @@ -1,20 +1,57 @@ """Unit tests for Dashboard Metrics Celery tasks.""" -from datetime import datetime, timedelta +import json +import time +from datetime import UTC, date, datetime, timedelta +from importlib import import_module +from types import SimpleNamespace +from unittest.mock import patch -from django.test import TestCase +from account_v2.models import Organization +from celery.exceptions import SoftTimeLimitExceeded +from django.apps import apps +from django.core.cache import cache +from django.db import connection +from django.db.utils import DatabaseError +from django.test import TestCase, override_settings +from django.test.utils import CaptureQueriesContext from django.utils import timezone +from django_celery_beat.models import PeriodicTask, PeriodicTasks +from pg_queue.models import PgPeriodicTask +from workflow_manager.file_execution.models import WorkflowFileExecution +from workflow_manager.workflow_v2.enums import ExecutionStatus +from workflow_manager.workflow_v2.models.execution import WorkflowExecution +from workflow_manager.workflow_v2.models.workflow import Workflow -from account_v2.models import Organization +from dashboard_metrics.internal_views import AggregateMetricsAPIView from dashboard_metrics.models import ( EventMetricsDaily, EventMetricsHourly, + EventMetricsMonthly, + Granularity, MetricType, ) +from dashboard_metrics.services import MetricsQueryService from dashboard_metrics.tasks import ( - _truncate_to_day, + LOWERED_MONTHS_REPORT_LIMIT, + DASHBOARD_RECONCILE_WINDOW_DAYS, + DASHBOARD_SOURCE_WINDOW_DAYS, + AggregationTier, + _acquire_aggregation_lock, + _acquire_aggregation_locks, + _release_aggregation_locks, + _active_org_ids, + _aggregation_lock_keys, + _months_missing_days, + _name_lowered_pairs, + _pairs_the_rollup_would_lower, + _rollup_monthly_from_daily, + _run_aggregation, + truncate_to_day, _truncate_to_hour, _truncate_to_month, + _validate_source_window, + aggregate_metrics_from_sources, cleanup_daily_metrics, cleanup_hourly_metrics, ) @@ -37,7 +74,6 @@ def test_truncate_to_hour_from_timestamp(self): def test_truncate_to_hour_from_datetime(self): """Test truncating a datetime to the hour.""" - dt = datetime(2024, 1, 15, 14, 35, 22, tzinfo=timezone.utc) result = _truncate_to_hour(dt) @@ -48,7 +84,6 @@ def test_truncate_to_hour_from_datetime(self): def test_truncate_to_hour_naive_datetime(self): """Test truncating a naive datetime makes it aware.""" - dt = datetime(2024, 1, 15, 14, 35, 22) result = _truncate_to_hour(dt) @@ -56,11 +91,10 @@ def test_truncate_to_hour_naive_datetime(self): assert result.hour == 14 assert result.minute == 0 - def test_truncate_to_day(self): + def testtruncate_to_day(self): """Test truncating a datetime to midnight.""" - dt = datetime(2024, 1, 15, 14, 35, 22, tzinfo=timezone.utc) - result = _truncate_to_day(dt) + result = truncate_to_day(dt) assert result.day == 15 assert result.hour == 0 @@ -70,7 +104,6 @@ def test_truncate_to_day(self): def test_truncate_to_month(self): """Test truncating a datetime to first day of month.""" - dt = datetime(2024, 1, 15, 14, 35, 22, tzinfo=timezone.utc) result = _truncate_to_month(dt) @@ -127,8 +160,12 @@ def test_cleanup_hourly_metrics_deletes_old_records(self): # _base_manager bypasses the org-scoped default manager, which filters # by UserContext.get_organization() — None here, so .objects sees nothing. - assert not EventMetricsHourly._base_manager.filter(metric_name="old_metric").exists() - assert EventMetricsHourly._base_manager.filter(metric_name="recent_metric").exists() + assert not EventMetricsHourly._base_manager.filter( + metric_name="old_metric" + ).exists() + assert EventMetricsHourly._base_manager.filter( + metric_name="recent_metric" + ).exists() def test_cleanup_daily_metrics_deletes_old_records(self): """Test that cleanup deletes daily records older than retention.""" @@ -198,3 +235,1597 @@ def test_cleanup_no_records_to_delete(self): assert result["success"] is True assert result["deleted"] == 0 + + +class TestMonthlyRollup(TestCase): + """Tests for deriving monthly metrics from the daily tier.""" + + def setUp(self): + """Set up test fixtures.""" + self.org = Organization.objects.create( + organization_id="rollup-org", name="rollup-org", display_name="Rollup Org" + ) + + def _daily( + self, + day, + value, + count=1, + metric_type=MetricType.COUNTER, + metric_name="documents_processed", + org=None, + ): + """Create a daily metric row, defaulting to the fixture org and metric.""" + EventMetricsDaily.objects.create( + organization=org or self.org, + date=day, + metric_name=metric_name, + metric_type=metric_type, + metric_value=value, + metric_count=count, + project="default", + ) + + def _monthly_rows(self): + """Read back monthly rows in a stable order.""" + return list( + EventMetricsMonthly._base_manager.order_by( + "month", "organization_id", "metric_name" + ) + ) + + def test_sums_daily_rows_into_month_bucket(self): + """Daily rows within a month sum into a single monthly row.""" + self._daily(date(2024, 3, 5), value=10, count=2) + self._daily(date(2024, 3, 18), value=32, count=4) + + assert _rollup_monthly_from_daily(date(2024, 3, 1)) == 1 + + rows = self._monthly_rows() + assert len(rows) == 1 + assert rows[0].month == date(2024, 3, 1) + assert rows[0].metric_value == 42 + assert rows[0].metric_count == 6 + + def test_month_boundary_keeps_months_separate(self): + """Rows spanning the 1st land in two months without bleeding.""" + self._daily(date(2024, 1, 30), value=5) + self._daily(date(2024, 1, 31), value=7) + self._daily(date(2024, 2, 1), value=100) + self._daily(date(2024, 2, 2), value=200) + + assert _rollup_monthly_from_daily(date(2024, 1, 1)) == 2 + + rows = self._monthly_rows() + assert [r.month for r in rows] == [date(2024, 1, 1), date(2024, 2, 1)] + assert [r.metric_value for r in rows] == [12, 300] + + def test_excludes_months_before_the_window(self): + """Daily rows older than month_start are not rolled up.""" + self._daily(date(2023, 12, 15), value=999) + self._daily(date(2024, 1, 15), value=5) + + assert _rollup_monthly_from_daily(date(2024, 1, 1)) == 1 + + rows = self._monthly_rows() + assert len(rows) == 1 + assert rows[0].month == date(2024, 1, 1) + + def test_rerun_overwrites_instead_of_accumulating(self): + """A second rollup replaces the monthly total rather than doubling it.""" + self._daily(date(2024, 3, 5), value=10, count=2) + _rollup_monthly_from_daily(date(2024, 3, 1)) + + self._daily(date(2024, 3, 6), value=5, count=1) + _rollup_monthly_from_daily(date(2024, 3, 1)) + + rows = self._monthly_rows() + assert len(rows) == 1 + assert rows[0].metric_value == 15 + assert rows[0].metric_count == 3 + + def test_mixed_metric_type_within_a_month_yields_one_row(self): + """metric_type is aggregated, so it cannot split one conflict target.""" + self._daily(date(2024, 3, 5), value=10, metric_type=MetricType.HISTOGRAM) + self._daily(date(2024, 3, 6), value=5, metric_type=MetricType.COUNTER) + + assert _rollup_monthly_from_daily(date(2024, 3, 1)) == 1 + + rows = self._monthly_rows() + assert len(rows) == 1 + assert rows[0].metric_value == 15 + + def test_an_empty_daily_tier_leaves_existing_monthly_rows_alone(self): + """An empty tier means the source is gone, not that every month is zero. + + Seeding a monthly row first is what makes the failure reachable at all: with + an empty table an implementation that wipes and one that writes nothing both + leave an empty table, and the assertion passes either way. + """ + EventMetricsMonthly._base_manager.create( + organization=self.org, + month=date(2024, 3, 1), + metric_name="documents_processed", + metric_type=MetricType.COUNTER, + metric_value=42, + metric_count=6, + project="default", + ) + + assert _rollup_monthly_from_daily(date(2024, 3, 1)) == 0 + + rows = self._monthly_rows() + assert len(rows) == 1 + assert rows[0].metric_value == 42 + + def test_a_metric_whose_daily_rows_are_gone_keeps_its_last_total(self): + """Upsert-only, per the design agreed on UN-3973. + + A stale total is recoverable — backfill_metrics rewrites it. A deleted row is + not, because the daily rows that would rebuild it are exactly what is missing. + """ + self._daily(date(2024, 3, 5), value=10) + self._daily(date(2024, 3, 6), value=7, metric_name="pages_processed") + assert _rollup_monthly_from_daily(date(2024, 3, 1)) == 2 + + EventMetricsDaily._base_manager.filter(metric_name="pages_processed").delete() + assert _rollup_monthly_from_daily(date(2024, 3, 1)) == 1 + + rows = self._monthly_rows() + assert [r.metric_name for r in rows] == ["documents_processed", "pages_processed"] + + def test_a_partially_repopulated_month_is_overwritten_not_accumulated(self): + """The realistic post-downtime shape: the daily tier comes back short. + + The total tracks whatever the daily tier currently holds, so repairing daily + repairs monthly on the next run — which is what makes upsert-only recoverable. + """ + self._daily(date(2024, 3, 5), value=10) + self._daily(date(2024, 3, 6), value=32) + assert _rollup_monthly_from_daily(date(2024, 3, 1)) == 1 + assert self._monthly_rows()[0].metric_value == 42 + + EventMetricsDaily._base_manager.filter(date=date(2024, 3, 6)).delete() + _rollup_monthly_from_daily(date(2024, 3, 1)) + assert self._monthly_rows()[0].metric_value == 10 + + self._daily(date(2024, 3, 6), value=32) + _rollup_monthly_from_daily(date(2024, 3, 1)) + assert self._monthly_rows()[0].metric_value == 42 + + def test_rows_for_other_organizations_are_never_touched(self): + """The rollup goes through _base_manager, bypassing the org-scoped default.""" + other = Organization.objects.create( + organization_id="rollup-org-2", name="rollup-org-2", display_name="Other" + ) + self._daily(date(2024, 3, 5), value=10) + self._daily(date(2024, 3, 6), value=20, org=other) + assert _rollup_monthly_from_daily(date(2024, 3, 1)) == 2 + + EventMetricsDaily._base_manager.filter(organization=other).delete() + assert _rollup_monthly_from_daily(date(2024, 3, 1)) == 1 + + rows = self._monthly_rows() + assert [(r.organization_id, r.metric_value) for r in rows] == [ + (self.org.id, 10), + (other.id, 20), + ] + + def test_months_before_the_window_are_left_alone(self): + """A month before month_start is untouched by a later rollup.""" + self._daily(date(2024, 1, 10), value=99) + _rollup_monthly_from_daily(date(2024, 1, 1)) + EventMetricsDaily._base_manager.all().delete() + + self._daily(date(2024, 3, 5), value=10) + _rollup_monthly_from_daily(date(2024, 3, 1)) + + months = [row.month for row in self._monthly_rows()] + assert months == [date(2024, 1, 1), date(2024, 3, 1)] + + +class TestRollupQueryShape(TestCase): + """The monthly rollup must not read the raw source tables.""" + + def test_monthly_rollup_never_touches_source_tables(self): + """This is the saving: monthly reads the daily tier and nothing else.""" + EventMetricsDaily._base_manager.create( + organization=Organization.objects.create( + organization_id="shape-org", name="shape", display_name="Shape" + ), + date=date(2024, 3, 5), + metric_name="documents_processed", + metric_type=MetricType.COUNTER, + metric_value=10, + metric_count=2, + project="default", + tag="", + ) + + with CaptureQueriesContext(connection) as captured: + _rollup_monthly_from_daily(date(2024, 3, 1)) + + sql = " ".join(q["sql"] for q in captured.captured_queries).lower() + assert "event_metrics_daily" in sql + for source_table in ( + "workflow_file_execution", + "workflow_execution", + "page_usage", + ): + assert source_table not in sql, f"monthly rollup read {source_table}" + + +class TestActiveOrgPrefilter(TestCase): + """The prefilter must never be narrower than the window it is filtering for.""" + + def setUp(self): + self.org = Organization.objects.create( + organization_id="prefilter-org", name="prefilter", display_name="Prefilter" + ) + workflow = Workflow.objects.create( + workflow_name="prefilter-wf", organization=self.org + ) + self.now = timezone.now() + execution = WorkflowExecution.objects.create( + workflow_id=workflow.id, status=ExecutionStatus.COMPLETED + ) + WorkflowExecution.objects.filter(pk=execution.pk).update( + created_at=self.now - timedelta(days=10) + ) + + def test_an_org_outside_the_default_lookback_is_filtered_out(self): + """The default lookback is the cheap case and stays exactly as wide as before.""" + window_start = self.now - timedelta(days=DASHBOARD_SOURCE_WINDOW_DAYS) + assert self.org.id not in _active_org_ids(self.now, window_start) + + def test_a_widened_window_widens_the_prefilter_with_it(self): + """Otherwise a long-outage repair queries 30 days for orgs active in 7, and + reports errors: 0 having skipped every org it exists to repair. + """ + window_start = self.now - timedelta(days=30) + assert self.org.id in _active_org_ids(self.now, window_start) + + def test_the_floor_keeps_an_org_older_than_the_source_window(self): + """The only region the DASHBOARD_ACTIVE_ORG_LOOKBACK_DAYS floor governs. + + Between the 2-day source window and the 7-day floor. The two cases above + bracket it without covering it: at 10 days the org is outside both bounds, + and the 30-day case pins only the window_start half of the min(). Drop the + floor and every org whose last execution is 3-7 days old silently leaves the + run — which is what the floor exists to prevent, since metrics keyed on + another column (approved_at) still land for them. + """ + stale_org = Organization.objects.create( + organization_id="floor-org", name="floor", display_name="Floor" + ) + workflow = Workflow.objects.create( + workflow_name="floor-wf", organization=stale_org + ) + execution = WorkflowExecution.objects.create( + workflow_id=workflow.id, status=ExecutionStatus.COMPLETED + ) + WorkflowExecution.objects.filter(pk=execution.pk).update( + created_at=self.now - timedelta(days=5) + ) + + window_start = self.now - timedelta(days=DASHBOARD_SOURCE_WINDOW_DAYS) + assert stale_org.id in _active_org_ids(self.now, window_start) + + +class TestMonthlyRollupFailurePosture(TestCase): + """The rollup's errors must be counted, so success is False without a retry.""" + + def test_a_database_error_is_counted_rather_than_raised(self): + """Raising bought a retry on one transport and a dropped message on the other. + + On Celery the exception reaches autoretry_for and each attempt re-runs the + whole aggregation — three more full passes in seconds, against a database + that just reported it is struggling. On the internal-HTTP path Task.retry + re-raises under called_directly, so nothing retries and MAX_ATTEMPTS=1 drops + the message. Counting it sets success: False on both, which is the signal + the raise was standing in for. + """ + with patch("dashboard_metrics.tasks.WorkflowExecution") as mock_execution: + prefilter = mock_execution.objects.filter.return_value + prefilter.values_list.return_value.distinct.return_value = [1] + with patch( + "dashboard_metrics.tasks._rollup_monthly_from_daily", + side_effect=DatabaseError("lock timeout"), + ): + result = _run_aggregation() + + assert result["success"] is False + assert result["errors"] == 1 + assert result["monthly"]["failed"] is True + + def test_an_unexpected_error_is_counted_but_does_not_abort_the_run(self): + """Everything outside the retry set stays non-fatal — the hourly and daily + tiers this run already wrote are kept — but it is not reported as success. + """ + with patch("dashboard_metrics.tasks.WorkflowExecution") as mock_execution: + prefilter = mock_execution.objects.filter.return_value + prefilter.values_list.return_value.distinct.return_value = [1] + with patch( + "dashboard_metrics.tasks._rollup_monthly_from_daily", + side_effect=ValueError("bad row"), + ): + result = _run_aggregation() + assert result["success"] is False + assert result["errors"] == 1 + assert result["monthly"]["failed"] is True + + +class TestInternalAggregateEndpoint(TestCase): + """The PG transport reaches the task through this view, not through Celery.""" + + def _post(self, data): + return AggregateMetricsAPIView().post(SimpleNamespace(data=data)) + + def test_the_source_window_reaches_the_task(self): + with patch( + "dashboard_metrics.internal_views.aggregate_metrics_from_sources", + return_value={"success": True}, + ) as task: + self._post({"source_window_days": 7}) + assert task.call_args.kwargs == {"source_window_days": 7} + + def test_omitting_it_leaves_the_task_default_in_charge(self): + with patch( + "dashboard_metrics.internal_views.aggregate_metrics_from_sources", + return_value={"success": True}, + ) as task: + self._post({}) + assert task.call_args.kwargs == {} + + def test_an_unrecognised_body_key_is_a_400(self): + """Ignored, it answered 200 having run every tier at the default window. + + `{"teir": ...}` is the realistic shape — a hand-run repair during an + incident, answered as though it did what was asked. + """ + with patch( + "dashboard_metrics.internal_views.aggregate_metrics_from_sources" + ) as task: + response = self._post({"teir": "hourly"}) + assert response.status_code == 400 + task.assert_not_called() + + def test_a_window_over_the_maximum_is_a_400(self): + """The bound this diff added at the boundary. + + Without it the value reaches the task, whose own ValueError is no longer + mapped to a 400 — so an over-wide window becomes a logged 500, the exact + inversion moving validation to the boundary was for. + """ + with patch( + "dashboard_metrics.internal_views.aggregate_metrics_from_sources" + ) as task: + response = self._post({"source_window_days": 365}) + assert response.status_code == 400 + task.assert_not_called() + + def test_a_non_integer_window_is_a_400(self): + with patch( + "dashboard_metrics.internal_views.aggregate_metrics_from_sources" + ) as task: + response = self._post({"source_window_days": "seven"}) + assert response.status_code == 400 + task.assert_not_called() + + +class TestMonthlyThroughTheTask(TestCase): + """The rollup as the task actually runs it, not via the helper directly. + + Every other rollup test calls ``_rollup_monthly_from_daily`` with a hand-chosen + ``month_start``. Nothing exercised the arithmetic that computes it, nor the sweep + running against a monthly table that already holds rows from earlier runs — so a + regression to "first of the current month" would silently drop last month's rows + with the whole rollup suite still green. + """ + + def setUp(self): + self.org = Organization.objects.create( + organization_id="entry-org", name="entry-org", display_name="Entry Org" + ) + self.now = timezone.now() + now = self.now + self.this_month = _truncate_to_month(now).date() + self.last_month = _truncate_to_month( + _truncate_to_month(now) - timedelta(days=1) + ).date() + self.before_window = _truncate_to_month( + _truncate_to_month(now - timedelta(days=1)) - timedelta(days=40) + ).date() + + def _daily(self, day, value, metric_name="documents_processed"): + EventMetricsDaily._base_manager.create( + organization=self.org, + date=day, + metric_name=metric_name, + metric_type=MetricType.COUNTER, + metric_value=value, + metric_count=1, + project="default", + tag="", + ) + + def _monthly(self, month, value, metric_name="documents_processed"): + EventMetricsMonthly._base_manager.create( + organization=self.org, + month=month, + metric_name=metric_name, + metric_type=MetricType.COUNTER, + metric_value=value, + metric_count=1, + project="default", + tag="", + ) + + def _run(self, **kwargs): + # setUp derives this_month/last_month from one clock reading; the run must + # use the same one, or a run straddling a month boundary fails on the 1st. + with patch("dashboard_metrics.tasks.WorkflowExecution") as mock_execution: + prefilter = mock_execution.objects.filter.return_value + prefilter.values_list.return_value.distinct.return_value = [self.org.id] + with patch("dashboard_metrics.tasks.timezone.now", return_value=self.now): + return _run_aggregation(**kwargs) + + def test_the_window_covers_the_previous_month_and_spares_what_precedes_it(self): + """monthly_start is the first of the *previous* month, and the sweep stops there.""" + self._daily(self.this_month, value=10) + self._daily(self.last_month, value=20) + self._monthly(self.before_window, value=999) + + result = self._run() + + assert result["period"]["monthly"]["start"] == self.last_month.isoformat() + assert result["monthly"]["upserted"] == 2 + assert result["monthly"]["failed"] is False + # A correct rollup lowers nothing, so it says nothing. The detector fires on + # a total that actually fell, not on a calendar heuristic that would flag an + # idle day or a fresh install as damage. + assert "needs_daily_repair" not in result["monthly"] + + rows = EventMetricsMonthly._base_manager.order_by("month") + assert [r.month for r in rows] == [ + self.before_window, + self.last_month, + self.this_month, + ] + + def test_a_failed_rollup_is_not_reported_as_nothing_to_do(self): + """Upserted stays 0 on failure, which is also the legitimate empty value. + + Three states used to collapse into one alongside success: True — failed, + empty, and no active orgs. + """ + self._daily(self.this_month, value=10) + with patch( + "dashboard_metrics.tasks._rollup_monthly_from_daily", + side_effect=ValueError("bad row"), + ): + result = self._run() + + assert result["monthly"] == {"upserted": 0, "failed": True} + assert result["success"] is False + + +class TestMonthlyMatchesTheOldDerivation(TestCase): + """AC-4: the new monthly figures equal the ones the source queries produced. + + Every other monthly test feeds hand-written daily rows in and checks the sum of + what it just wrote — self-consistency, not equivalence. This one seeds *source* + rows, lets the real aggregation populate the daily tier from them, and compares + the rolled-up monthly against the pre-change derivation computed independently: + `get_documents_processed` at DAY granularity, bucketed by month in Python. + + The window is deliberately wide enough to cover both months, which is the state + `backfill_metrics` establishes before this change is deployed. + """ + + def setUp(self): + self.org = Organization.objects.create( + organization_id="golden-org", name="golden-org", display_name="Golden Org" + ) + self.workflow = Workflow.objects.create( + workflow_name="golden-wf", organization=self.org + ) + # Offsets are derived from the month boundary, never fixed day counts: on the + # 25th of a month a hardcoded "25 days ago" lands in the current month and the + # cross-boundary coverage silently disappears. + # One clock reading for setUp, _seed and the run: three separate ones put + # the seeds and the window in different months across a boundary. + self.now = timezone.now() + now = self.now + first_of_this_month = _truncate_to_month(now) + self.days_to_last_month_end = (now - first_of_this_month).days + 1 + self.days_to_last_month_start = ( + now - _truncate_to_month(first_of_this_month - timedelta(days=1)) + ).days + + def _seed(self, days_ago: int, count: int) -> None: + """Seed `count` completed file executions dated `days_ago`.""" + stamp = self.now - timedelta(days=days_ago) + for n in range(count): + execution = WorkflowExecution.objects.create( + workflow=self.workflow, status=ExecutionStatus.COMPLETED + ) + file_execution = WorkflowFileExecution.objects.create( + workflow_execution=execution, + file_name=f"{days_ago}-{n}.pdf", + status=ExecutionStatus.COMPLETED.value, + ) + WorkflowFileExecution.objects.filter(pk=file_execution.pk).update( + created_at=stamp + ) + WorkflowExecution.objects.filter(pk=execution.pk).update(created_at=stamp) + + def _written(self) -> dict: + """Monthly totals as the rollup wrote them.""" + return { + row.month: row.metric_value + for row in EventMetricsMonthly._base_manager.filter( + metric_name="documents_processed" + ) + } + + def _oracle(self, monthly_start, end_date) -> dict: + """Monthly totals the way the code derived them before this change.""" + rows = MetricsQueryService.get_documents_processed( + organization_id=str(self.org.id), # tasks.py passes the numeric PK + start_date=monthly_start, + end_date=end_date, + granularity=Granularity.DAY, + ) + totals: dict = {} + for row in rows: + month = _truncate_to_month(row["period"]).date() + totals[month] = totals.get(month, 0) + row["value"] + return totals + + def test_monthly_equals_the_pre_change_figures_across_a_month_boundary(self): + self._seed(days_ago=0, count=3) + self._seed(days_ago=self.days_to_last_month_end, count=2) + self._seed(days_ago=self.days_to_last_month_start, count=4) + + with patch("dashboard_metrics.tasks.WorkflowExecution") as mock_execution: + prefilter = mock_execution.objects.filter.return_value + prefilter.values_list.return_value.distinct.return_value = [self.org.id] + with patch("dashboard_metrics.tasks.timezone.now", return_value=self.now): + result = _run_aggregation( + source_window_days=self.days_to_last_month_start + 1 + ) + + monthly_start = date.fromisoformat(result["period"]["monthly"]["start"]) + end_date = datetime.fromisoformat(result["period"]["monthly"]["end"]) + expected = self._oracle( + datetime.combine(monthly_start, datetime.min.time(), tzinfo=end_date.tzinfo), + end_date, + ) + + assert len(expected) == 2, f"fixture must straddle a month boundary: {expected}" + assert self._written() == expected + + def test_the_comparison_can_fail_when_the_daily_tier_is_wrong(self): + """Guards the test above: an oracle that always matches proves nothing. + + Monthly is the sum of whatever the daily tier holds, so corrupting a day has + to move the monthly total away from the source-derived figure. Corrupting + rather than deleting is the point — deleting a day leaves the group in place + with a smaller sum, so it would move the total too and could not distinguish + a working oracle from a broken one. (Only an *entirely* absent month leaves + the previous monthly row untouched; that case is covered by TestMonthlyRollup.) + """ + self._seed(days_ago=0, count=3) + self._seed(days_ago=self.days_to_last_month_end, count=2) + + with patch("dashboard_metrics.tasks.WorkflowExecution") as mock_execution: + prefilter = mock_execution.objects.filter.return_value + prefilter.values_list.return_value.distinct.return_value = [self.org.id] + with patch("dashboard_metrics.tasks.timezone.now", return_value=self.now): + result = _run_aggregation( + source_window_days=self.days_to_last_month_start + 1 + ) + + monthly_start = date.fromisoformat(result["period"]["monthly"]["start"]) + end_date = datetime.fromisoformat(result["period"]["monthly"]["end"]) + expected = self._oracle( + datetime.combine(monthly_start, datetime.min.time(), tzinfo=end_date.tzinfo), + end_date, + ) + assert self._written() == expected + + last_month_day = ( + self.now - timedelta(days=self.days_to_last_month_end) + ).date() + corrupted = EventMetricsDaily._base_manager.filter( + date=last_month_day, metric_name="documents_processed" + ).update(metric_value=99) + assert corrupted, "fixture wrote no daily row for the previous month" + + _rollup_monthly_from_daily(monthly_start) + assert self._written() != expected + + +# Same rationale as test_aggregation_tier.py: the lock protocol needs a cache, not a +# server, and cache.clear() on django_redis is a whole-database FLUSHDB. +_LOCMEM_CACHE = { + "default": { + "BACKEND": "django.core.cache.backends.locmem.LocMemCache", + "LOCATION": "aggregation-lock-window-tests", + } +} + + +class TestTheLockIsPerSchedule(TestCase): + """The reconciliation pass must not lose a race it is never retried after. + + Per-granularity exclusion is covered in test_aggregation_tier.py; this is the + window half — two schedules that both write the daily/monthly tier. + """ + + def setUp(self): + # Pinned to locmem: cache.clear() is FLUSHDB on django_redis, which would wipe + # every key in that database — the Celery broker shares db 0 in the test env — + # and these keys are un-namespaced, so parallel workers would clear each + # other's. The lock protocol only needs add/get/delete. + override = override_settings(CACHES=_LOCMEM_CACHE) + override.enable() + self.addCleanup(override.disable) + cache.clear() + self.addCleanup(cache.clear) + + def _keys(self, window): + return _aggregation_lock_keys(AggregationTier.ALL, window) + + def test_the_two_schedules_take_different_keys(self): + assert self._keys(DASHBOARD_SOURCE_WINDOW_DAYS) != self._keys( + DASHBOARD_RECONCILE_WINDOW_DAYS + ) + + def test_a_held_key_does_not_block_the_other_schedule(self): + assert _acquire_aggregation_locks(self._keys(DASHBOARD_SOURCE_WINDOW_DAYS))[0] + # Same schedule: excluded, which is what the lock is for. + assert not _acquire_aggregation_locks(self._keys(DASHBOARD_SOURCE_WINDOW_DAYS))[0] + # The reconciliation pass proceeds regardless. + assert _acquire_aggregation_locks(self._keys(DASHBOARD_RECONCILE_WINDOW_DAYS))[0] + + +class TestSourceWindowValidation(TestCase): + """The window arrives as JSON from a Beat row editable in the admin.""" + + def test_a_sane_window_passes_through(self): + assert _validate_source_window(7) == 7 + assert _validate_source_window("7") == 7 + + def test_a_window_that_would_query_nothing_is_rejected(self): + # Negative puts daily_start in the future; 0 never refreshes yesterday. + for bad in (-1, 0): + with self.assertRaises(ValueError): + _validate_source_window(bad) + + def test_a_window_that_restores_the_multi_month_scan_is_rejected(self): + with self.assertRaises(ValueError): + _validate_source_window(365) + + def test_a_non_integer_window_is_rejected(self): + with self.assertRaises(ValueError): + _validate_source_window("seven") + + +class TestSourceWindow(TestCase): + """Tests for the per-run source window and the reconciliation pass.""" + + def setUp(self): + """Set up test fixtures.""" + self.org = Organization.objects.create( + organization_id="window-org", name="window-org", display_name="Window Org" + ) + self.now = timezone.now() + + def _run_with_active_org(self, **kwargs): + """Run aggregation with the active-org prefilter stubbed to the fixture org. + + The clock is frozen to self.now so the run and the test's own expectation + derive from one reading. Unpinned, a run straddling midnight UTC truncates + to two different days and the assertion fails on no code change. + """ + with patch("dashboard_metrics.tasks.WorkflowExecution") as mock_execution: + prefilter = mock_execution.objects.filter.return_value + prefilter.values_list.return_value.distinct.return_value = [self.org.id] + with patch("dashboard_metrics.tasks.timezone.now", return_value=self.now): + return _run_aggregation(**kwargs) + + def test_default_window_bounds_the_daily_query(self): + """The per-run daily window is DASHBOARD_SOURCE_WINDOW_DAYS wide.""" + result = self._run_with_active_org() + + expected = truncate_to_day( + self.now - timedelta(days=DASHBOARD_SOURCE_WINDOW_DAYS) + ) + assert result["period"]["daily"]["start"] == expected.isoformat() + + def test_reconciliation_window_widens_the_daily_query(self): + """The reconciliation pass reaches further back on the same code path.""" + result = self._run_with_active_org( + source_window_days=DASHBOARD_RECONCILE_WINDOW_DAYS + ) + + expected = truncate_to_day( + self.now - timedelta(days=DASHBOARD_RECONCILE_WINDOW_DAYS) + ) + assert result["period"]["daily"]["start"] == expected.isoformat() + + def test_task_passes_the_window_through(self): + """The scheduled task forwards its kwarg, defaulting to the per-run window. + + The lock is patched out: acquiring it for real takes — and then releases in the + task's ``finally`` — the shared Redis key a live local aggregation may be + holding. + """ + with ( + patch("dashboard_metrics.tasks._acquire_aggregation_lock", return_value=True), + patch("dashboard_metrics.tasks.cache"), + patch("dashboard_metrics.tasks._run_aggregation") as mock_run, + ): + aggregate_metrics_from_sources() + mock_run.assert_called_once_with( + AggregationTier.ALL, DASHBOARD_SOURCE_WINDOW_DAYS + ) + + with ( + patch("dashboard_metrics.tasks._acquire_aggregation_lock", return_value=True), + patch("dashboard_metrics.tasks.cache"), + patch("dashboard_metrics.tasks._run_aggregation") as mock_run, + ): + aggregate_metrics_from_sources(source_window_days=7) + mock_run.assert_called_once_with(AggregationTier.ALL, 7) + + def _seed_file( + self, days_ago: int, status: ExecutionStatus = ExecutionStatus.COMPLETED + ) -> date: + """Seed one file execution dated days_ago, return its date.""" + workflow = Workflow.objects.create( + workflow_name=f"recon-wf-{days_ago}", organization=self.org + ) + execution = WorkflowExecution.objects.create( + workflow=workflow, status=ExecutionStatus.COMPLETED + ) + file_execution = WorkflowFileExecution.objects.create( + workflow_execution=execution, + file_name="a.pdf", + status=status.value, + ) + + stamp = timezone.now() - timedelta(days=days_ago) + # created_at is auto_now_add; a queryset update is what bypasses it + WorkflowFileExecution.objects.filter(pk=file_execution.pk).update( + created_at=stamp + ) + WorkflowExecution.objects.filter(pk=execution.pk).update(created_at=stamp) + return stamp.date() + + def test_reconciliation_recovers_a_day_the_narrow_window_missed(self): + """A row outside the per-run window is picked up by the wider pass.""" + day = self._seed_file(days_ago=5) + + _run_aggregation() + assert not EventMetricsDaily._base_manager.filter(date=day).exists() + + result = _run_aggregation(source_window_days=DASHBOARD_RECONCILE_WINDOW_DAYS) + + row = EventMetricsDaily._base_manager.get( + date=day, metric_name="documents_processed" + ) + assert row.metric_value == 1 + assert result["errors"] == 0 + + def test_late_terminal_status_does_not_re_enter_the_narrow_window(self): + """Finishing after the window moved on does not bring a row back.""" + day = self._seed_file(days_ago=3, status=ExecutionStatus.PENDING) + + # Still running: nothing to count yet. + _run_aggregation() + assert not EventMetricsDaily._base_manager.filter(date=day).exists() + + # It finishes. status turns terminal; created_at does not move. + WorkflowFileExecution.objects.update(status=ExecutionStatus.COMPLETED.value) + + # The per-run window no longer reaches its created_at, so it stays missed. + _run_aggregation() + assert not EventMetricsDaily._base_manager.filter(date=day).exists() + + # Only the wider pass recovers it. + _run_aggregation(source_window_days=DASHBOARD_RECONCILE_WINDOW_DAYS) + assert EventMetricsDaily._base_manager.filter( + date=day, metric_name="documents_processed" + ).exists() + + def test_gap_older_than_the_reconcile_window_needs_a_manual_backfill(self): + """Neither scheduled pass reaches a day beyond the reconcile window.""" + old_day = self._seed_file(days_ago=62) + recent_day = self._seed_file(days_ago=0) + + _run_aggregation() + _run_aggregation(source_window_days=DASHBOARD_RECONCILE_WINDOW_DAYS) + + # The run worked — it just cannot reach that far back. + assert EventMetricsDaily._base_manager.filter(date=recent_day).exists() + assert not EventMetricsDaily._base_manager.filter(date=old_day).exists() + + +class TestReconciliationSchedule(TestCase): + """Migration 0005 schedules the once-daily reconciliation pass on both transports. + + The suite runs with --no-migrations, so the migration's function is called + directly rather than relying on it having been applied. + """ + + def setUp(self): + """Load the data migration module.""" + self.migration = import_module( + "dashboard_metrics.migrations.0005_add_reconciliation_task" + ) + + def _task(self): + return PeriodicTask.objects.get(name=self.migration.RECONCILE_TASK_NAME) + + def test_migration_schedules_the_pass_at_0440_with_a_7_day_window(self): + """The beat row lands enabled, at 04:40 UTC, carrying the wider window.""" + self.migration.create_reconciliation_task(apps, None) + + task = self._task() + assert task.task == "dashboard_metrics.aggregate_from_sources" + assert task.enabled + assert task.queue == "dashboard_metric_events" + # The tier is part of the row: without it the pass runs ALL, and its hourly + # half both duplicates the */15 run's work and is the only thing writing + # event_metrics_hourly concurrently with it. + assert json.loads(task.kwargs) == { + "source_window_days": DASHBOARD_RECONCILE_WINDOW_DAYS, + "tier": "daily_monthly", + } + assert (task.crontab.hour, task.crontab.minute) == ("4", "40") + + def test_the_pg_twin_lands_with_the_same_cadence_and_kwargs(self): + """A Beat-only row stops firing the moment the PG scheduler takes over.""" + self.migration.create_reconciliation_task(apps, None) + + row = PgPeriodicTask.objects.get(name=self.migration.RECONCILE_TASK_NAME) + assert row.task_name == "dashboard_metrics.aggregate_from_sources" + assert row.queue == "dashboard_metric_events" + assert row.cron_string == "40 4 * * *" + assert row.task_kwargs == { + "source_window_days": DASHBOARD_RECONCILE_WINDOW_DAYS, + "tier": "daily_monthly", + } + assert row.enabled + # Inert until the rollout flag decides otherwise. + assert not row.pg_owned + assert row.next_run_at is None + + def test_a_running_beat_is_told_to_reload(self): + """Historical models fire no post_save, so the tracker has to be bumped by hand. + + Without it a live Beat never adopts the new schedule and the reconciliation + pass simply never runs — no error, nothing logged. + """ + before = timezone.now() + self.migration.create_reconciliation_task(apps, None) + + tracker = PeriodicTasks.objects.get(ident=1) + assert tracker.last_update >= before + + def test_migration_is_idempotent_and_reversible(self): + """Re-running leaves one row; the reverse function removes it.""" + self.migration.create_reconciliation_task(apps, None) + self.migration.create_reconciliation_task(apps, None) + + assert ( + PeriodicTask.objects.filter(name=self.migration.RECONCILE_TASK_NAME).count() + == 1 + ) + + self.migration.remove_reconciliation_task(apps, None) + assert not PeriodicTask.objects.filter( + name=self.migration.RECONCILE_TASK_NAME + ).exists() + assert not PgPeriodicTask.objects.filter( + name=self.migration.RECONCILE_TASK_NAME + ).exists() + + +class TestALoweredTotalIsReported(TestCase): + """The damage is per-tenant, so the detector has to be. + + A fleet-wide date count cannot see this: one org covers every date while + another loses one, so no date is globally missing and nothing fires — while + the second org's monthly total is rewritten downward and served to its + dashboard. `_collect_org_metrics` catches a failing metric per organization + and continues, so a query fault on one tenant produces exactly this shape, + and the 2-day source window makes it permanent two days later. + """ + + def setUp(self): + self.covered = Organization.objects.create( + organization_id="covered-org", name="covered", display_name="Covered" + ) + self.short = Organization.objects.create( + organization_id="short-org", name="short", display_name="Short" + ) + self.month = _truncate_to_month(timezone.now()).date() + + def _daily(self, org, day, value): + EventMetricsDaily._base_manager.create( + organization=org, + date=day, + metric_name="documents_processed", + metric_type=MetricType.COUNTER, + metric_value=value, + metric_count=1, + project="default", + tag="", + ) + + def _monthly(self, org, value): + EventMetricsMonthly._base_manager.create( + organization=org, + month=self.month, + metric_name="documents_processed", + metric_type=MetricType.COUNTER, + metric_value=value, + metric_count=2, + project="default", + tag="", + ) + + def test_one_tenant_losing_a_day_is_named_while_the_other_is_not(self): + # Both orgs previously totalled 80. Only `short` lost a day of daily rows. + self._monthly(self.covered, value=80) + self._monthly(self.short, value=80) + self._daily(self.covered, self.month, value=40) + self._daily(self.covered, self.month + timedelta(days=1), value=40) + self._daily(self.short, self.month, value=70) + + lowered = _pairs_the_rollup_would_lower(self.month) + _rollup_monthly_from_daily(self.month, skip=set(lowered)) + + assert lowered == [ + (self.short.id, self.month, "documents_processed", "default", "") + ] + + short_row = EventMetricsMonthly._base_manager.get(organization=self.short) + covered_row = EventMetricsMonthly._base_manager.get(organization=self.covered) + # Kept, not overwritten: writing 70 would replace a correct figure with a + # known-short one just because the daily tier has not been repaired yet. + assert short_row.metric_value == 80 + assert covered_row.metric_value == 80 + + def test_a_healthy_sibling_metric_is_still_updated(self): + """The skip is per conflict key, not per (org, month). + + Skipping the whole org-month would freeze a metric whose own total is fine + because a sibling metric's daily rows are short. + """ + self._monthly(self.short, value=80) + EventMetricsMonthly._base_manager.create( + organization=self.short, month=self.month, metric_name="pages_processed", + metric_type=MetricType.COUNTER, metric_value=5, metric_count=1, + project="default", tag="", + ) + self._daily(self.short, self.month, value=70) # short — will be skipped + EventMetricsDaily._base_manager.create( + organization=self.short, date=self.month, metric_name="pages_processed", + metric_type=MetricType.COUNTER, metric_value=50, metric_count=1, + project="default", tag="", + ) + + lowered = _pairs_the_rollup_would_lower(self.month) + _rollup_monthly_from_daily(self.month, skip=set(lowered)) + + rows = { + r.metric_name: r.metric_value + for r in EventMetricsMonthly._base_manager.filter(organization=self.short) + } + assert rows["documents_processed"] == 80, "the short metric must be preserved" + assert rows["pages_processed"] == 50, "the healthy metric must still update" + + def test_a_tier_that_covers_everything_reports_nothing(self): + """The control: no total fell, so no warning — however few days are seeded.""" + self._monthly(self.covered, value=40) + self._daily(self.covered, self.month, value=40) + + assert _pairs_the_rollup_would_lower(self.month) == [] + _rollup_monthly_from_daily(self.month) + + +class TestTheUnderCountCheckIsBounded(TestCase): + """The check must not scale with tenant x metric x project x tag. + + An earlier version snapshotted every monthly row into a dict before the rollup + and read them all again afterwards — comparing the right thing on the axis the + streaming rollup exists to keep off the heap. This pins the replacement: one + statement, evaluated in the database, returning only offending pairs. + """ + + def setUp(self): + self.month = _truncate_to_month(timezone.now()).date() + for n in range(12): + org = Organization.objects.create( + organization_id=f"bounded-{n}", name=f"b{n}", display_name=f"B{n}" + ) + for metric in ("documents_processed", "pages_processed", "llm_calls"): + EventMetricsDaily._base_manager.create( + organization=org, + date=self.month, + metric_name=metric, + metric_type=MetricType.COUNTER, + metric_value=5, + metric_count=1, + project="default", + tag="", + ) + EventMetricsMonthly._base_manager.create( + organization=org, + month=self.month, + metric_name=metric, + metric_type=MetricType.COUNTER, + metric_value=5, + metric_count=1, + project="default", + tag="", + ) + + def test_it_costs_one_query_regardless_of_tenant_count(self): + with CaptureQueriesContext(connection) as captured: + assert _pairs_the_rollup_would_lower(self.month) == [] + assert len(captured.captured_queries) == 1, ( + "the under-count check should be a single database-side comparison, " + f"got {len(captured.captured_queries)}:\n" + + "\n\n".join(q["sql"] for q in captured.captured_queries) + ) + + def test_it_does_not_select_every_monthly_row(self): + """36 rows exist; the check must return only what is wrong, which is none.""" + with CaptureQueriesContext(connection) as captured: + _pairs_the_rollup_would_lower(self.month) + sql = captured.captured_queries[0]["sql"] + assert "metric_value" in sql and "<" in sql, ( + "the comparison is not happening in the database:\n" + sql + ) + + +class TestTheDiagnosticCannotBlockTheRollup(TestCase): + """The under-count check is a diagnostic; the rollup is the job. + + This regressed once already. It was fixed by giving the diagnostic its own + try, then reintroduced while making the check a single database query — with + no test to catch it. Hence this one. + """ + + def _run(self, **patches): + with patch("dashboard_metrics.tasks.WorkflowExecution") as mock_execution: + prefilter = mock_execution.objects.filter.return_value + prefilter.values_list.return_value.distinct.return_value = [1] + with patch( + "dashboard_metrics.tasks._pairs_the_rollup_would_lower", + side_effect=DatabaseError("diagnostic exploded"), + ): + return _run_aggregation(**patches) + + def test_a_failing_diagnostic_still_lets_the_rollup_run(self): + with patch( + "dashboard_metrics.tasks._rollup_monthly_from_daily", return_value=7 + ) as rollup: + result = self._run() + + rollup.assert_called_once() + assert result["monthly"]["upserted"] == 7 + + def test_a_failing_diagnostic_is_not_reported_as_a_failed_rollup(self): + """Otherwise the run contradicts itself: upserted 7, failed True.""" + with patch("dashboard_metrics.tasks._rollup_monthly_from_daily", return_value=7): + result = self._run() + + assert result["monthly"]["failed"] is False + + def test_the_soft_time_limit_is_not_swallowed_by_the_diagnostic(self): + """The broad catch here is the same hazard the per-org catches guard. + + SoftTimeLimitExceeded subclasses Exception, so swallowing it would hand an + empty `skip` to the rollup — the heaviest write in the task — with the guard + off and under a minute left before the hard limit kills the worker. It would + then overwrite exactly the totals the guard exists to preserve, and once a + short total is stored the lowering check can never see it again. + """ + with patch( + "dashboard_metrics.tasks._rollup_monthly_from_daily" + ) as rollup, patch( + "dashboard_metrics.tasks._pairs_the_rollup_would_lower", + side_effect=SoftTimeLimitExceeded(), + ), patch("dashboard_metrics.tasks.WorkflowExecution") as mock_execution: + prefilter = mock_execution.objects.filter.return_value + prefilter.values_list.return_value.distinct.return_value = [1] + with self.assertRaises(SoftTimeLimitExceeded): + _run_aggregation(tier=AggregationTier.DAILY_MONTHLY) + + rollup.assert_not_called() + + def test_a_failing_diagnostic_still_fails_the_run(self): + """Did not block the rollup and succeeded are separable claims. + + A failing check leaves ``skip`` empty, so the upsert runs with the guard OFF + and overwrites every total it would have protected. That is the opposite of + a clean run, and ``errors`` is the only field anything alerts on. + """ + with patch("dashboard_metrics.tasks._rollup_monthly_from_daily", return_value=7): + result = self._run() + + assert result["errors"] == 1 + assert result["success"] is False + assert result["monthly"]["lowered_check"] == "unavailable" + + +class TestTheLockIsReleasedOnlyByItsOwner(TestCase): + """The ownership check had no test; deleting it left the suite green. + + Without it a run whose lock had already expired deletes whichever run took the + key next, so two runs write the same tier and a third is free to enter. + """ + + def setUp(self): + override = override_settings(CACHES=_LOCMEM_CACHE) + override.enable() + self.addCleanup(override.disable) + cache.clear() + self.addCleanup(cache.clear) + self.key = _aggregation_lock_keys(AggregationTier.HOURLY, 2)[0] + + def test_a_stale_owner_does_not_release_the_current_holder(self): + cache.set(self.key, f"newer-run:{time.time()}", 3600) + + _release_aggregation_locks([self.key], "older-run") + + assert cache.get(self.key) is not None, ( + "a run that no longer owns the key deleted the current holder's lock" + ) + + def test_the_owner_does_release_its_own_key(self): + """The control: ownership gates the delete, it does not disable it.""" + assert _acquire_aggregation_lock(self.key, "mine") + _release_aggregation_locks([self.key], "mine") + assert cache.get(self.key) is None + + +class TestTheRunSurfacesWhatTheDiagnosticFound(TestCase): + """The leg between the diagnostic and the result dict was untested on both sides. + + One test called the helper directly; another asserted against a hand-built + payload. Neither observed the assignment, so dropping it left the suite green. + """ + + def setUp(self): + self.org = Organization.objects.create( + organization_id="surface-org", name="surface", display_name="Surface" + ) + self.month = _truncate_to_month(timezone.now()).date() + + def _run(self, **kwargs): + with patch("dashboard_metrics.tasks.WorkflowExecution") as mock_execution: + prefilter = mock_execution.objects.filter.return_value + prefilter.values_list.return_value.distinct.return_value = [self.org.id] + return _run_aggregation(**kwargs) + + def test_a_lowered_total_reaches_the_result_dict(self): + EventMetricsMonthly._base_manager.create( + organization=self.org, month=self.month, + metric_name="documents_processed", metric_type=MetricType.COUNTER, + metric_value=999, metric_count=1, project="default", tag="", + ) + EventMetricsDaily._base_manager.create( + organization=self.org, date=self.month, + metric_name="documents_processed", metric_type=MetricType.COUNTER, + metric_value=1, metric_count=1, project="default", tag="", + ) + + result = self._run(tier=AggregationTier.DAILY_MONTHLY) + + assert result["monthly"]["needs_daily_repair"], ( + "the rollup lowered a total and the result dict did not say so" + ) + + def test_an_incomplete_daily_tier_reaches_the_result_dict(self): + """The sibling of the assertion above, for the other check. + + Returning `[]` from the coverage check, or typoing the key it is stored + under, left the whole suite green — the key is hand-duplicated into the + worker, so nothing crossed the seam. + """ + yesterday = timezone.now().date() - timedelta(days=1) + if yesterday <= self.month: + # On the 1st nothing has elapsed; on the 2nd exactly one whole day has, + # and the single seeded row covers it — so there is no gap to assert and + # the suite would go red for every PR in the repo on that date. The + # sibling class covers the logic itself under a frozen clock. + self.skipTest("fewer than two whole days of the month have elapsed") + # A row for the month's first day and nothing since: every other whole day + # of the month is missing. + EventMetricsDaily._base_manager.create( + organization=self.org, date=self.month, + metric_name="documents_processed", metric_type=MetricType.COUNTER, + metric_value=1, metric_count=1, project="default", tag="", + ) + + result = self._run(tier=AggregationTier.DAILY_MONTHLY) + + assert result["monthly"]["incomplete_daily_coverage"], ( + "the daily tier is missing whole days and the result dict did not say so" + ) + + def test_a_failed_coverage_check_is_reported_as_unavailable(self): + """The sibling of the lowering check's arm, for the other key. + + `coverage_check` was the one key with no assertion on either side of the + seam — renaming its literal left 190 backend tests green while the same + mutation on `needs_daily_repair` was caught. + """ + with patch( + "dashboard_metrics.tasks._months_missing_days", + side_effect=DatabaseError("coverage check exploded"), + ): + result = self._run(tier=AggregationTier.DAILY_MONTHLY) + + assert result["monthly"]["coverage_check"] == "unavailable" + + def test_a_failed_check_is_reported_as_unavailable_not_as_clean(self): + """`[]` alone would read as 'checked, nothing lowered'.""" + with patch( + "dashboard_metrics.tasks._pairs_the_rollup_would_lower", + side_effect=DatabaseError("diagnostic exploded"), + ): + result = self._run(tier=AggregationTier.DAILY_MONTHLY) + + assert result["monthly"]["lowered_check"] == "unavailable" + assert "needs_daily_repair" not in result["monthly"] + + +class TestAnIncompleteDailyTierIsReported(TestCase): + """The two gaps the lowering check is structurally blind to. + + `_pairs_the_rollup_would_lower` needs a stored monthly total to compare + against. So it says nothing on the first run of a calendar month, when no row + exists yet — and nothing ever again once a short total IS stored, because from + then on every sum is higher and the total is never "lowered". Both leave an + under-count permanent and silent. Day coverage reads the daily tier itself, so + neither blind spot applies. It does not replace the per-tenant check: that one + still catches a single tenant losing a day the rest of the fleet covered. + """ + + NOW = datetime(2026, 3, 10, 12, 0, tzinfo=UTC) + MONTH = date(2026, 3, 1) + + def setUp(self): + self.org = Organization.objects.create( + organization_id="cov-org", name="cov", display_name="Cov" + ) + + def _daily(self, day, org=None): + EventMetricsDaily._base_manager.create( + organization=self.org if org is None else org, + date=date(2026, 3, day), + metric_name="documents_processed", + metric_type=MetricType.COUNTER, + metric_value=1, + metric_count=1, + project="default", + tag="", + ) + + def _missing(self): + with patch("dashboard_metrics.tasks.timezone.now", return_value=self.NOW): + return _months_missing_days(self.MONTH) + + def test_a_gap_is_reported_with_no_monthly_row_to_compare_against(self): + """The no-prior-row escape: nothing is 'lowered', yet March is short.""" + for day in (1, 2, 3, 4, 6, 7, 8, 9): # the 5th never landed + self._daily(day) + + assert _pairs_the_rollup_would_lower(self.MONTH) == [], ( + "precondition: with no stored monthly row there is nothing to lower, " + "which is exactly why that check cannot see this" + ) + assert self._missing() == ["2026-03 (8/9 days)"] + + def test_a_gap_is_still_seen_once_todays_row_has_landed(self): + """The production shape, and the one the pair below could not reach. + + Counting today while measuring against yesterday let today's row cancel + exactly one missing earlier day — so a single missed aggregation, the case + this check exists for, was silent from the day's first run onward. + """ + for day in (1, 2, 3, 4, 6, 7, 8, 9, 10): # the 5th never landed; 10th is today + self._daily(day) + + assert self._missing() == ["2026-03 (8/9 days)"] + + def test_a_fully_covered_month_is_silent(self): + for day in range(1, 10): + self._daily(day) + + assert self._missing() == [] + + def test_a_month_with_no_daily_rows_at_all_is_silent(self): + """A fresh install has no rows, which is not the same as missing days.""" + assert self._missing() == [] + + def test_todays_partial_row_is_not_counted_as_a_gap(self): + """Today is partial by construction until its last run of the day.""" + for day in range(1, 11): # 10th == "today" under the frozen clock + self._daily(day) + + assert self._missing() == [] + + +class TestAnOrgLessDailyRowIsNotRolledUp(TestCase): + """`organization` is nullable and `unique_monthly_metric` includes it. + + Postgres unique indexes are NULLS DISTINCT, so ON CONFLICT never matches such a + row: the upsert INSERTs another duplicate on every run rather than updating one. + No writer originates one today — both take the org from a loop — but the rollup + reads the column rather than a loop variable, so nothing structural stops it. + """ + + def setUp(self): + self.month = _truncate_to_month(timezone.now()).date() + EventMetricsDaily._base_manager.create( + organization=None, + date=self.month, + metric_name="documents_processed", + metric_type=MetricType.COUNTER, + metric_value=5, + metric_count=1, + project="default", + tag="", + ) + + def test_it_produces_no_monthly_row(self): + _rollup_monthly_from_daily(self.month) + + assert not EventMetricsMonthly._base_manager.filter( + organization__isnull=True + ).exists() + + def test_repeated_runs_do_not_accumulate_duplicates(self): + """The actual damage: unbounded growth, not one wrong row.""" + for _ in range(3): + _rollup_monthly_from_daily(self.month) + + assert ( + EventMetricsMonthly._base_manager.filter(organization__isnull=True).count() + == 0 + ) + + +class TestTheGuardComparesWithinOneMonth(TestCase): + """The rollup window spans two months; every other guard test seeds one. + + `month_start` is the first of the PREVIOUS month, so the subquery has to + correlate each candidate row to its own month. Seeded inside a single month + that correlation is inert — deleting it leaves the suite green while, in + production, one month's stored total is compared against two months of daily + rows. The sum is then always larger, nothing is ever "lowered", and the guard + silently stops guarding. + """ + + def setUp(self): + self.org = Organization.objects.create( + organization_id="two-month-org", name="two", display_name="Two" + ) + this_month = _truncate_to_month(timezone.now()).date() + self.previous = (this_month - timedelta(days=1)).replace(day=1) + self.current = this_month + + def _daily(self, day, value): + EventMetricsDaily._base_manager.create( + organization=self.org, date=day, metric_name="documents_processed", + metric_type=MetricType.COUNTER, metric_value=value, metric_count=1, + project="default", tag="", + ) + + def _monthly(self, month, value): + EventMetricsMonthly._base_manager.create( + organization=self.org, month=month, metric_name="documents_processed", + metric_type=MetricType.COUNTER, metric_value=value, metric_count=1, + project="default", tag="", + ) + + def test_a_short_month_is_flagged_even_when_its_neighbour_is_whole(self): + # Previous month is complete and matches its stored total. + self._monthly(self.previous, value=100) + self._daily(self.previous, value=100) + # Current month lost days: stored 80, daily now sums to 70. + self._monthly(self.current, value=80) + self._daily(self.current, value=70) + + lowered = _pairs_the_rollup_would_lower(self.previous) + + # Uncorrelated, the current month's candidate would be compared against + # 100 + 70 = 170 and pass as healthy. + assert lowered == [ + (self.org.id, self.current, "documents_processed", "default", "") + ], "the short month must be flagged, and the whole one must not be" + + def test_the_whole_neighbour_is_not_frozen_by_its_short_sibling(self): + self._monthly(self.previous, value=100) + self._daily(self.previous, value=100) + self._monthly(self.current, value=80) + self._daily(self.current, value=70) + + lowered = _pairs_the_rollup_would_lower(self.previous) + _rollup_monthly_from_daily(self.previous, skip=set(lowered)) + + rows = { + r.month: r.metric_value + for r in EventMetricsMonthly._base_manager.filter(organization=self.org) + } + assert rows[self.current] == 80, "the short month must keep its stored total" + assert rows[self.previous] == 100, "the whole month must still be rewritten" + + +class TestTheTaskAcquiresAndReleasesForReal(TestCase): + """The task's own lock round trip, against a real cache backend. + + The helper-level tests exercise `_acquire_aggregation_locks` and + `_release_aggregation_locks` directly, and the one test that drives the task + patches BOTH the acquire helper and `cache` wholesale — so nothing executed + acquire -> run -> `finally` release end to end. + + That gap is not cosmetic: AGGREGATION_LOCK_TIMEOUT is 900s and the hourly + schedule fires every 900s, so a release that silently stopped working would + leave the key held for exactly one period and skip roughly every other run — + while every run still returns success, because a lock-held skip is reported as + `{"success": True, "skipped": True}`. + """ + + def setUp(self): + override = override_settings(CACHES=_LOCMEM_CACHE) + override.enable() + self.addCleanup(override.disable) + cache.clear() + self.addCleanup(cache.clear) + self.keys = _aggregation_lock_keys(AggregationTier.ALL, DASHBOARD_SOURCE_WINDOW_DAYS) + + def _held(self): + return [k for k in self.keys if cache.get(k) is not None] + + def test_the_keys_are_held_during_the_run_and_gone_after(self): + seen = {} + + def _record(*args, **kwargs): + seen["during"] = self._held() + return {"success": True} + + with patch("dashboard_metrics.tasks._run_aggregation", side_effect=_record): + aggregate_metrics_from_sources() + + assert seen["during"] == self.keys, "the run must hold every key it claimed" + assert self._held() == [], "the finally must release every key" + + def test_a_second_run_is_locked_out_while_the_first_holds(self): + def _reentrant(*args, **kwargs): + # A second tick firing mid-run is exactly what the lock exists for. + seen["inner"] = aggregate_metrics_from_sources() + return {"success": True} + + seen = {} + with patch("dashboard_metrics.tasks._run_aggregation", side_effect=_reentrant): + aggregate_metrics_from_sources() + + assert seen["inner"]["skipped"] is True + assert seen["inner"]["reason"] == "lock_held" + assert self._held() == [], "the outer run still releases on the way out" + + def test_the_keys_are_released_when_the_run_raises(self): + """Otherwise one failure silences the schedule for a full period.""" + with patch( + "dashboard_metrics.tasks._run_aggregation", + side_effect=DatabaseError("aggregation exploded"), + ): + with self.assertRaises(DatabaseError): + aggregate_metrics_from_sources() + + assert self._held() == [], "a raising run must not strand its keys" + + +class TestTheReconciliationRowInheritsOwnership(TestCase): + """0005's `_inherited_ownership` on the branch it exists for. + + Every other test on this migration runs with no aggregation row present, which + exercises only the `is None` fallbacks — hardcoding `True/True/False` would + pass all of them. The branch that matters is the opposite one: where the + metrics periodics are already PG-adopted, the Beat twin is disabled and Beat + may not be running at all, so a hardcoded Beat row would land the pass with no + firer. This is the only automatic repair for the narrowed source window, so it + is the worst row to strand. 0006's equivalent is covered; this one was not. + """ + + def setUp(self): + self.migration = import_module( + "dashboard_metrics.migrations.0005_add_reconciliation_task" + ) + self.existing = self.migration.EXISTING_AGGREGATE_ROW + + def _adopt_by_pg(self): + """The shape after the metrics periodics move to the PG scheduler.""" + interval, _ = apps.get_model( + "django_celery_beat", "IntervalSchedule" + ).objects.get_or_create(every=15, period="minutes") + PeriodicTask.objects.create( + name=self.existing, + task="dashboard_metrics.aggregate_from_sources", + interval=interval, + enabled=False, + ) + PgPeriodicTask.objects.create( + name=self.existing, + task_name="dashboard_metrics.aggregate_from_sources", + cron_string="*/15 * * * *", + org_id="", + enabled=True, + pg_owned=True, + ) + + def test_a_pg_adopted_fleet_gets_a_pg_owned_row_not_a_beat_one(self): + self._adopt_by_pg() + + self.migration.create_reconciliation_task(apps, None) + + beat = PeriodicTask.objects.get(name=self.migration.RECONCILE_TASK_NAME) + pg = PgPeriodicTask.objects.get(name=self.migration.RECONCILE_TASK_NAME) + assert beat.enabled is False, ( + "the Beat twin must stay disabled, matching the row it follows — " + "otherwise both transports fire the same reconciliation pass" + ) + assert pg.enabled is True + assert pg.pg_owned is True, ( + "hardcoding pg_owned=False strands the pass: the PG scheduler skips a " + "row it does not own and Beat's copy is disabled" + ) + + def test_the_fallback_still_applies_with_no_row_to_inherit_from(self): + """The control, so the assertions above cannot pass by coincidence.""" + self.migration.create_reconciliation_task(apps, None) + + assert PeriodicTask.objects.get( + name=self.migration.RECONCILE_TASK_NAME + ).enabled is True + assert PgPeriodicTask.objects.get( + name=self.migration.RECONCILE_TASK_NAME + ).pg_owned is False + + +class TestTheTruncatedListNamesTheTotal(TestCase): + """The count is what separates one tenant's gap from a fleet-wide one. + + Reporting the cap instead of the total makes three affected tenants and four + thousand render identically, which is the difference between "look at that + org" and "the aggregation stopped running". + """ + + def _pairs(self, n): + month = _truncate_to_month(timezone.now()).date() + return [(i, month, "documents_processed", "default", "") for i in range(n)] + + def test_under_the_cap_nothing_is_truncated(self): + names = _name_lowered_pairs(self._pairs(LOWERED_MONTHS_REPORT_LIMIT)) + + assert len(names) == LOWERED_MONTHS_REPORT_LIMIT + assert not any("more" in n for n in names) + + def test_over_the_cap_the_tail_names_the_total_not_the_cap(self): + names = _name_lowered_pairs(self._pairs(LOWERED_MONTHS_REPORT_LIMIT + 5)) + + assert names[-1] == f"... and 5 more of {LOWERED_MONTHS_REPORT_LIMIT + 5}", ( + "the tail must carry the real total; reporting the cap makes every " + f"overflow look identical:\n{names[-1]}" + ) diff --git a/backend/dashboard_metrics/tests/test_tier_split_equivalence.py b/backend/dashboard_metrics/tests/test_tier_split_equivalence.py new file mode 100644 index 0000000000..483a3e5163 --- /dev/null +++ b/backend/dashboard_metrics/tests/test_tier_split_equivalence.py @@ -0,0 +1,234 @@ +"""The split preserves every figure it used to write (UN-3974, AC-2). + +AC-2 is an equivalence claim — "hourly figures unchanged; daily and monthly lag by at +most one hour" — so it is settled by running the real aggregation and diffing what lands +in the metrics tables, not by reasoning about the gating predicates. Those are pinned +separately in test_aggregation_tier.py; this is the outcome they are supposed to produce. + +Two properties, and both matter: + +- the `hourly` schedule reproduces what an all-tiers run writes to EventMetricsHourly, + exactly — that is the "unchanged" half. Note this is a **partition** property of the + post-change code, not a comparison against the pre-split implementation, which this + branch does not have: `test_the_hourly_tier_holds_the_figures_the_fixture_implies` + is what anchors it to an absolute number +- `hourly` and `daily_monthly` together reproduce every row the pre-split run wrote to + any table — that is the "nothing is lost" half, which the AC assumes rather than states + +DB-bound, so conftest marks it integration. +""" + +from __future__ import annotations + +import os +import uuid +from datetime import timedelta +from typing import Any +from unittest.mock import patch + +import django +from django.apps import apps + +os.environ.setdefault("DJANGO_SETTINGS_MODULE", "backend.settings.test") +if not apps.ready: + django.setup() + +from account_v2.models import Organization # noqa: E402 +from django.db import connection # noqa: E402 +from django.test import TestCase # noqa: E402 +from django.utils import timezone # noqa: E402 +from workflow_manager.workflow_v2.models.workflow import Workflow # noqa: E402 + +from dashboard_metrics.models import ( # noqa: E402 + EventMetricsDaily, + EventMetricsHourly, + EventMetricsMonthly, +) +from dashboard_metrics.tasks import ( # noqa: E402 + AggregationTier, + _run_aggregation, + _truncate_to_month, +) + +# (model, the column naming its period) — the period field differs per tier. +_TIERS = [ + (EventMetricsHourly, "timestamp"), + (EventMetricsDaily, "date"), + (EventMetricsMonthly, "month"), +] +_FIELDS = ["metric_name", "metric_type", "metric_value", "metric_count"] + + +# Wide enough to reach the -3d and previous-month fixture rows. The tier split is +# what is under test here, not the window: at the 2-day default those two rows feed +# no tier at all, and the equivalence would be proven over a single day of data. +_FIXTURE_WINDOW_DAYS = 40 + + +class TestTheSplitPreservesEveryFigure(TestCase): + def setUp(self) -> None: + self.org = Organization.objects.create( + organization_id="tier-split-org", name="tier-split", display_name="Tier Split" + ) + self.workflow = Workflow.objects.create( + workflow_name="tier-split-wf", organization=self.org + ) + self.now = now = timezone.now() + # One row per window the aggregation reads. The two recent ones cover the + # hourly tier's 24h and also make the org visible to the active-org prefilter, + # without which nothing runs at all. The -3d and previous-month rows sit + # outside the 2-day default, so _run passes an explicit source_window_days + # wide enough to reach them — without that they contribute to no tier and the + # equivalence is proven over one day of data. + # + # The previous-month row is derived from the month boundary, not a fixed + # "25 days ago": for the last few days of any month that lands in the *current* + # month and the cross-boundary coverage silently disappears. + last_month_day = _truncate_to_month(now) - timedelta(days=1) + windows = [ + now - timedelta(hours=2), + now - timedelta(hours=5), + now - timedelta(days=3), + last_month_day, + ] + executions = self._add_executions(windows) + # Both aggregation paths have to be exercised: the per-metric queries go through + # _aggregate_single_metric and the four LLM metrics through + # _aggregate_llm_combined, and each gates on the tier separately. A fixture + # producing only LLM figures leaves half the split unverified. + self._add_file_executions(executions) + self._add_llm_usage(windows) + + def _add_executions(self, timestamps: list[Any]) -> list[tuple[Any, Any]]: + """Raw insert so created_at is ours; the model sets it with auto_now_add.""" + created = [] + with connection.cursor() as cur: + for ts in timestamps: + execution_id = uuid.uuid4() + cur.execute( + "INSERT INTO workflow_execution (id, created_at, modified_at, " + "workflow_id, execution_mode, execution_method, execution_type, " + "execution_log_id, status, error_message, attempts, execution_time, " + "result_acknowledged, total_files) " + "VALUES (%s, %s, %s, %s, 'INSTANT', 'DIRECT', 'COMPLETE', '', " + "'COMPLETED', '', 0, 1.0, false, 1)", + [execution_id, ts, ts, self.workflow.id], + ) + created.append((execution_id, ts)) + return created + + def _add_file_executions(self, executions: list[tuple[Any, Any]]) -> None: + """Feeds documents_processed, which runs through _aggregate_single_metric.""" + with connection.cursor() as cur: + for execution_id, ts in executions: + cur.execute( + "INSERT INTO workflow_file_execution (id, created_at, modified_at, " + "file_name, status, workflow_execution_id) " + "VALUES (%s, %s, %s, 'doc.pdf', 'COMPLETED', %s)", + [uuid.uuid4(), ts, ts, execution_id], + ) + + def _add_llm_usage(self, timestamps: list[Any]) -> None: + """LLM metrics need no joins, so they are the cheapest way to put a real figure + in all three tiers. + """ + with connection.cursor() as cur: + for ts in timestamps: + cur.execute( + "INSERT INTO usage (id, created_at, modified_at, adapter_instance_id, " + "usage_type, llm_usage_reason, model_name, embedding_tokens, " + "prompt_tokens, completion_tokens, total_tokens, cost_in_dollars, " + "organization_id) " + "VALUES (%s, %s, %s, 'test-adapter', 'llm', 'extraction', 'test-model', " + "0, 100, 50, 150, 0.25, %s)", + [uuid.uuid4(), ts, ts, self.org.id], + ) + + def _snapshot(self) -> dict[str, set[tuple[Any, ...]]]: + return { + model.__name__: set( + model._base_manager.values_list("organization_id", period, *_FIELDS) + ) + for model, period in _TIERS + } + + def _clear(self) -> None: + for model, _ in _TIERS: + model._base_manager.all().delete() + + def _run(self, tier: AggregationTier) -> dict[str, set[tuple[Any, ...]]]: + """One clock for every run in a test. + + _run_aggregation reads timezone.now() itself, so three unpatched invocations + compute three different window starts — and a run straddling an hour or a month + boundary would fail on a non-regression. + """ + self._clear() + with patch("dashboard_metrics.tasks.timezone.now", return_value=self.now): + _run_aggregation(tier, source_window_days=_FIXTURE_WINDOW_DAYS) + return self._snapshot() + + def test_the_pre_split_run_writes_all_three_tiers(self) -> None: + """Guards the tests below from passing vacuously: an equivalence between two + empty sets proves nothing. + """ + every_tier = self._run(AggregationTier.ALL) + for name, rows in every_tier.items(): + assert rows, f"{name} is empty — the fixture produces no metrics to compare" + + def test_the_fixture_exercises_both_aggregation_paths(self) -> None: + """The other way these tests can go quietly vacuous. The tier is checked + separately in _aggregate_single_metric and in _aggregate_llm_combined, so a + fixture yielding only one kind of metric verifies only half the split — which + is exactly what a mutation test caught here. + """ + every_tier = self._run(AggregationTier.ALL) + for table, rows in every_tier.items(): + names = {row[2] for row in rows} + assert "documents_processed" in names, f"{table}: no per-metric figure" + assert "llm_calls" in names, f"{table}: no combined-LLM figure" + + def test_the_hourly_tier_holds_the_figures_the_fixture_implies(self) -> None: + """An absolute expectation, not a comparison of the code against itself. + + Every other assertion in this file runs the same post-change function twice, so + a regression in the shared path — the window arithmetic, the org_identifier + handoff, an upsert that writes zeroes — moves both sides equally and stays + green. This one names a number the fixture determines. + """ + self._run(AggregationTier.HOURLY) + rows = EventMetricsHourly._base_manager.filter(metric_name="documents_processed") + assert sum(row.metric_value for row in rows) == 2, ( + "exactly the -2h and -5h file executions fall inside the 24h window; " + "the -3d and previous-month ones must not" + ) + assert {row.metric_value for row in rows} != {0} + + def test_hourly_reproduces_the_pre_split_hourly_figures(self) -> None: + """The "figures unchanged" half of AC-2, row for row rather than in aggregate.""" + before = self._run(AggregationTier.ALL)["EventMetricsHourly"] + after = self._run(AggregationTier.HOURLY)["EventMetricsHourly"] + assert after == before + + def test_the_two_schedules_together_lose_nothing(self) -> None: + """Every row the single pre-split run wrote is still written by one of the two + schedules, and neither invents one. + """ + every_tier = self._run(AggregationTier.ALL) + hourly = self._run(AggregationTier.HOURLY) + daily_monthly = self._run(AggregationTier.DAILY_MONTHLY) + + for name in every_tier: + combined = hourly[name] | daily_monthly[name] + assert combined == every_tier[name], f"{name} differs after the split" + + def test_neither_schedule_writes_the_other_tiers_tables(self) -> None: + """If they overlapped, the two schedules would duplicate work every hour on the + hour — harmless thanks to the upserts, but not free. + """ + hourly = self._run(AggregationTier.HOURLY) + assert not hourly["EventMetricsDaily"] + assert not hourly["EventMetricsMonthly"] + + daily_monthly = self._run(AggregationTier.DAILY_MONTHLY) + assert not daily_monthly["EventMetricsHourly"] diff --git a/backend/workflow_manager/file_execution/migrations/0007_wfe_status_created_idx.py b/backend/workflow_manager/file_execution/migrations/0007_wfe_status_created_idx.py new file mode 100644 index 0000000000..98b6875d96 --- /dev/null +++ b/backend/workflow_manager/file_execution/migrations/0007_wfe_status_created_idx.py @@ -0,0 +1,100 @@ +"""Add a (status, created_at) index to workflow_file_execution. + +The dashboard metrics cron filters this table on status and a created_at window. No +existing index leads with status or created_at — every secondary index is prefixed by +the workflow_execution FK column — so the planner cannot drive from here and scans +workflow_execution in full instead. Execution plan in UN-4094 (2026-08-31, which +supersedes the earlier workflow_file_execution reading); cost measurements in UN-3883. + +Full rather than partial: get_failed_pages benefits at any window (ERROR is 0.40% of +rows), and get_documents_processed benefits since UN-3973 narrowed the window to 2 days +— at the previous 52 days the COMPLETED slice was 20.4% of the table and the planner +scanned regardless. A partial index on ERROR would serve the first and never the second. + +Built CONCURRENTLY (atomic = False): a plain AddIndex holds a SHARE lock for the whole +build and would block writes to a large, write-heavy table. Prefer building it out of +band before the deploy. Application tables are not in the default search path — the +schema comes from DB_SCHEMA and is set per connection by the app's own wrapper, which a +psql session does not inherit — so set it first: + + SET search_path TO unstract; -- or whatever DB_SCHEMA is set to + CREATE INDEX CONCURRENTLY IF NOT EXISTS wfe_status_created_idx + ON workflow_file_execution (status, created_at); + +The migration then no-ops via IF NOT EXISTS and asserts the existing index is valid +and has the expected definition. Do not build the two-index variant from an older +revision of UN-3972's description: wfe_created_at_desc_idx was struck as worse than +nothing. +""" + +from django.db import migrations, models + +INDEX_NAME = "wfe_status_created_idx" + +INDEX_DEF_SUFFIX = "USING btree (status, created_at)" + +# IF NOT EXISTS matches on name alone, so a hand-built index with different columns +# would be kept while Django recorded (status, created_at) into model state. An +# interrupted CONCURRENTLY build likewise leaves an INVALID index that costs on every +# write and is never read. Fail loudly on both rather than diverge silently. +_ASSERT_INDEX_MATCHES = f""" +DO $$ +DECLARE + idx_def text; + idx_valid boolean; +BEGIN + SELECT pg_get_indexdef(i.indexrelid), i.indisvalid INTO idx_def, idx_valid + FROM pg_class c + JOIN pg_namespace n ON n.oid = c.relnamespace + JOIN pg_index i ON i.indexrelid = c.oid + WHERE c.relname = '{INDEX_NAME}' AND n.nspname = current_schema(); + + IF idx_def IS NULL THEN + RAISE EXCEPTION 'Index {INDEX_NAME} is missing from schema % after CREATE INDEX.', current_schema(); + END IF; + + IF NOT idx_valid THEN + RAISE EXCEPTION 'Index {INDEX_NAME} exists but is INVALID (a prior CREATE INDEX CONCURRENTLY was interrupted). Drop it and re-run: DROP INDEX CONCURRENTLY IF EXISTS {INDEX_NAME};'; + END IF; + + IF idx_def NOT LIKE '%{INDEX_DEF_SUFFIX}' THEN + RAISE EXCEPTION 'Index {INDEX_NAME} exists with an unexpected definition (%), expected {INDEX_DEF_SUFFIX}. Drop it and re-run: DROP INDEX CONCURRENTLY IF EXISTS {INDEX_NAME};', idx_def; + END IF; +END +$$; +""" + + +class Migration(migrations.Migration): + # CREATE / DROP INDEX CONCURRENTLY cannot run inside a transaction block. + atomic = False + + dependencies = [ + ( + "file_execution", + "0006_workflowfileexecution_wf_file_hash_path_status_idx_and_more", + ), + ] + + operations = [ + migrations.SeparateDatabaseAndState( + database_operations=[ + migrations.RunSQL( + sql=( + f"CREATE INDEX CONCURRENTLY IF NOT EXISTS {INDEX_NAME} " + "ON workflow_file_execution (status, created_at);" + ), + reverse_sql=f"DROP INDEX CONCURRENTLY IF EXISTS {INDEX_NAME};", + ), + migrations.RunSQL( + sql=_ASSERT_INDEX_MATCHES, reverse_sql=migrations.RunSQL.noop + ), + ], + state_operations=[ + migrations.AddIndex( + model_name="workflowfileexecution", + index=models.Index(fields=["status", "created_at"], name=INDEX_NAME), + ), + ], + ), + ] diff --git a/backend/workflow_manager/file_execution/models.py b/backend/workflow_manager/file_execution/models.py index 105b3875a9..61da4f1d26 100644 --- a/backend/workflow_manager/file_execution/models.py +++ b/backend/workflow_manager/file_execution/models.py @@ -198,6 +198,14 @@ class Meta: ], name="wf_provider_uuid_path_stat_idx", ), + # Every other index on this table is prefixed by the workflow_execution + # FK column, so none can serve a status + created_at filter. Serves both + # get_failed_pages and, since UN-3973 narrowed the source window, the + # COMPLETED path. See migration 0007. + models.Index( + fields=["status", "created_at"], + name="wfe_status_created_idx", + ), ] constraints = [ models.UniqueConstraint( diff --git a/backend/workflow_manager/file_execution/tests/__init__.py b/backend/workflow_manager/file_execution/tests/__init__.py new file mode 100644 index 0000000000..e69de29bb2 diff --git a/backend/workflow_manager/file_execution/tests/test_index_migration_guards.py b/backend/workflow_manager/file_execution/tests/test_index_migration_guards.py new file mode 100644 index 0000000000..a99a2f9d29 --- /dev/null +++ b/backend/workflow_manager/file_execution/tests/test_index_migration_guards.py @@ -0,0 +1,106 @@ +"""Both index migrations' ``DO $$`` guard blocks, executed by a real server. + +The suite runs under ``--no-migrations``, so neither migration is ever applied and +no Postgres ever parses these blocks. Their assertions are otherwise checked only +as Python substrings, which cannot tell valid PL/pgSQL from invalid: breaking +``BEGIN`` to ``BEGINN`` in both migrations leaves the whole suite green while +``migrate`` would fail outright on the deploy this guard exists to protect. + +Both migrations are covered here rather than in their own apps because the guard +is one shape written twice, and a divergence between the two copies is exactly +what a single exerciser catches. + +Each block is run twice: once against the index it expects, and once against an +index of the same name with a different definition — the ``(created_at DESC)`` +slip its own comment calls out. A guard that never fires is not a guard. + +DB-bound, so conftest marks it integration. +""" + +from __future__ import annotations + +import os + +import django +from django.apps import apps as django_apps + +os.environ.setdefault("DJANGO_SETTINGS_MODULE", "backend.settings.test") +if not django_apps.ready: + django.setup() + +from importlib import import_module # noqa: E402 + +from django.db import connection # noqa: E402 +from django.db.utils import InternalError # noqa: E402 +from django.test import TransactionTestCase # noqa: E402 + +_MIGRATIONS = { + "wfe_status_created_idx": ( + "workflow_manager.file_execution.migrations.0007_wfe_status_created_idx", + "workflow_file_execution", + "(status, created_at)", + ), + "we_created_at_idx": ( + "workflow_manager.workflow_v2.migrations.0029_we_created_at_idx", + "workflow_execution", + "(created_at)", + ), +} + + +class TestTheIndexGuardsAreRunnableSql(TransactionTestCase): + """The guard blocks parse and behave, against a live server.""" + + def _module(self, index_name): + return import_module(_MIGRATIONS[index_name][0]) + + def _run_guard(self, index_name): + with connection.cursor() as cur: + cur.execute(self._module(index_name)._ASSERT_INDEX_MATCHES) + + def _replace_with_a_wrong_index(self, index_name): + """Same name, descending — the slip the migration's own comment names.""" + _, table, columns = _MIGRATIONS[index_name] + descending = columns.replace(")", " DESC)").replace(", ", " DESC, ") + with connection.cursor() as cur: + cur.execute(f"DROP INDEX IF EXISTS {index_name}") + cur.execute(f"CREATE INDEX {index_name} ON {table} {descending}") + + def test_the_guards_pass_against_the_index_they_expect(self): + """Also the parse check: invalid PL/pgSQL cannot reach a passing result.""" + for index_name in _MIGRATIONS: + with self.subTest(index=index_name): + self._run_guard(index_name) + + def test_each_guard_rejects_an_index_of_the_same_name_built_descending(self): + """IF NOT EXISTS matches on name alone, which is why this case exists.""" + for index_name, (_, table, columns) in _MIGRATIONS.items(): + with self.subTest(index=index_name): + self._replace_with_a_wrong_index(index_name) + try: + with self.assertRaises(InternalError) as caught: + self._run_guard(index_name) + assert "unexpected definition" in str(caught.exception), ( + f"{index_name}: the guard raised, but not for the reason it " + f"claims to:\n{caught.exception}" + ) + finally: + with connection.cursor() as cur: + cur.execute(f"DROP INDEX IF EXISTS {index_name}") + cur.execute(f"CREATE INDEX {index_name} ON {table} {columns}") + + def test_each_guard_rejects_a_missing_index(self): + for index_name, (_, table, columns) in _MIGRATIONS.items(): + with self.subTest(index=index_name): + with connection.cursor() as cur: + cur.execute(f"DROP INDEX IF EXISTS {index_name}") + try: + with self.assertRaises(InternalError) as caught: + self._run_guard(index_name) + assert "is missing from schema" in str(caught.exception) + finally: + with connection.cursor() as cur: + cur.execute( + f"CREATE INDEX IF NOT EXISTS {index_name} " + f"ON {table} {columns}" + ) diff --git a/backend/workflow_manager/file_execution/tests/test_wfe_status_created_idx.py b/backend/workflow_manager/file_execution/tests/test_wfe_status_created_idx.py new file mode 100644 index 0000000000..4707ac3c78 --- /dev/null +++ b/backend/workflow_manager/file_execution/tests/test_wfe_status_created_idx.py @@ -0,0 +1,119 @@ +"""Shape guard for the ``(status, created_at)`` index migration (UN-3972). + +``workflow_file_execution`` is ~3.4 GB in production and takes live inserts. A plain +``AddIndex`` — which is what ``makemigrations`` emits from ``Meta.indexes`` — holds a +``SHARE`` lock for the whole build and stalls file processing. ``0007`` is therefore +hand-written: non-atomic, ``CONCURRENTLY``, and split so the ``AddIndex`` updates model +state only. + +Nothing else guards that. The suite runs with ``--no-migrations``, so this migration is +never executed in CI; regenerating or "tidying" it would land the locking version with +every test still green. These assertions are what fails instead. + +DB-free by design: the migration module is imported and inspected directly. +""" + +from __future__ import annotations + +import importlib + +from django.db import migrations +from django.test import SimpleTestCase + +from workflow_manager.file_execution.models import WorkflowFileExecution + +_MIGRATION = "workflow_manager.file_execution.migrations.0007_wfe_status_created_idx" + +INDEX_NAME = "wfe_status_created_idx" +INDEX_FIELDS = ["status", "created_at"] +TABLE = "workflow_file_execution" + + +class MigrationShapeTests(SimpleTestCase): + """The properties that keep the build off the write path.""" + + @classmethod + def setUpClass(cls) -> None: + super().setUpClass() + cls.migration = importlib.import_module(_MIGRATION).Migration + cls.operation = cls.migration.operations[0] + + def test_the_migration_has_exactly_one_operation(self) -> None: + """Every other assertion reads operations[0], so anything appended after the + SeparateDatabaseAndState is invisible — including a bare AddIndex, which is a + real lock-taking build on a 3.4 GB table. + """ + self.assertEqual(len(self.migration.operations), 1) + + def test_no_operation_builds_an_index_against_the_database(self) -> None: + """The same failure stated directly, so it survives the count changing.""" + for op in self.migration.operations: + self.assertNotIsInstance(op, migrations.AddIndex) + + def test_migration_is_non_atomic(self) -> None: + """CREATE/DROP INDEX CONCURRENTLY is rejected inside a transaction block.""" + self.assertIs(self.migration.atomic, False) + + def test_index_is_built_and_dropped_concurrently(self) -> None: + """Both directions must stay off the write-blocking lock path.""" + create = self.operation.database_operations[0] + self.assertIn("CREATE INDEX CONCURRENTLY IF NOT EXISTS", create.sql) + self.assertIn(INDEX_NAME, create.sql) + # Column order is the point — (created_at, status) cannot serve an equality + # plus range filter. Whitespace and case are not, and a red test on + # semantically identical SQL only teaches people to loosen the assertion. + self.assertRegex( + create.sql, + rf"ON\s+{TABLE}\s*\(\s*{INDEX_FIELDS[0]}\s*,\s*{INDEX_FIELDS[1]}\s*\)", + ) + self.assertIn("DROP INDEX CONCURRENTLY IF EXISTS", create.reverse_sql) + # A typo here makes rollback a silent no-op through IF EXISTS: Django unapplies + # the migration while the index stays on the table. + self.assertIn(INDEX_NAME, create.reverse_sql) + + def test_every_database_operation_is_reversible(self) -> None: + """One irreversible operation kills the whole rollback, DROP INDEX included.""" + self.assertTrue(all(op.reversible for op in self.operation.database_operations)) + + def test_pre_existing_index_guard_is_present(self) -> None: + """``IF NOT EXISTS`` matches on name alone, so the guard carries the rest. + + An interrupted concurrent build leaves an INVALID index, and a hand-built one + may have different columns; either would be kept while Django recorded the + migration as applied. The guard turns both into a loud failure, and looks the + index up in ``current_schema()`` because app tables do not live in ``public``. + """ + guard = self.operation.database_operations[1].sql + # Polarity, not presence: `NOT idx_valid` raises on a broken index, `idx_valid` + # raises on every healthy deploy, and both contain "indisvalid". + self.assertIn("i.indisvalid", guard) + self.assertIn("IF NOT idx_valid THEN", guard) + # Scoped to this index, in this schema. + self.assertIn(f"c.relname = '{INDEX_NAME}'", guard) + self.assertIn("n.nspname = current_schema()", guard) + # Definition, not just validity. + self.assertIn("pg_get_indexdef", guard) + self.assertIn(f"USING btree ({', '.join(INDEX_FIELDS)})", guard) + self.assertIn("NOT LIKE", guard) + self.assertIn("RAISE EXCEPTION", guard) + self.assertIn(f"DROP INDEX CONCURRENTLY IF EXISTS {INDEX_NAME}", guard) + + def test_add_index_updates_state_only(self) -> None: + """``AddIndex`` must not reach the database, or it builds a second time.""" + self.assertIsInstance(self.operation, migrations.SeparateDatabaseAndState) + self.assertTrue( + all( + isinstance(op, migrations.RunSQL) + for op in self.operation.database_operations + ) + ) + self.assertEqual(len(self.operation.state_operations), 1) + state_op = self.operation.state_operations[0] + self.assertIsInstance(state_op, migrations.AddIndex) + self.assertEqual(state_op.index.name, INDEX_NAME) + self.assertEqual(state_op.index.fields, INDEX_FIELDS) + + def test_model_meta_matches_the_migration(self) -> None: + """Model state and migration state drift silently otherwise.""" + declared = {idx.name: idx.fields for idx in WorkflowFileExecution._meta.indexes} + self.assertEqual(declared.get(INDEX_NAME), INDEX_FIELDS) diff --git a/backend/workflow_manager/file_execution/tests/test_wfe_status_created_idx_planner.py b/backend/workflow_manager/file_execution/tests/test_wfe_status_created_idx_planner.py new file mode 100644 index 0000000000..9f4cc6f2b0 --- /dev/null +++ b/backend/workflow_manager/file_execution/tests/test_wfe_status_created_idx_planner.py @@ -0,0 +1,207 @@ +"""The metric queries can actually use wfe_status_created_idx (UN-3972). + +``test_wfe_status_created_idx.py`` proves the index is declared and built safely — +every assertion there reads migration attributes or greps ``Meta.indexes``. That +leaves the pairing unproven: change ``get_documents_processed`` or +``get_failed_pages`` to stop leading with ``status`` and the index stays built, +valid and dead, with the whole suite green. + +This is the sibling of ``dashboard_metrics/tests/test_active_org_prefilter.py``, +which does the same job for ``we_created_at_idx``, and it is deliberately the same +shape: seed at production-ish status ratios, ``ANALYZE``, then ask whether the plan +*can* be served from the index rather than whether the planner chooses it. + +What is asserted is the **predicate**, not the full joined metric query. The metric +queries reach this table through ``workflow_execution__workflow__organization_id``, +so which side the planner drives from is a cost-model decision that a synthetic +fixture cannot pin — asserting it would red the build on a config change. The +predicate is the part the index exists for, and a query that stops filtering on +``status`` stops matching it. + +**Not production evidence.** A few thousand rows on a locally-configured Postgres +is not the production planner's input. What the assertion rules out is the +regression — a metric query that must read the table whatever the cost model says. + +DB-bound, so conftest marks it integration. +""" + +from __future__ import annotations + +import os +from datetime import timedelta + +import django +from django.apps import apps + +os.environ.setdefault("DJANGO_SETTINGS_MODULE", "backend.settings.test") +if not apps.ready: + django.setup() + +from account_v2.models import Organization # noqa: E402 +from django.db import connection # noqa: E402 +from django.test import TestCase # noqa: E402 +from django.test.utils import CaptureQueriesContext # noqa: E402 +from django.utils import timezone # noqa: E402 +from workflow_manager.file_execution.models import WorkflowFileExecution # noqa: E402 +from workflow_manager.workflow_v2.enums import ExecutionStatus # noqa: E402 +from workflow_manager.workflow_v2.models.execution import WorkflowExecution # noqa: E402 +from workflow_manager.workflow_v2.models.workflow import Workflow # noqa: E402 + +from dashboard_metrics.models import Granularity # noqa: E402 +from dashboard_metrics.services import MetricsQueryService # noqa: E402 + + +INDEX_NAME = "wfe_status_created_idx" + +_ROWS = 4000 +_SPAN_DAYS = 60 +# Measured on the replica 2026-08-27: COMPLETED is 97.6% of the table and ERROR +# 0.40%. The ratio is the whole point — a partial index on ERROR would serve +# get_failed_pages and never get_documents_processed, which is why this one is full. +_ERROR_IN = 250 + + +class TestTheMetricQueriesCanUseTheIndex(TestCase): + """Both queries the index exists for, at production-ish status ratios.""" + + @classmethod + def setUpTestData(cls) -> None: + org = Organization.objects.create( + organization_id="wfe-idx-org", name="wfe-idx", display_name="WFE Idx" + ) + workflow = Workflow.objects.create(workflow_name="wfe-idx-wf", organization=org) + cls.org_id = org.id + execution = WorkflowExecution.objects.create( + workflow_id=workflow.id, status=ExecutionStatus.COMPLETED + ) + + now = timezone.now() + rows = [] + for n in range(_ROWS): + status = ( + ExecutionStatus.ERROR.value + if n % _ERROR_IN == 0 + else ExecutionStatus.COMPLETED.value + ) + rows.append( + WorkflowFileExecution( + workflow_execution=execution, + file_name=f"idx-{n}.pdf", + status=status, + ) + ) + WorkflowFileExecution.objects.bulk_create(rows, batch_size=1000) + + # bulk_create overwrites auto_now_add with now(), so spread the dates + # afterwards. Correlation is not pinned and does not need to be: the + # assertions below run under enable_seqscan = off, which asks whether the + # index CAN serve the predicate, not whether the planner picks it. + # Scoped to this fixture's own execution: an unqualified UPDATE would rewrite + # created_at for every row in whatever database this happens to run against. + with connection.cursor() as cur: + cur.execute( + "UPDATE workflow_file_execution SET created_at = %s::timestamptz" + " - (random() * %s || ' days')::interval" + " WHERE workflow_execution_id = %s", + [now.isoformat(), _SPAN_DAYS, str(execution.id)], + ) + cur.execute("ANALYZE workflow_file_execution") + + def _plan(self, status: str) -> str: + with connection.cursor() as cur: + cur.execute("SET LOCAL enable_seqscan = off") + cur.execute( + "EXPLAIN SELECT date_trunc('day', created_at), count(*)" + " FROM workflow_file_execution" + " WHERE status = %s AND created_at >= now() - interval '2 days'" + " GROUP BY 1", + [status], + ) + return "\n".join(row[0] for row in cur.fetchall()) + + def _assert_status_leads_the_index_scan(self, status: str) -> None: + plan = self._plan(status) + assert INDEX_NAME in plan, ( + f"expected {INDEX_NAME} to be usable for status={status}:\n{plan}" + ) + index_cond = [ln for ln in plan.splitlines() if "Index Cond" in ln] + assert any("status" in ln for ln in index_cond), ( + f"{INDEX_NAME} is in the plan for status={status} but not entered by " + f"status, so it is not serving the shape it was added for:\n{plan}" + ) + + def _real_query_sql(self, query_method) -> str: + """The SQL the production metric query actually emits. + + Taken from the query rather than rewritten here. A hand-copied predicate + keeps passing after the query changes, which is the one thing this file is + for — the sibling prefilter test says exactly that and does exactly this. + """ + now = timezone.now() + with CaptureQueriesContext(connection) as captured: + query_method( + organization_id=str(self.org_id), + start_date=now - timedelta(days=2), + end_date=now, + granularity=Granularity.DAY, + ) + sql = [ + q["sql"] + for q in captured.captured_queries + if "workflow_file_execution" in q["sql"] + ] + assert sql, f"{query_method.__name__} did not read workflow_file_execution" + return sql[-1] + + def test_get_documents_processed_still_filters_on_status(self) -> None: + """The pairing this index exists for. + + Which side the planner drives from on a joined query is a cost-model + decision a synthetic fixture cannot pin, so this asserts the half that is + the actual regression: the query stops filtering on status and the index is + left built, valid and dead. + """ + sql = self._real_query_sql(MetricsQueryService.get_documents_processed) + assert '"status"' in sql and "created_at" in sql, ( + "get_documents_processed no longer constrains status and created_at " + f"together, so {INDEX_NAME} cannot serve it:\n{sql}" + ) + + def test_get_failed_pages_still_filters_on_status(self) -> None: + sql = self._real_query_sql(MetricsQueryService.get_failed_pages) + assert '"status"' in sql and "created_at" in sql, ( + "get_failed_pages no longer constrains status and created_at together, " + f"so {INDEX_NAME} cannot serve it:\n{sql}" + ) + + def test_the_index_serves_the_documents_processed_predicate(self) -> None: + """status = COMPLETED plus a created_at window — get_documents_processed.""" + self._assert_status_leads_the_index_scan(ExecutionStatus.COMPLETED.value) + + def test_the_index_serves_the_failed_pages_predicate(self) -> None: + """status = ERROR plus the same window — get_failed_pages. + + The full index is what lets one index serve both; a partial index on ERROR + would pass this and fail the one above. + """ + self._assert_status_leads_the_index_scan(ExecutionStatus.ERROR.value) + + def test_the_index_is_valid(self) -> None: + """The index exists and is valid in the schema under test. + + Note what this does NOT cover: the suite runs under --no-migrations, so 0007 + never executes and the index here comes from Meta.indexes, which cannot + produce an INVALID one. The migration's own DO $$ assertion is the guard for + that, and test_wfe_status_created_idx.py pins its presence. + """ + with connection.cursor() as cur: + cur.execute( + "SELECT i.indisvalid FROM pg_class c" + " JOIN pg_index i ON i.indexrelid = c.oid" + " JOIN pg_namespace n ON n.oid = c.relnamespace" + " WHERE c.relname = %s AND n.nspname = current_schema()", + [INDEX_NAME], + ) + row = cur.fetchone() + assert row is not None, f"{INDEX_NAME} does not exist in the test schema" + assert row[0] is True, f"{INDEX_NAME} exists but is INVALID" diff --git a/backend/workflow_manager/workflow_v2/migrations/0029_we_created_at_idx.py b/backend/workflow_manager/workflow_v2/migrations/0029_we_created_at_idx.py new file mode 100644 index 0000000000..cab0eff8bf --- /dev/null +++ b/backend/workflow_manager/workflow_v2/migrations/0029_we_created_at_idx.py @@ -0,0 +1,91 @@ +"""Add a created_at index to workflow_execution. + +Serves bare "rows in this date window" queries with no leading column value — the +dashboard metrics active-org prefilter today, and the grouped metric queries in +UN-4094. The composite indexes lead with workflow_id / pipeline_id, so they are +date-ordered only within one workflow or pipeline, and the two indexes that are +keyed on created_at are partial, so neither covers the full range. Measurements in +UN-3883. + +Built CONCURRENTLY (atomic = False): a plain AddIndex holds a SHARE lock for the +whole build and would block every execution in flight. Prefer building it out of +band before the deploy. Application tables are not in the default search path — the +schema comes from DB_SCHEMA and is set per connection by the app's own wrapper, which a +psql session does not inherit — so set it first:: + + SET search_path TO unstract; -- or whatever DB_SCHEMA is set to + CREATE INDEX CONCURRENTLY IF NOT EXISTS we_created_at_idx + ON workflow_execution (created_at); + +The migration then no-ops via IF NOT EXISTS and asserts the existing index is valid +and has the expected definition. +""" + +from django.db import migrations, models + +INDEX_NAME = "we_created_at_idx" + +INDEX_DEF_SUFFIX = "USING btree (created_at)" + +# IF NOT EXISTS matches on name alone, so a hand-built index with a different +# definition — (created_at DESC) is the likely slip, since the neighbouring indexes +# in this Meta are declared "-created_at" — would be kept while AddIndex recorded +# fields=["created_at"] into model state. An interrupted CONCURRENTLY build likewise +# leaves an INVALID index that costs on every write and is never read. Fail loudly on +# both rather than diverge silently. +_ASSERT_INDEX_MATCHES = f""" +DO $$ +DECLARE + idx_def text; + idx_valid boolean; +BEGIN + SELECT pg_get_indexdef(i.indexrelid), i.indisvalid INTO idx_def, idx_valid + FROM pg_class c + JOIN pg_namespace n ON n.oid = c.relnamespace + JOIN pg_index i ON i.indexrelid = c.oid + WHERE c.relname = '{INDEX_NAME}' AND n.nspname = current_schema(); + + IF idx_def IS NULL THEN + RAISE EXCEPTION 'Index {INDEX_NAME} is missing from schema % after CREATE INDEX.', current_schema(); + END IF; + + IF NOT idx_valid THEN + RAISE EXCEPTION 'Index {INDEX_NAME} exists but is INVALID (a prior CREATE INDEX CONCURRENTLY was interrupted). Drop it and re-run: DROP INDEX CONCURRENTLY IF EXISTS {INDEX_NAME};'; + END IF; + + IF idx_def NOT LIKE '%{INDEX_DEF_SUFFIX}' THEN + RAISE EXCEPTION 'Index {INDEX_NAME} exists with an unexpected definition (%), expected {INDEX_DEF_SUFFIX}. Drop it and re-run: DROP INDEX CONCURRENTLY IF EXISTS {INDEX_NAME};', idx_def; + END IF; +END +$$; +""" + + +class Migration(migrations.Migration): + # CREATE / DROP INDEX CONCURRENTLY cannot run inside a transaction block. + atomic = False + + dependencies = [("workflow_v2", "0028_undispatched_idx_dispatched_at")] + + operations = [ + migrations.SeparateDatabaseAndState( + database_operations=[ + migrations.RunSQL( + sql=( + f"CREATE INDEX CONCURRENTLY IF NOT EXISTS {INDEX_NAME} " + "ON workflow_execution (created_at);" + ), + reverse_sql=f"DROP INDEX CONCURRENTLY IF EXISTS {INDEX_NAME};", + ), + migrations.RunSQL( + sql=_ASSERT_INDEX_MATCHES, reverse_sql=migrations.RunSQL.noop + ), + ], + state_operations=[ + migrations.AddIndex( + model_name="workflowexecution", + index=models.Index(fields=["created_at"], name=INDEX_NAME), + ), + ], + ), + ] diff --git a/backend/workflow_manager/workflow_v2/models/execution.py b/backend/workflow_manager/workflow_v2/models/execution.py index d6082aa423..1f39804783 100644 --- a/backend/workflow_manager/workflow_v2/models/execution.py +++ b/backend/workflow_manager/workflow_v2/models/execution.py @@ -272,6 +272,10 @@ class Meta: queue_message_id__isnull=True, ), ), + # Bare created_at range scans, which no index above serves: the two that + # are keyed on created_at are partial, so neither covers the full range. + # See migration 0029. + models.Index(fields=["created_at"], name="we_created_at_idx"), ] @property diff --git a/backend/workflow_manager/workflow_v2/tests/test_we_created_at_idx.py b/backend/workflow_manager/workflow_v2/tests/test_we_created_at_idx.py new file mode 100644 index 0000000000..eb27ebf06c --- /dev/null +++ b/backend/workflow_manager/workflow_v2/tests/test_we_created_at_idx.py @@ -0,0 +1,152 @@ +"""Guard: ``we_created_at_idx`` keeps the shape that makes it safe to deploy. + +The backend suite runs with ``--no-migrations``, so migration 0029 never executes in +CI. Regenerating it with ``makemigrations``, or dropping ``atomic = False`` while +tidying, lands a plain ``AddIndex`` — which holds a SHARE lock for the whole build and +blocks every in-flight execution on a multi-million-row table — with every other test +still green. These assert the properties that keep that from happening. + +Model and migration introspection only, no test database, so this runs in the unit tier +alongside ``test_active_execution_index.py`` and ``test_undispatched_execution_index.py``. +""" + +from __future__ import annotations + +import importlib +import os +import re +from pathlib import Path +from typing import Any, cast + +import django +from django.apps import apps +from django.db import migrations, models + +os.environ.setdefault("DJANGO_SETTINGS_MODULE", "backend.settings.test") +if not apps.ready: + django.setup() + +INDEX_NAME = "we_created_at_idx" +_MIGRATION_FILE = ( + Path(__file__).resolve().parent.parent / "migrations" / "0029_we_created_at_idx.py" +) +_MIGRATION_MODULE = "workflow_manager.workflow_v2.migrations.0029_we_created_at_idx" + + +def _model_index() -> models.Index | None: + model = apps.get_model("workflow_v2", "WorkflowExecution") + return next((i for i in model._meta.indexes if i.name == INDEX_NAME), None) + + +def _operations() -> list[Any]: + return cast( + list[Any], importlib.import_module(_MIGRATION_MODULE).Migration.operations + ) + + +class TestTheModelDeclaresIt: + def test_it_is_keyed_on_created_at_alone(self) -> None: + """A bare created_at range with no leading column value is the whole point — + the composite indexes lead with workflow_id / pipeline_id and are date-ordered + only within one workflow or pipeline. + """ + index = _model_index() + assert index is not None, f"{INDEX_NAME} is missing from WorkflowExecution.Meta" + assert index.fields == ["created_at"] + + def test_it_carries_no_condition(self) -> None: + """A partial index would not serve the prefilter, which bounds nothing but the + date. we_undispatched_dispatch_idx is the partial one and is a different index. + """ + assert getattr(_model_index(), "condition", None) is None + + +class TestTheMigrationIsSafeToDeploy: + def test_it_is_non_atomic(self) -> None: + """CREATE/DROP INDEX CONCURRENTLY cannot run inside a transaction block, so + without this the migration cannot run at all. + """ + assert re.search( + r"^\s*atomic\s*=\s*False", _MIGRATION_FILE.read_text(), re.MULTILINE + ) + + def test_it_builds_and_drops_concurrently(self) -> None: + """Both directions: a plain DROP INDEX takes an ACCESS EXCLUSIVE lock, so a + rollback would block writes just as a plain build would. + + Asserted on the rendered operation, not the file source: the guard's own + RAISE EXCEPTION messages contain the DROP text, so a source grep passes even + if reverse_sql is a noop and the index survives the rollback. + """ + create = _operations()[0].database_operations[0] + assert "CREATE INDEX CONCURRENTLY IF NOT EXISTS" in create.sql + assert f"DROP INDEX CONCURRENTLY IF EXISTS {INDEX_NAME}" in create.reverse_sql + + def test_the_statement_that_runs_names_the_model_table_and_column(self) -> None: + """Everything else here reads the ``AddIndex`` state operation, which by + construction never reaches the database, or greps the source for + ``CONCURRENTLY``. The ``RunSQL`` is the only statement production executes and + its table and column were cross-checked against nothing — so the index could be + built on the wrong column while Django's model state claimed otherwise. + """ + index = _model_index() + assert index is not None + model = apps.get_model("workflow_v2", "WorkflowExecution") + expected = f"{model._meta.db_table} ({', '.join(index.fields)})" + + create = _operations()[0].database_operations[0] + assert expected in create.sql, f"expected {expected!r} in {create.sql!r}" + + def test_it_guards_against_a_leftover_invalid_index(self) -> None: + """An interrupted CONCURRENTLY build leaves an INVALID index that costs on every + write and is never read. IF NOT EXISTS would keep it while Django recorded the + migration as applied — green, and permanently slower. + """ + sql = _MIGRATION_FILE.read_text() + assert "RAISE EXCEPTION" in sql + # Polarity, not presence: `NOT idx_valid` raises on a broken index, `idx_valid` + # would raise on every healthy deploy, and both contain "indisvalid". + assert "i.indisvalid" in sql + assert "IF NOT idx_valid THEN" in sql + + def test_it_guards_against_a_hand_built_index_of_the_wrong_shape(self) -> None: + """IF NOT EXISTS matches on name alone. + + The likely slip is (created_at DESC), since the neighbouring indexes in this + Meta are declared "-created_at". Without a definition check that index is kept + while AddIndex records fields=["created_at"] into model state, and nothing ever + reports the divergence. + """ + # The rendered statement, not the file source: the source carries {INDEX_NAME} + # placeholders, so asserting on it would pass whatever the name resolves to. + guard = _operations()[0].database_operations[1].sql + assert "pg_get_indexdef" in guard + assert "USING btree (created_at)" in guard + assert "NOT LIKE" in guard + # Scoped to this index, in this schema — app tables do not live in `public`. + assert "c.relname = 'we_created_at_idx'" in guard + assert "n.nspname = current_schema()" in guard + # The remedy is in the message the operator actually sees. + assert "DROP INDEX CONCURRENTLY IF EXISTS we_created_at_idx" in guard + + def test_add_index_is_state_only(self) -> None: + """The failure mode this whole file exists for. AddIndex outside + state_operations is a real lock-taking build; inside, it only keeps Django's + model state in step so makemigrations does not re-add the index. + """ + ops = _operations() + assert len(ops) == 1 + wrapper = ops[0] + assert isinstance(wrapper, migrations.SeparateDatabaseAndState) + assert all( + isinstance(op, migrations.RunSQL) for op in wrapper.database_operations + ) + assert [type(op) for op in wrapper.state_operations] == [migrations.AddIndex] + + def test_the_migration_and_the_model_agree(self) -> None: + """Two declarations of one index; they must not drift.""" + index = _model_index() + assert index is not None + add_index = _operations()[0].state_operations[0] + assert add_index.index.name == INDEX_NAME + assert add_index.index.fields == index.fields diff --git a/docker/docker-compose.yaml b/docker/docker-compose.yaml index 9f6ca7789d..e89ca0e19d 100644 --- a/docker/docker-compose.yaml +++ b/docker/docker-compose.yaml @@ -419,7 +419,11 @@ services: # Sized for a minutes-long aggregation: stale > vt > the task's own ceiling. - WORKER_PG_QUEUE_CONSUMER_VT_SECONDS=${WORKER_PG_METRICS_VT_SECONDS:-900} - WORKER_PG_QUEUE_CONSUMER_HEALTH_STALE_SECONDS=${WORKER_PG_METRICS_HEALTH_STALE_SECONDS:-960} - # One at a time — these are global singletons, not parallel work. + # One at a time. Since UN-3974 split the aggregation by tier the crons can + # overlap (the :20 daily/monthly row against a long */15 run, and the 04:40 + # reconcile against the 04:45 one), and the per-tier lock keys deliberately do + # not exclude them — so this serialises them instead. Raise to 2 if the tail + # delay matters more than the DB load two concurrent runs add. - WORKER_PG_QUEUE_CONSUMER_CONCURRENCY=1 - WORKER_PG_QUEUE_CONSUMER_MAX_ATTEMPTS=1 labels: diff --git a/workers/scheduler/dashboard_metrics_tasks.py b/workers/scheduler/dashboard_metrics_tasks.py index 44bbe50440..dec4869b9b 100644 --- a/workers/scheduler/dashboard_metrics_tasks.py +++ b/workers/scheduler/dashboard_metrics_tasks.py @@ -91,23 +91,140 @@ def _call_internal( return response.json() +def _log_if_failed(name: str, result: dict[str, Any]) -> None: + """Surface a cleanup that reported failure. + + The backend catches every exception and answers 200 with ``success: False``, + so a permanently failing retention delete is otherwise invisible here. + """ + if not result.get("success", True): + logger.warning("%s did not complete: %s", name, result.get("error", "no detail")) + + def _log_if_skipped(name: str, result: dict[str, Any]) -> None: - """Surface a lock-held no-op. + """Surface a run that did nothing, whatever shape the backend reported it in. + + Each condition is correct behaviour in isolation, but left at INFO a leaked lock + or a frozen source table looks like a day of successful runs. The arms below are + the enumeration; keeping a second copy here only lets the two drift. + + The conditions are independent, not alternatives: an empty prefilter and a + failed monthly rollup co-occur, since the rollup is org-agnostic and runs even + when the org loop did not. Reported as an ``elif`` chain the failure would sit + behind a benign "no active orgs" line. - The backend returns success with ``skipped=True`` when the Redis lock is held. That - is correct behaviour, but left at INFO a permanently leaked lock looks like 96 - successful runs a day that did nothing. + ``skipped_reason`` reports the prefilter, not the whole run, so the row count + says which happened. """ + wrote = sum( + result.get(granularity, {}).get("upserted", 0) + for granularity in ("hourly", "daily", "monthly") + ) + monthly = result.get("monthly", {}) if result.get("skipped"): logger.warning( "%s did no work: %s", name, result.get("reason", "reported skipped=True") ) + return + + if result.get("skipped_reason"): + logger.warning("%s: %s (rows written: %d)", name, result["skipped_reason"], wrote) + if result.get("errors"): + # ERROR, not WARNING: a periodic on the PG transport is fire-and-forget, so + # nothing records a task status either way and severity is the only signal + # that reaches an alert. Raising instead would buy a poison-drop at + # MAX_ATTEMPTS=1 and no retry. + logger.error( + "%s completed with %s error(s) across %s organisation(s)", + name, + result["errors"], + result.get("organizations_processed", "?"), + ) + if stale := monthly.get("needs_daily_repair"): + # Same wording as the backend's own line: these months were KEPT, not + # overwritten. Saying "lowered" here points at a rollback when the fix is a + # backfill, and on-call sees this line first on the PG transport. + logger.warning( + "%s left %s unchanged — the daily tier now sums lower than the stored " + "total, so the figures were kept rather than overwritten. Repair daily " + "for those months with `backfill_metrics`", + name, + ", ".join(stale), + ) + if short := monthly.get("incomplete_daily_coverage"): + # Independent of needs_daily_repair: a month with no stored total to compare + # against is under-counted without ever being "lowered". + logger.warning( + "%s rolled up an incomplete daily tier for %s — those totals are " + "under-counted whether or not they were lowered. Repair with " + "`backfill_metrics` if the source tables hold those days; a date on " + "which nothing ran anywhere reads the same and needs no action", + name, + ", ".join(short), + ) + if monthly.get("coverage_check") == "unavailable": + logger.warning( + "%s could not check whether the daily tier is missing whole days", name + ) + if monthly.get("lowered_check") == "unavailable": + # Distinct from "nothing was lowered": the check itself did not run, so this + # run verified nothing about the derived tier. + logger.warning( + "%s could not check whether the rollup would lower monthly totals", name + ) + if monthly.get("failed"): + # Distinct from a per-org metric error: the rollup is org-agnostic, so its + # failure leaves EVERY tenant's monthly tier stale for this run. + logger.error( + "%s: the monthly rollup did not run; every tenant's monthly tier is " + "stale for this run", + name, + ) + if ( + result.get("tier") != "hourly" + and not wrote + and not result.get("skipped_reason") + and not result.get("errors") + ): + # The signature of the regression this change could introduce: a tier with + # work to do, no error, and nothing written. Not on the */15 hourly row, + # which writes nothing on a quiet weekend by design — the backend guards the + # same condition with _writes_daily_monthly, and without the guard here this + # warns 96 times a day about a healthy fleet. + logger.warning("%s: %s tier wrote no rows", name, result.get("tier", "?")) @worker_task(name="dashboard_metrics.aggregate_from_sources") -def dashboard_metrics_aggregate() -> dict[str, Any]: - """Aggregate source tables into the hourly/daily/monthly metrics tables.""" - result = _call_internal(_AGGREGATE_PATH) +def dashboard_metrics_aggregate( + tier: str | None = None, + source_window_days: int | None = None, + **_ignored: Any, +) -> dict[str, Any]: + """Aggregate source tables into the hourly/daily/monthly metrics tables. + + Both kwargs come from the schedule row and both are optional: ``tier`` selects + which tiers to write, ``source_window_days`` widens the daily lookback for the + reconciliation pass. Omitting either applies the backend task's own default. + + Unknown kwargs are accepted rather than rejected. Note what this does and does + not buy: it does NOT save the deploy that introduces a kwarg, because a pod on + the previous image has the old signature. It saves a LATER release — a row may + gain a kwarg while pods still run this code. That matters here because the rows + ship in the backend image and this consumer ships in another, a TypeError is + dropped at MAX_ATTEMPTS=1, and the once-daily reconciliation row has no next + tick to recover on. + """ + if _ignored: + logger.warning("Ignoring unrecognised aggregation kwargs: %s", sorted(_ignored)) + body = { + key: value + for key, value in ( + ("tier", tier), + ("source_window_days", source_window_days), + ) + if value is not None + } or None + result = _call_internal(_AGGREGATE_PATH, body=body) _log_if_skipped("dashboard_metrics.aggregate_from_sources", result) return result @@ -116,11 +233,15 @@ def dashboard_metrics_aggregate() -> dict[str, Any]: def dashboard_metrics_cleanup_hourly(retention_days: int | None = None) -> dict[str, Any]: """Delete hourly metrics older than the retention window.""" body = {"retention_days": retention_days} if retention_days is not None else None - return _call_internal(_CLEANUP_HOURLY_PATH, body=body) + result = _call_internal(_CLEANUP_HOURLY_PATH, body=body) + _log_if_failed("dashboard_metrics.cleanup_hourly_data", result) + return result @worker_task(name="dashboard_metrics.cleanup_daily_data") def dashboard_metrics_cleanup_daily(retention_days: int | None = None) -> dict[str, Any]: """Delete daily metrics older than the retention window.""" body = {"retention_days": retention_days} if retention_days is not None else None - return _call_internal(_CLEANUP_DAILY_PATH, body=body) + result = _call_internal(_CLEANUP_DAILY_PATH, body=body) + _log_if_failed("dashboard_metrics.cleanup_daily_data", result) + return result diff --git a/workers/tests/test_dashboard_metrics_tasks.py b/workers/tests/test_dashboard_metrics_tasks.py index ce8ff853ac..54061b7963 100644 --- a/workers/tests/test_dashboard_metrics_tasks.py +++ b/workers/tests/test_dashboard_metrics_tasks.py @@ -8,6 +8,7 @@ from __future__ import annotations +import inspect import sys from pathlib import Path from unittest.mock import MagicMock, patch @@ -67,6 +68,34 @@ def test_aggregate_posts_to_the_aggregate_endpoint(self): dmt.dashboard_metrics_aggregate() assert call.call_args[0][0] == "v1/dashboard-metrics/aggregate/" + @pytest.mark.parametrize("tier", ["hourly", "daily_monthly", "all"]) + def test_aggregate_forwards_the_tier_from_the_schedule_row(self, tier): + """UN-3974: the PG scheduler hands a row's task_kwargs over as **kwargs, so the + tier arrives here and has to reach the backend in the request body. + + This is the leg that fails quietly. Drop the forwarding and every schedule still + fires, the endpoint still returns 200, and every other test here still passes — + but both rows run the default tier, so daily and monthly quietly go back to + being recomputed every 15 minutes. + """ + with patch.object(dmt, "_call_internal", return_value={"success": True}) as call: + dmt.dashboard_metrics_aggregate(tier=tier) + assert call.call_args.kwargs["body"] == {"tier": tier} + + def test_aggregate_passes_the_source_window_through(self): + # UN-3973: the reconciliation row carries this; dropping it here silently + # reverts the pass to the narrow window it exists to widen. + with patch.object(dmt, "_call_internal", return_value={"success": True}) as call: + dmt.dashboard_metrics_aggregate(source_window_days=7) + assert call.call_args.kwargs["body"] == {"source_window_days": 7} + + def test_aggregate_omits_the_body_when_neither_is_given(self): + # Rows written before 0006 carry no tier kwarg; the backend default then applies, + # which is every tier rather than none. + with patch.object(dmt, "_call_internal", return_value={"success": True}) as call: + dmt.dashboard_metrics_aggregate() + assert call.call_args.kwargs["body"] is None + @pytest.mark.parametrize( "func,path", [ @@ -98,6 +127,46 @@ def test_lock_held_result_is_surfaced_not_swallowed(self, caplog): assert result["skipped"] is True +class TestTheReconciliationKwargSurvives: + """0005 declares a row against this same task path carrying source_window_days. + + The PG scheduler copies task_kwargs verbatim into the payload, so a proxy that + does not accept it raises TypeError per tick — not covered by autoretry_for, and + dropped at MAX_ATTEMPTS=1. The gap-repair pass simply never runs. + """ + + _DECLARED = [{}, {"tier": "hourly"}, {"source_window_days": 7}] + + @pytest.mark.parametrize("kwargs", _DECLARED) + def test_every_scheduled_kwarg_set_binds(self, kwargs) -> None: + named = { + p.name + for p in inspect.signature(dmt.dashboard_metrics_aggregate).parameters.values() + if p.kind is not inspect.Parameter.VAR_KEYWORD + } + # Named parameters only — `**_ignored` makes bind() accept anything. + assert not set(kwargs) - named + + def test_the_source_window_reaches_the_endpoint(self) -> None: + with patch.object(dmt, "_call_internal", return_value={}) as call: + dmt.dashboard_metrics_aggregate(source_window_days=7) + assert call.call_args.kwargs["body"] == {"source_window_days": 7} + + def test_both_kwargs_travel_together(self) -> None: + with patch.object(dmt, "_call_internal", return_value={}) as call: + dmt.dashboard_metrics_aggregate(tier="hourly", source_window_days=7) + assert call.call_args.kwargs["body"] == { + "tier": "hourly", + "source_window_days": 7, + } + + def test_omitting_both_sends_no_body(self) -> None: + # The backend then applies its own defaults rather than ones invented here. + with patch.object(dmt, "_call_internal", return_value={}) as call: + dmt.dashboard_metrics_aggregate() + assert call.call_args.kwargs["body"] is None + + class TestInternalCall: def _response(self, status_code=200, payload=None): r = MagicMock() @@ -138,10 +207,255 @@ def test_non_200_raises(self): @pytest.mark.parametrize( "missing", ["INTERNAL_API_BASE_URL", "INTERNAL_SERVICE_API_KEY"] ) - def test_missing_config_raises_rather_than_returning_falsy(self, monkeypatch, missing): + def test_missing_config_raises_rather_than_returning_falsy( + self, monkeypatch, missing + ): # Deliberately different from process_log_history.py, which returns False: that # runs under a bash loop with no other channel. Here raising is what marks the # message failed and gets it logged. monkeypatch.delenv(missing) with pytest.raises(RuntimeError, match=missing): dmt._call_internal("v1/x/") + + +class TestTheRunSummaryReachesTheLog: + """The proxy's log line is the only view of a run on the PG transport. + + Every branch below existed with no test: deleting all of them left the whole + workers suite green, which is the same as having no operator signal at all. + """ + + def _run(self, caplog, result): + with caplog.at_level("WARNING"): + with patch.object(dmt, "_call_internal", return_value=result): + dmt.dashboard_metrics_aggregate() + return caplog.text + + @staticmethod + def _levels(caplog, needle): + """Levels of the records whose message contains `needle`. + + Asserting on caplog.text alone cannot see severity, so an ERROR silently + downgraded to WARNING stays green — and severity is the only thing that + reaches an alert for a fire-and-forget periodic. + """ + return {r.levelname for r in caplog.records if needle in r.getMessage()} + + def test_an_empty_prefilter_reports_the_rows_the_rollup_still_wrote(self, caplog): + text = self._run( + caplog, + { + "success": True, + "skipped_reason": "no_active_orgs", + "tier": "daily_monthly", + "monthly": {"upserted": 7}, + }, + ) + assert "no_active_orgs" in text + assert "rows written: 7" in text + + def test_an_error_is_reported_even_alongside_an_empty_prefilter(self, caplog): + """The two co-occur: the rollup is org-agnostic and runs when the loop did not. + + Reported as alternatives, the failure hides behind a benign "no active orgs". + """ + text = self._run( + caplog, + { + "success": False, + "skipped_reason": "no_active_orgs", + "errors": 1, + "organizations_processed": 0, + "tier": "daily_monthly", + "monthly": {"upserted": 0, "failed": True}, + }, + ) + assert "no_active_orgs" in text + assert "1 error(s)" in text + + def test_a_preserved_monthly_total_is_named_and_not_called_a_lowering(self, caplog): + """The backend KEPT these months; the worker used to say it lowered them. + + Naming the month was all this asserted, so an inverted verb passed. The two + processes then emitted opposite remediations for one event — and on the PG + transport this line is what on-call sees first. "Lowered" points at a + rollback; the fix is a backfill. + """ + text = self._run( + caplog, + { + "success": True, + "tier": "daily_monthly", + "monthly": { + "upserted": 3, + "needs_daily_repair": ["2026-08 (org 3)"], + }, + }, + ) + assert "2026-08 (org 3)" in text + assert "unchanged" in text and "backfill_metrics" in text + assert "lowered existing" not in text + + def test_breakage_is_logged_at_error_not_warning(self, caplog): + """Both arms that mean "something broke" must reach an alert.""" + self._run( + caplog, + { + "success": False, + "tier": "daily_monthly", + "errors": 2, + "organizations_processed": 7, + "monthly": {"upserted": 0, "failed": True}, + }, + ) + + assert self._levels(caplog, "error(s) across") == {"ERROR"} + assert self._levels(caplog, "the monthly rollup did not run") == {"ERROR"} + + def test_a_quiet_hourly_run_is_not_reported_as_writing_nothing(self, caplog): + """The backend exempts the */15 row from this arm; the copy here did not. + + An hourly run writes nothing whenever the shortlisted orgs had no activity + in the last 24h — a healthy weekend. Unguarded, on-call gets 96 warnings a + day for it, on the line whose own comment calls it "the signature of the + regression this change could introduce". + """ + text = self._run( + caplog, + {"success": True, "tier": "hourly", "hourly": {"upserted": 0}}, + ) + + assert "wrote no rows" not in text + + def test_a_daily_monthly_run_that_wrote_nothing_is_still_reported(self, caplog): + """The control: the arm must still fire for the tier it was written for.""" + text = self._run( + caplog, + {"success": True, "tier": "daily_monthly", "daily": {"upserted": 0}}, + ) + + assert "wrote no rows" in text + + def test_an_incomplete_daily_tier_is_named(self, caplog): + """Independent of the above: no stored total, so nothing was preserved.""" + text = self._run( + caplog, + { + "success": True, + "tier": "daily_monthly", + "monthly": { + "upserted": 3, + "incomplete_daily_coverage": ["2026-03 (8/9 days)"], + }, + }, + ) + assert "2026-03 (8/9 days)" in text + assert "under-counted" in text + + def test_a_clean_run_that_wrote_nothing_is_still_reported(self, caplog): + """The regression signature of narrowing the source window: work to do, no + error, nothing written. It passes every other branch silently. + """ + text = self._run( + caplog, + {"success": True, "tier": "daily_monthly", "organizations_processed": 4}, + ) + assert "wrote no rows" in text + + def test_a_normal_run_logs_no_warning(self, caplog): + """The control: the arms above must not fire on a healthy run.""" + text = self._run( + caplog, + { + "success": True, + "tier": "hourly", + "organizations_processed": 4, + "hourly": {"upserted": 12}, + }, + ) + assert text.strip() == "" + + +class TestAnUnknownKwargDoesNotKillTheRun: + """The schedule rows and this consumer ship in different images. + + A migration in the backend image can write a kwarg into a row while a + worker-unified pod is still on the previous image. The PG scheduler copies + task_kwargs verbatim into the payload and the consumer applies them, so a + signature that rejects the unknown key raises TypeError — not covered by + autoretry_for and dropped at MAX_ATTEMPTS=1. The */15 rows survive that on + their next tick; the once-daily reconciliation row does not. + """ + + def test_an_unrecognised_kwarg_is_accepted_and_not_forwarded(self): + with patch.object(dmt, "_call_internal", return_value={"success": True}) as call: + dmt.dashboard_metrics_aggregate(tier="hourly", some_future_kwarg=1) + + assert call.call_args.kwargs["body"] == {"tier": "hourly"} + + +class TestCleanupFailuresReachTheLog: + """`_log_if_failed` was added with no test, in the same file and commit as the + branches that did get one. The backend answers 200 with success: False, so this + is the only place a permanently failing retention delete becomes visible here. + """ + + def _run(self, caplog, task, result): + with caplog.at_level("WARNING"): + with patch.object(dmt, "_call_internal", return_value=result): + task() + return caplog.text + + def test_a_failed_cleanup_is_reported(self, caplog): + text = self._run( + caplog, + dmt.dashboard_metrics_cleanup_hourly, + {"success": False, "error": "deadlock detected"}, + ) + assert "did not complete" in text + assert "deadlock detected" in text + + def test_a_successful_cleanup_is_silent(self, caplog): + """The control: it reports failure, not every run.""" + text = self._run( + caplog, dmt.dashboard_metrics_cleanup_daily, {"success": True, "deleted": 4} + ) + assert text.strip() == "" + + +class TestTheDiagnosticBlindSpotIsReported: + """A check that could not run must not read as a check that found nothing.""" + + def test_an_unavailable_check_is_named(self, caplog): + with caplog.at_level("WARNING"): + with patch.object( + dmt, + "_call_internal", + return_value={ + "success": True, + "tier": "daily_monthly", + "monthly": {"upserted": 7, "lowered_check": "unavailable"}, + }, + ): + dmt.dashboard_metrics_aggregate() + # "would lower", not "lowered": the check never ran, so nothing was lowered + # — the same past-tense slip the payload rename removed from the other arm. + assert "could not check whether the rollup would lower" in caplog.text + assert "rollup lowered" not in caplog.text + + def test_a_failed_rollup_is_named_as_fleet_wide(self, caplog): + """Distinct from a per-org metric error, which reads the same otherwise.""" + with caplog.at_level("WARNING"): + with patch.object( + dmt, + "_call_internal", + return_value={ + "success": False, + "errors": 1, + "organizations_processed": 3, + "tier": "daily_monthly", + "monthly": {"upserted": 0, "failed": True}, + }, + ): + dmt.dashboard_metrics_aggregate() + assert "every tenant's monthly tier is stale" in caplog.text