Skip to content

[BUG] duration_min reports 0 when a stage produced no tasks #2151

Description

@amahussein

Describe the bug

TaskMetricsAccumRec.finalizeAggregation calls resetFields() when numTasks < 1, which sets durationMin to 0. Zero is not the identity for a minimum, so a record that observed no tasks does not drop out of a later minimum, it wins it.

Two code paths fold that sentinel into a published value:

  • TaskMetricsAccumRec.addRecord(rec: StageAggTaskMetricsProfileResult) does durationMin = math.min(durationMin, rec.durationMin) with no guard on rec.numTasks, so a zero-task stage drags the job-level and SQL-level minimum to 0.
  • StageAggTaskMetricsProfileResult.aggregateStageProfileMetric does durationMin = Math.min(this.durationMin, other.durationMin), so a stage attempt that ran no tasks drags the merged stage row to 0.

The maxima in the same expressions are unaffected, because 0 is the identity for a maximum over non-negative durations. durationMin is the only minimum in either fold, and the only *Min field on StageAggTaskMetricsProfileResult.

Steps/Code to reproduce bug

This reproduces today on a stored fixture, with no stage retry needed. Profile core/src/test/resources/spark-events-profiling/gpu_oom_eventlog.zstd. Stages 32, 33 and 37 have a SparkListenerStageCompleted and no task-end event, so each emits a row with num_tasks 0 and duration_min 0. All three belong to SQL 24, whose remaining stages report minima of 3085, 4374 and 4760 ms:

stage_level_aggregated_task_metrics.csv
  stage 31  num_tasks=31   duration_min=3085
  stage 32  num_tasks=0    duration_min=0
  stage 33  num_tasks=0    duration_min=0
  stage 34  num_tasks=122  duration_min=4374
  stage 35  num_tasks=200  duration_min=4760
  stage 37  num_tasks=0    duration_min=0

sql_level_aggregated_task_metrics.csv
  sqlID 24  duration_min=0

So SQL 24 publishes a minimum task duration of 0 ms for a query whose fastest task took just over 3 seconds.

Job level does not show it on this log only because jobs 34, 35 and 36 contain nothing but an empty stage and are suppressed by isEmptyAggregates. A job mixing an empty stage with a real one would publish 0.

Expected behavior

duration_min should be the smallest duration a task actually reported. A record that observed no tasks carries no minimum and should not participate in one. Guarding both fold sites on the task count would do it, for example:

// TaskMetricsAccumRec.addRecord(rec: StageAggTaskMetricsProfileResult)
if (rec.numTasks > 0) {
  durationMin = math.min(durationMin, rec.durationMin)
}

and the same shape in aggregateStageProfileMetric. Whether a zero-task stage row should publish duration_min of 0 or an empty cell is a separate call; the defect is that it propagates.

Additional context

Every Math.min in core/src/main was checked. Beyond the two folds above, one more site has the same shape and is worth investigating with this fix: AccumInfo.calculateAccStats reduces stagesStatMap.values with Math.min(a.min, b.min), and addAccumToStage seeds an absent entry from StatisticsMetrics.ZERO_RECORD, whose min is 0. That feeds the min column of sql_plan_metrics_for_application.csv. It is unmeasured: no available fixture produces that shape, and the file carries no sample count, so a sentinel zero cannot be told from a task that genuinely measured zero.

Nothing else is affected. The remaining minima are clamps and bounds, timeline start times, a minimum over stage IDs for plan-node disambiguation, and per-task folds over real task records. durationMin is the only *Min field on StageAggTaskMetricsProfileResult, and the other four fields resetFields zeroes are maxima, which are safe because 0 is the identity for a maximum over non-negative values.

No event log under core/src/test/resources has a stage attempt above 0, so the stage-attempt half of this has no coverage. The job and SQL half needs no retry and is reproducible on the fixture above.

Found while reviewing #2147. That change makes durationAvg immune to a zero-task record, since it now divides a pooled sum by a pooled task count, which leaves durationMin the only field in that merge still corrupted.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

bugSomething isn't workingcore_toolsScope the core module (scala)

Type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions