Skip to content

refactor(inkless:delete): improve retention-enforcement observability - #725

Merged
giuseppelillo merged 3 commits into
mainfrom
jeqo/enforce-per-partition-metrics
Jul 29, 2026
Merged

refactor(inkless:delete): improve retention-enforcement observability#725
giuseppelillo merged 3 commits into
mainfrom
jeqo/enforce-per-partition-metrics

Conversation

@jeqo

@jeqo jeqo commented Jul 28, 2026

Copy link
Copy Markdown
Contributor

Improves observability of diskless retention enforcement and file cleanup. No change to enforcement or cleanup behavior. Three focused commits, all in the io.aiven.inkless.delete / control-plane area.

What changed

  • Schedule-lag gauge — new RetentionEnforcementScheduleLagMs gauge: milliseconds the most overdue diskless partition is past its scheduled enforcement time (0 when on schedule; a sustained positive value means enforcement is falling behind its per-partition cadence). Fed by the scheduler's oldest past-due queue entry, read under a lock so the metrics/JMX thread and the enforcement thread don't race the PriorityQueue.
  • Per-partition enforce latencyEnforceRetentionJob runs one transaction per partition (post-fix(inkless:retention): decouple enforce_retention_v2 from the log lock #705), so EnforceRetentionQueryTime/QueryRate are now recorded per partition instead of once per wave. No new metric.
  • Intent/result run logs — enforcer and file cleaner now log a "starting" intent line before the potentially-blocking work and a "done" line after, so a stuck operation shows as intent-without-completion.

Metrics

New:

  • RetentionEnforcer.RetentionEnforcementScheduleLagMs — gauge (ms).

Redefined (operator impact — re-baseline any dashboards/alerts on these): PostgresControlPlane.EnforceRetentionQueryTime and EnforceRetentionQueryRate now measure a single enforce_retention_v2 call (one partition) rather than the whole wave. QueryRate rises by roughly partitions-per-wave with no config change; QueryTime percentiles become per-partition latencies. Nothing is lost — the whole-wave duration remains RetentionEnforcer.RetentionEnforcementTotalTime and the wave count remains RetentionEnforcementRate. Per-transaction latency is the more accurate thing to measure since each partition is its own transaction.

Logs

  • Enforcer: per-cycle summary promoted DEBUG -> INFO and paired with an intent line — Enforcing retention for {n} partitions / Enforced retention for {n} partitions in {ms} ms: {b} batches, {y} bytes deleted. One pair per non-empty cycle; empty cycles stay silent (no per-tick heartbeat, since the enforcer ticks every 500ms).
  • File cleaner: replaced the per-run Running file cleaner at {now} heartbeat (redundant with the log framework timestamp and the outcome line) with a work-gated pair — Running file cleaner: deleting {n} of {m} marked files / File cleaner deleted {n} files in {ms} ms (the m - n files are still within the retention grace period).
  • Also fixes a latent partition misattribution in the enforcer's per-partition log lines (they indexed readyPartitions while responses align with the delete-policy-filtered requests); now uses a list kept aligned 1:1 with requests/responses. Latent today (diskless doesn't support compaction, so the lists don't diverge) but made correct.

Operator notes

  • Re-baseline dashboards/alerts on EnforceRetentionQueryTime/EnforceRetentionQueryRate (semantics changed as above).
  • The enforcer now emits an INFO intent+result pair per non-empty cycle; if that volume is a concern on high-delete clusters, the pair can be gated on deletions later.
  • RetentionEnforcementScheduleLagMs returns 0 for both "on schedule" and "empty queue" (no diskless delete-policy partitions yet, or during startup); pair it with queue activity if that distinction matters.
  • Partition/size counts are intentionally absent from the file-cleaner logs: FileToDelete carries only the object key, and batches are already deleted by cleanup time.

Testing

  • scheduleLagTracksOverduePartition (empty -> 0, future head -> 0, advance past due -> exact lag).
  • durationCallbackFiresOncePerPartition (3 callbacks for 3 requests, including a non-existent partition).
  • File-cleaner mocked + integration tests.
  • metrics.rst regenerated; checkstyle (main + test) clean.

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Improves observability around diskless retention enforcement scheduling/execution and file-cleanup runs by adding a new scheduler lag gauge, redefining retention query timing to be per-partition, and adjusting logs to emit intent/result pairs around potentially blocking work.

Changes:

  • Added RetentionEnforcementScheduleLagMs gauge fed by the scheduler head entry, with locking to avoid PriorityQueue races.
  • Changed retention-enforcement query timing so the duration callback fires once per partition (one transaction per partition).
  • Updated retention/file-cleaner logs to emit clearer intent/result pairs; fixed partition attribution in per-partition retention logs.

Reviewed changes

Copilot reviewed 8 out of 8 changed files in this pull request and generated 4 comments.

Show a summary per file
File Description
storage/inkless/src/test/java/io/aiven/inkless/delete/RetentionEnforcementSchedulerTest.java Adds coverage for the new schedule-lag gauge behavior.
storage/inkless/src/test/java/io/aiven/inkless/control_plane/postgres/EnforceRetentionJobTest.java Adds coverage ensuring the duration callback fires once per partition.
storage/inkless/src/main/java/io/aiven/inkless/delete/RetentionEnforcerMetrics.java Introduces the new schedule-lag metric and wires it into the metrics group.
storage/inkless/src/main/java/io/aiven/inkless/delete/RetentionEnforcer.java Wires the schedule-lag supplier into metrics; improves intent/result logging and per-partition attribution.
storage/inkless/src/main/java/io/aiven/inkless/delete/RetentionEnforcementScheduler.java Adds queue locking and exposes schedule lag calculation for the new gauge.
storage/inkless/src/main/java/io/aiven/inkless/delete/FileCleaner.java Updates file-cleaner logs to be work-gated and to include runtime duration.
storage/inkless/src/main/java/io/aiven/inkless/control_plane/postgres/EnforceRetentionJob.java Moves duration measurement to per-partition calls (one callback per request).
docs/inkless/metrics.rst Documents the new RetentionEnforcer schedule-lag gauge.

Comment thread docs/inkless/metrics.rst Outdated
@jeqo
jeqo force-pushed the jeqo/enforce-per-partition-metrics branch from 7a4c29d to 9e27f3c Compare July 28, 2026 15:01
@jeqo
jeqo requested a review from Copilot July 28, 2026 15:20

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 8 out of 8 changed files in this pull request and generated no new comments.

Comments suppressed due to low confidence (2)

storage/inkless/src/main/java/io/aiven/inkless/delete/RetentionEnforcerMetrics.java:77

  • scheduleLagMsSupplier is used directly when registering the gauge. If this is ever passed as null (e.g., in tests or future call sites), this will fail at runtime with an NPE during metric registration or polling. Consider enforcing non-null at construction and using the validated reference for the gauge.
    public RetentionEnforcerMetrics(final Supplier<Long> scheduleLagMsSupplier) {
        retentionEnforcementTotalTime = metricsGroup.newHistogram(RETENTION_ENFORCEMENT_TOTAL_TIME, true, Map.of());
        metricsGroup.newGauge(RETENTION_ENFORCEMENT_RATE, retentionEnforcementRate::intValue);
        metricsGroup.newGauge(RETENTION_ENFORCEMENT_TOTAL_BATCHES_DELETED, retentionEnforcementTotalBatchesDeleted::intValue);
        metricsGroup.newGauge(RETENTION_ENFORCEMENT_TOTAL_BYTES_DELETED, retentionEnforcementTotalBytesDeleted::intValue);
        metricsGroup.newGauge(RETENTION_ENFORCEMENT_ERROR_RATE, retentionEnforcementErrorRate::intValue);
        metricsGroup.newGauge(RETENTION_ENFORCEMENT_SCHEDULE_LAG_MS, scheduleLagMsSupplier);
    }

storage/inkless/src/main/java/io/aiven/inkless/delete/RetentionEnforcementScheduler.java:189

  • dumpQueue() sorts only by nextEnforcementTime. When multiple partitions share the same scheduled time, the resulting order can still vary because PriorityQueue iteration order is unspecified and the comparator treats ties as equal. Adding deterministic tie-breakers keeps this method stable and better matches the intent of making assertions independent of heap layout.
    List<TopicIdPartitionWithNextEnforcementTime> dumpQueue() {
        synchronized (queueLock) {
            return partitionsByNextEnforcementTime.stream()
                .sorted(TopicIdPartitionWithNextEnforcementTime.timeComparator())
                .toList();

jeqo added 3 commits July 28, 2026 18:51
Add a RetentionEnforcementScheduleLagMs gauge (0 when on schedule; a sustained
positive value means enforcement is falling behind its per-partition cadence),
fed by the scheduler's oldest past-due queue entry read under a lock so the
metrics/JMX thread and the enforcement thread do not race the PriorityQueue.
EnforceRetentionJob runs one transaction per partition (post-#705), yet
EnforceRetentionQueryTime wrapped the whole batch -- duplicating the broker-side
RetentionEnforcementTotalTime, which already measures the whole enforce wave.

Record EnforceRetentionQueryTime/QueryRate per enforce_retention_v2 call (one per
partition) instead, matching the other *QueryTime metrics (one DB operation each)
and yielding per-partition enforce latency without a new metric. The whole-wave
total stays RetentionEnforcementTotalTime on the broker.

Note: this redefines two existing metrics -- EnforceRetentionQueryTime from
per-wave to per-partition, and EnforceRetentionQueryRate from wave count to
partitions-enforced count (wave count remains RetentionEnforcementRate).
…t/result pairs

Retention enforcer: promote the per-cycle summary from DEBUG to INFO and add a
matching intent line before the (potentially blocking) enforce call, so a stuck
enforce shows as intent-without-completion:
  "Enforcing retention for {n} partitions"
  "Enforced retention for {n} partitions in {ms} ms: {b} batches, {y} bytes deleted"
One pair per non-empty cycle; empty cycles stay silent (no per-tick heartbeat).
Also fix a latent partition misattribution: the per-partition log lines indexed
readyPartitions while responses align with the delete-policy-filtered requests, so a
filtered-out partition could be mislabeled -- keep an enforcedPartitions list aligned
1:1 with requests/responses instead.

File cleaner: replace the per-run "Running file cleaner at {now}" heartbeat
(redundant with the framework timestamp and the outcome line) with a work-gated
intent/result pair:
  "Running file cleaner: deleting {n} of {m} marked files"  (m-n still within grace)
  "File cleaner deleted {n} files in {ms} ms"
Partition/size counts are not available at this layer (FileToDelete carries only the
object key; batches are already deleted by cleanup time).
@jeqo
jeqo force-pushed the jeqo/enforce-per-partition-metrics branch from 9e27f3c to 1bc3e35 Compare July 28, 2026 15:51
@jeqo
jeqo marked this pull request as ready for review July 28, 2026 16:20
@giuseppelillo
giuseppelillo merged commit 429af33 into main Jul 29, 2026
7 checks passed
@giuseppelillo
giuseppelillo deleted the jeqo/enforce-per-partition-metrics branch July 29, 2026 12:57
giuseppelillo pushed a commit that referenced this pull request Jul 29, 2026
…#725)

* feat(inkless:retention): surface enforcement schedule lag

Add a RetentionEnforcementScheduleLagMs gauge (0 when on schedule; a sustained
positive value means enforcement is falling behind its per-partition cadence),
fed by the scheduler's oldest past-due queue entry read under a lock so the
metrics/JMX thread and the enforcement thread do not race the PriorityQueue.

* feat(inkless:retention): meter enforce latency per partition

EnforceRetentionJob runs one transaction per partition (post-#705), yet
EnforceRetentionQueryTime wrapped the whole batch -- duplicating the broker-side
RetentionEnforcementTotalTime, which already measures the whole enforce wave.

Record EnforceRetentionQueryTime/QueryRate per enforce_retention_v2 call (one per
partition) instead, matching the other *QueryTime metrics (one DB operation each)
and yielding per-partition enforce latency without a new metric. The whole-wave
total stays RetentionEnforcementTotalTime on the broker.

Note: this redefines two existing metrics -- EnforceRetentionQueryTime from
per-wave to per-partition, and EnforceRetentionQueryRate from wave count to
partitions-enforced count (wave count remains RetentionEnforcementRate).

* feat(inkless:retention): make enforcement and file-cleaner logs intent/result pairs

Retention enforcer: promote the per-cycle summary from DEBUG to INFO and add a
matching intent line before the (potentially blocking) enforce call, so a stuck
enforce shows as intent-without-completion:
  "Enforcing retention for {n} partitions"
  "Enforced retention for {n} partitions in {ms} ms: {b} batches, {y} bytes deleted"
One pair per non-empty cycle; empty cycles stay silent (no per-tick heartbeat).
Also fix a latent partition misattribution: the per-partition log lines indexed
readyPartitions while responses align with the delete-policy-filtered requests, so a
filtered-out partition could be mislabeled -- keep an enforcedPartitions list aligned
1:1 with requests/responses instead.

File cleaner: replace the per-run "Running file cleaner at {now}" heartbeat
(redundant with the framework timestamp and the outcome line) with a work-gated
intent/result pair:
  "Running file cleaner: deleting {n} of {m} marked files"  (m-n still within grace)
  "File cleaner deleted {n} files in {ms} ms"
Partition/size counts are not available at this layer (FileToDelete carries only the
object key; batches are already deleted by cleanup time).
giuseppelillo pushed a commit that referenced this pull request Jul 30, 2026
…#725)

* feat(inkless:retention): surface enforcement schedule lag

Add a RetentionEnforcementScheduleLagMs gauge (0 when on schedule; a sustained
positive value means enforcement is falling behind its per-partition cadence),
fed by the scheduler's oldest past-due queue entry read under a lock so the
metrics/JMX thread and the enforcement thread do not race the PriorityQueue.

* feat(inkless:retention): meter enforce latency per partition

EnforceRetentionJob runs one transaction per partition (post-#705), yet
EnforceRetentionQueryTime wrapped the whole batch -- duplicating the broker-side
RetentionEnforcementTotalTime, which already measures the whole enforce wave.

Record EnforceRetentionQueryTime/QueryRate per enforce_retention_v2 call (one per
partition) instead, matching the other *QueryTime metrics (one DB operation each)
and yielding per-partition enforce latency without a new metric. The whole-wave
total stays RetentionEnforcementTotalTime on the broker.

Note: this redefines two existing metrics -- EnforceRetentionQueryTime from
per-wave to per-partition, and EnforceRetentionQueryRate from wave count to
partitions-enforced count (wave count remains RetentionEnforcementRate).

* feat(inkless:retention): make enforcement and file-cleaner logs intent/result pairs

Retention enforcer: promote the per-cycle summary from DEBUG to INFO and add a
matching intent line before the (potentially blocking) enforce call, so a stuck
enforce shows as intent-without-completion:
  "Enforcing retention for {n} partitions"
  "Enforced retention for {n} partitions in {ms} ms: {b} batches, {y} bytes deleted"
One pair per non-empty cycle; empty cycles stay silent (no per-tick heartbeat).
Also fix a latent partition misattribution: the per-partition log lines indexed
readyPartitions while responses align with the delete-policy-filtered requests, so a
filtered-out partition could be mislabeled -- keep an enforcedPartitions list aligned
1:1 with requests/responses instead.

File cleaner: replace the per-run "Running file cleaner at {now}" heartbeat
(redundant with the framework timestamp and the outcome line) with a work-gated
intent/result pair:
  "Running file cleaner: deleting {n} of {m} marked files"  (m-n still within grace)
  "File cleaner deleted {n} files in {ms} ms"
Partition/size counts are not available at this layer (FileToDelete carries only the
object key; batches are already deleted by cleanup time).
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants