minor: Add logs and metrics observability to the segment upgrade path that fires while using concurrent locking#19651
Conversation
…ncurrent append and replace ingestion mets checkpoint doc and test tidy up self review
FrankChen021
left a comment
There was a problem hiding this comment.
I have reviewed the code for correctness, edge cases, concurrency/lifecycle, security, data loss, API compatibility, and missing-test risks; no high-confidence issues found.
Reviewed 11 of 11 changed files.
This is an automated review by Codex GPT-5.5
kfaraz
left a comment
There was a problem hiding this comment.
Thanks for adding the metrics/logs, @capistrant ! These would be instrumental in debugging failures in concurrent compaction.
Overall looks good, but I have left some nitpicks.
| public class SegmentUpgradeMetrics | ||
| { | ||
| /** Number of upgraded pending segments a REPLACE commit created and handed to the supervisor. Task-action dims. */ | ||
| public static final String COUNT = "ingest/segmentUpgrade/count"; |
There was a problem hiding this comment.
Please include the prefix realtime in all the metrics to distinguish upgrade of pending segments from upgrade of appended segments.
| public static final String COUNT = "ingest/segmentUpgrade/count"; | |
| public static final String REALTIME_PERSISTED = "ingest/realtime/segmentUpgrade/persisted"; |
| // Values for the DruidMetrics.REASON dimension on SKIPPED. | ||
|
|
||
| /** The task holds no pending segment matching upgradedFromSegmentId (request targeted the wrong task). */ | ||
| public static final String REASON_UNKNOWN_BASE = "unknownBase"; |
There was a problem hiding this comment.
Nit: The reasons need not be camel cased, e.g. unknown base sink instead of unknownBase.
| public static final String COUNT = "ingest/segmentUpgrade/count"; | ||
|
|
||
| /** A record was delivered to at least one running task. Supervisor dims. */ | ||
| public static final String NOTIFIED = "ingest/segmentUpgrade/notified"; |
There was a problem hiding this comment.
| public static final String NOTIFIED = "ingest/segmentUpgrade/notified"; | |
| public static final String REALTIME_TASK_NOTIFIED = "ingest/realtime/segmentUpgrade/notified"; |
| return; | ||
| } | ||
|
|
||
| log.info("Registering [%d] upgraded pending segments created by task[%s] on supervisor[%s]", |
There was a problem hiding this comment.
Maybe move this log to the end of this method and include a summary map from pending segment ID to number of tasks notified.
|
|
||
| supervisor.addTaskGroupToActivelyReadingTaskGroup( | ||
| supervisor.getTaskGroupIdForPartition("0"), | ||
| ImmutableMap.of("0", "5"), |
There was a problem hiding this comment.
Nit: Use Map.of and Set.of for brevity.
There was a problem hiding this comment.
ack on Set. the method signature seems to require explicit ImmutableMap tho
There was a problem hiding this comment.
Oh, I see. Thanks for the clarification!
| if (basePendingSegment == null || droppingSinks.contains(basePendingSegment) || !sinks.containsKey(basePendingSegment)) { | ||
| if (basePendingSegment == null) { | ||
| // This task never allocated a segment matching upgradedFromSegmentId, i.e. the request targeted the wrong task. | ||
| log.info( |
| log.info( | ||
| "Not announcing upgraded pending segment[%s] because this task has no base sink matching" | ||
| + " upgradedFromSegmentId[%s]; the upgrade request likely targeted the wrong task[%s].", | ||
| upgradedPendingSegment, pendingSegmentRecord.getUpgradedFromSegmentId(), myId | ||
| ); | ||
| return UpgradeAnnouncementOutcome.SKIPPED_UNKNOWN_BASE; | ||
| } else if (droppingSinks.contains(basePendingSegment)) { | ||
| // Expected during handoff: the base sink is being dropped | ||
| log.debug( | ||
| "Not announcing upgraded pending segment[%s] for base segment[%s] on task[%s] because the base sink is being dropped.", | ||
| upgradedPendingSegment, basePendingSegment, myId | ||
| ); | ||
| return UpgradeAnnouncementOutcome.SKIPPED_DROPPING; | ||
| } else { | ||
| // Unexpected: the base sink is gone even though this task once held it. | ||
| log.info( | ||
| "Not announcing upgraded pending segment[%s] for base segment[%s] on task[%s] because the base sink is no longer present.", | ||
| upgradedPendingSegment, basePendingSegment, myId |
There was a problem hiding this comment.
I feel like these logs can be merged into one and can be logged by the caller itself using the result of this method.
applying the pure text changes. will commit responses to review in another commit Co-authored-by: Kashif Faraz <kashif.faraz@gmail.com>
| |`ingest/notices/time`|Milliseconds taken to process a notice by the supervisor.|`supervisorId`, `dataSource`, `tags`| < 1s | | ||
| |`ingest/pause/time`|Milliseconds spent by a task in a paused state without ingesting.|`dataSource`, `taskId`, `tags`| < 10 seconds| | ||
| |`ingest/handoff/time`|Total number of milliseconds taken to handoff a set of segments.|`dataSource`, `taskId`, `taskType`, `groupId`, `tags`|Depends on the coordinator cycle time.| | ||
| |`ingest/realtime/segmentUpgrade/count`|Number of pending segments that a concurrent replace (for example, compaction) upgraded to a new version and asked the supervisor to have running tasks announce under the new version. Emitted by the replace task only when streaming ingestion is running concurrently with replace on the same interval.|`dataSource`, `taskId`, `taskType`, `groupId`, `interval`, `version`, `tags`|0 unless [concurrent append and replace](../ingestion/concurrent-append-replace.md) is in use.| |
There was a problem hiding this comment.
We should probably rename this metric from count to persisted to signify that this is the count that was actually persisted to the metadata store.
Also, rephrased the text a bit.
| |`ingest/realtime/segmentUpgrade/count`|Number of pending segments that a concurrent replace (for example, compaction) upgraded to a new version and asked the supervisor to have running tasks announce under the new version. Emitted by the replace task only when streaming ingestion is running concurrently with replace on the same interval.|`dataSource`, `taskId`, `taskType`, `groupId`, `interval`, `version`, `tags`|0 unless [concurrent append and replace](../ingestion/concurrent-append-replace.md) is in use.| | |
| |`ingest/realtime/segmentUpgrade/persisted`|Number of pending segments that were upgraded in the metadata store while publishing segments to an interval. Emitted by the Overlord only when a REPLACE task (e.g., compaction task with `useConcurrentLocks` set to `true`) commits segments to an interval already containing pending segments allocated to an APPEND task (e.g. streaming task with `useConcurrentLocks` set to `true`). |`dataSource`, `taskId`, `taskType`, `groupId`, `interval`, `version`, `tags`|0 unless [concurrent append and replace](../ingestion/concurrent-append-replace.md) is in use.| |
| * segment-upgrade metric can be sliced by the specific segment being re-announced. Mirrors | ||
| * {@code IndexTaskUtils.setSegmentDimensions}, which serves the same purpose for {@code DataSegment}s. | ||
| */ | ||
| public static ServiceMetricEvent.Builder setSegmentDimensions( |
There was a problem hiding this comment.
Nit: Maybe move this method to IndexTaskUtils itself, as it feels like a more generic place (rather than upgrade specific) allowing for reuse for this method.
| log.info("No active streaming supervisor for datasource[%s]; the [%d] upgraded pending segment(s) from task[%s]" | ||
| + " will become queryable when their tasks hand off.", | ||
| task.getDataSource(), | ||
| upgradedPendingSegments.size(), | ||
| task.getId() | ||
| ); |
There was a problem hiding this comment.
minor rephrase
| log.info("No active streaming supervisor for datasource[%s]; the [%d] upgraded pending segment(s) from task[%s]" | |
| + " will become queryable when their tasks hand off.", | |
| task.getDataSource(), | |
| upgradedPendingSegments.size(), | |
| task.getId() | |
| ); | |
| log.info( | |
| "Could not find any active concurrent streaming supervisor for datasource[%s]." | |
| + " Ignoring registry of [%d] pending segment(s) upgraded by task[%s]. These will become queryable only after handoff." | |
| task.getDataSource(), | |
| upgradedPendingSegments.size(), | |
| task.getId() | |
| ); |
| /** | ||
| * Notifies every running task in the matching task group(s) of an upgraded pending segment. | ||
| * | ||
| * @return the number of tasks notified, which the caller aggregates into a per-batch summary |
There was a problem hiding this comment.
| * @return the number of tasks notified, which the caller aggregates into a per-batch summary | |
| * @return the number of tasks notified |
| } | ||
|
|
||
| // Only the exceptional no-match case is logged per segment; the notified count is returned to the task action, | ||
| // which summarizes the whole batch in one log line, and each notification is captured by the per-task metric. |
There was a problem hiding this comment.
We need not call this out. This method should be agnostic of the behaviour of its caller.
We choose not to log the successful case here to reduce verbosity, irrespective of the behaviour of the caller.
| "Could not find any task matching taskAllocatorId[%s] in supervisor[%s] for upgraded pending segment[%s]" | ||
| + " (upgradedFrom[%s]); it will not be re-announced until handoff. Currently tracking [%d] activelyReading" | ||
| + " and [%d] pendingCompletion task group(s).", |
There was a problem hiding this comment.
Do you think logging the number of actively reading / pending completion groups would be useful for debugging? I feel we may omit these for now.
There was a problem hiding this comment.
hmm I guess probably not useful. was kinda just packing in bits of information wherever I could find them in this PR. but you're right I'm not sure what I do with this number in this log so I will remove
| { | ||
| ANNOUNCED(null), | ||
| /** The task holds no pending segment matching upgradedFromSegmentId (request targeted the wrong task). */ | ||
| SKIPPED_UNKNOWN_BASE("unknown base"), |
There was a problem hiding this comment.
| SKIPPED_UNKNOWN_BASE("unknown base"), | |
| SKIPPED_UNKNOWN_BASE("unknown base sink"), |
| * Logs and emits a metric for the outcome of a pending-segment upgrade request, keyed off the {@code outcome} | ||
| * returned by {@link StreamAppenderator#registerUpgradedPendingSegment}. | ||
| */ | ||
| private void recordUpgradeOutcome( |
There was a problem hiding this comment.
| private void recordUpgradeOutcome( | |
| private void recordUpgradeResult( |
| */ | ||
| private void recordUpgradeOutcome( | ||
| PendingSegmentRecord upgradedPendingSegment, | ||
| StreamAppenderator.PendingSegmentUpgradeResult outcome |
There was a problem hiding this comment.
| StreamAppenderator.PendingSegmentUpgradeResult outcome | |
| StreamAppenderator.PendingSegmentUpgradeResult result |
FrankChen021
left a comment
There was a problem hiding this comment.
| Severity | Findings |
|---|---|
| P0 | 0 |
| P1 | 1 |
| P2 | 1 |
| P3 | 0 |
| Total | 2 |
| Severity | Findings |
|---|---|
| P0 | 0 |
| P1 | 1 |
| P2 | 1 |
| P3 | 0 |
| Total | 2 |
Reviewed 16 of 16 changed files.
This is an automated review by Codex GPT-5.6-Sol
| "ingest/notices/time" : { "dimensions" : ["dataSource"], "type" : "timer", "conversionFactor": 1000.0, "help": "Seconds taken to process a notice by the supervisor." }, | ||
| "ingest/pause/time" : { "dimensions" : ["dataSource"], "type" : "timer", "conversionFactor": 1000.0, "help": "Seconds spent by a task in a paused state without ingesting." }, | ||
| "ingest/handoff/time" : { "dimensions" : ["dataSource"], "type" : "timer", "conversionFactor": 1000.0, "help": "Total number of seconds taken to handoff a set of segments." }, | ||
| "ingest/realtime/segmentUpgrade/count" : { "dimensions" : ["dataSource", "interval", "version"], "type" : "count", "help": "Number of pending segments upgraded by a concurrent replace." }, |
There was a problem hiding this comment.
[P1] Avoid unbounded per-version Prometheus series
The default exporter has no TTL unless flushPeriod is explicitly configured, and its collector retains every label tuple. version, interval, and taskId continually change across replacements and tasks, so recurring concurrent compaction makes these six default metrics accumulate series indefinitely on long-lived Overlord/supervisor processes, potentially exhausting heap. Keep high-cardinality identifiers out of the default mapping or enforce bounded expiry.
| notifiedTasksBySegment.size(), | ||
| task.getId(), | ||
| activeSupervisorIdWithAppendLock.get(), | ||
| notifiedTasksBySegment |
There was a problem hiding this comment.
[P2] Bound the per-segment INFO summary
The upgraded-segment list is not capped, yet this builds and formats every segment ID into one INFO message. Broad compaction can produce thousands of entries and megabyte-scale log lines on the task-action path. Log aggregate counts with a bounded sample, reserving full detail for debug output.
Description
Investigating potential issues with concurrent append and replace actions not being properly accepted and reflected on realtime ingestion tasks who should be upgrading their segments to reflect the concurrent append that happened on an interval they are ingesting to. This PR attempts to add some logs and metrics to the related code to help give observability into the process and smoke out if there are indeed issues going on. Biggest risk of these new mets and logs is probably chattiness, since they scale with the volume of upgrade segments that may be existing under a clusters normal operaions.
New Metrics
ingest/segmentUpgrade/countdataSource,taskId,taskType,groupId,tagsingest/segmentUpgrade/notifiedingest/segmentUpgrade/count:countshould equalnotified+unmatchedover the same period anddataSource.supervisorId,dataSource,stream,tagscountin a healthy cluster.ingest/segmentUpgrade/unmatchedsupervisorId,dataSource,stream,tagsingest/segmentUpgrade/sendFailedsupervisorId,dataSource,stream,taskId,tagsingest/segmentUpgrade/announcedingest/segmentUpgrade/count, which is per-segment rather than per-replica.dataSource,taskId,taskType,groupId,tagsingest/segmentUpgrade/skippedreasondimension is one ofunknownBase(the request reached the wrong task),noSink(the base sink is no longer present), ordropping(the base sink is handing off, which is benign and covered by the durable publish path).dataSource,taskId,taskType,groupId,tags,reasonreason=dropping.Release note
TBD
Key changed/added classes in this PR
TBD
This PR has: