Skip to content

fix: read the logs once more before a goodput measurement completes - #63

Merged
lalitadithya merged 3 commits into
NVIDIA:mainfrom
dims:worktree-goodput-final
Aug 8, 2026
Merged

fix: read the logs once more before a goodput measurement completes#63
lalitadithya merged 3 commits into
NVIDIA:mainfrom
dims:worktree-goodput-final

Conversation

@dims

@dims dims commented Aug 8, 2026

Copy link
Copy Markdown
Collaborator

What was wrong

handleSucceeded and handleFailed both build from the stored status via buildCumulativeFromStatus and never read logs again. Anything the workload wrote in the last sampling window was dropped — sampleInterval, 60 seconds by default.

Seen on hardware (test-plan P3.1): a script that logged up to iteration 100 was recorded as reaching currentStep: 90. The workaround at the time was to make the workload sleep before exiting, which is not something a user should have to know about.

It matters most on failure, where the last lines before a crash are the interesting ones.

The shape already exists

The bandwidth controller does exactly this. On JobSucceeded and JobFailed it calls handleRunning for one more parse before going terminal:

if cond := ...JobSucceeded...; cond.Status == metav1.ConditionTrue {
    if len(measurement.Status.Results) == 0 {
        if _, err := r.handleRunning(ctx, measurement, job); err != nil { ... }
    }
    return r.handleTerminal(...)
}

bandwidthmeasurement_controller.go:152-167. finalSample gives goodput the same shape.

The detail that makes it work

handleRunning throttles reads so a status update does not re-trigger one:

if last, ok := r.lastSample[key]; ok && time.Since(last) < interval {
    return ctrl.Result{RequeueAfter: interval - time.Since(last)}, nil
}

The final read lands moments after the previous sample, so it would normally be skipped — the throttle would silently defeat the fix. finalSample clears the recorded sample time first.

Two tests cover both halves, so the mechanism is pinned rather than assumed:

  • TestHandleRunningIsThrottledWithoutFinalSample — a plain call is throttled and asks for a requeue
  • TestFinalSampleBypassesTheThrottlefinalSample clears the sample time

Scope

Best effort, matching the bandwidth version: a failure in the final read logs and leaves the previous status in place, which is what would have happened anyway.

Verification

make lint 0 issues, make build clean, make test all packages pass. No golden file changes — the existing goodput cases read the same fixture logs, so one extra read produces the same result.

@dims

dims commented Aug 8, 2026

Copy link
Copy Markdown
Collaborator Author

/ok to test

handleSucceeded and handleFailed both build from the stored status and
never read logs again, so anything the workload wrote in the last sampling
window was dropped. That window is sampleInterval, 60 seconds by default.

Seen on hardware: a script that logged up to iteration 100 was recorded as
reaching step 90. The workaround at the time was to make the workload
sleep before exiting, which is not something a user should have to know.

It matters most on failure, where the last lines before a crash are the
interesting ones.

The bandwidth controller already does this. On JobSucceeded and JobFailed
it calls handleRunning for one more parse before going terminal
(bandwidthmeasurement_controller.go:152-167). finalSample gives goodput
the same shape.

One difference worth noting: the throttle in handleRunning exists so that
a status update does not re-trigger a read, and the final read lands
moments after the previous sample, so it would normally be skipped.
finalSample clears the recorded sample time first. Tests cover both
halves: the throttle holds on a plain handleRunning call, and finalSample
clears it.

Best effort, like the bandwidth version: a failure here leaves the
previous status in place, which is what would have happened anyway.

Signed-off-by: Davanum Srinivas <dsrinivas@nvidia.com>
@dims
dims force-pushed the worktree-goodput-final branch from dfeb601 to 92cd1e5 Compare August 8, 2026 01:10
Follows pkg/catalog/gpu_defaults_test.go, as pkg/controller does
throughout.

Two cases under testdata/goodput-final-sample. They are a behavioural pin
rather than a value transform, so the recorded output is the two facts
that matter: whether the throttle was cleared, and whether the call asked
for a requeue instead of reading.

Together they show why the fix needs the clear. A plain handleRunning call
one second after a sample is throttled and requeues. finalSample clears
the sample time first, so the last read actually happens.

Signed-off-by: Davanum Srinivas <dsrinivas@nvidia.com>
@lalitadithya
lalitadithya enabled auto-merge (squash) August 8, 2026 08:09
@lalitadithya
lalitadithya merged commit 07008a1 into NVIDIA:main Aug 8, 2026
9 checks passed
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.

2 participants