Fix must-gather hang: apply --timeout to log streaming phase#2297
Fix must-gather hang: apply --timeout to log streaming phase#2297afcollins wants to merge 1 commit into
Conversation
|
[APPROVALNOTIFIER] This PR is NOT APPROVED This pull-request has been approved by: afcollins The full list of commands accepted by this bot can be found here. DetailsNeeds approval from an approver in each of these files:Approvers can indicate their approval by writing |
WalkthroughThe must-gather log flow now uses a timeout-scoped context for log streaming and gather completion polling, while the download/copy step remains on the parent context. Log-streaming errors now ignore both cancellation and deadline expiration. ChangesMust-Gather Timeout Scoping
Estimated code review effort: 2 (Simple) | ~10 minutes 🚥 Pre-merge checks | ✅ 15✅ Passed checks (15 passed)
✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
There was a problem hiding this comment.
🧹 Nitpick comments (1)
pkg/cli/admin/mustgather/mustgather.go (1)
834-854: 📐 Maintainability & Code Quality | 🔵 Trivial | ⚡ Quick winAdd/update unit test coverage for the new timeout scoping behavior.
This change alters lifecycle timing and error-suppression logic but no corresponding test changes are included.
processNextWorkItemis exercised viaMustGatherOptions, so a table-driven test simulating a slow/hanging log stream (context deadline expiring mid-stream) would validate that the command now returns promptly with "gather never finished" instead of hanging, and thatDeadlineExceededfrom log streaming doesn't spuriously log "gather logs unavailable."
As per coding guidelines, "All changes must include unit test additions/changes."🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@pkg/cli/admin/mustgather/mustgather.go` around lines 834 - 854, Add or update unit tests for the new timeout scoping in MustGatherOptions.processNextWorkItem. Cover a slow or hanging getGatherContainerLogs path where gatherCtx expires mid-stream, and assert the command returns promptly with the expected "gather never finished" behavior instead of hanging. Also verify that context.DeadlineExceeded or context.Canceled from getGatherContainerLogs does not trigger the "gather logs unavailable" log path, while non-context errors still do.Source: Coding guidelines
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Nitpick comments:
In `@pkg/cli/admin/mustgather/mustgather.go`:
- Around line 834-854: Add or update unit tests for the new timeout scoping in
MustGatherOptions.processNextWorkItem. Cover a slow or hanging
getGatherContainerLogs path where gatherCtx expires mid-stream, and assert the
command returns promptly with the expected "gather never finished" behavior
instead of hanging. Also verify that context.DeadlineExceeded or
context.Canceled from getGatherContainerLogs does not trigger the "gather logs
unavailable" log path, while non-context errors still do.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository YAML (base), Central YAML (inherited)
Review profile: CHILL
Plan: Enterprise
Run ID: 79101a03-76c9-4e86-9a09-f4f771ba4057
📒 Files selected for processing (1)
pkg/cli/admin/mustgather/mustgather.go
|
|
||
| // wait for gather container to be running (gather is running) | ||
| if err := o.waitForGatherContainerRunning(ctx, pod); err != nil { | ||
| if err := o.waitForGatherContainerRunning(gatherCtx, pod); err != nil { |
There was a problem hiding this comment.
I would use ctx here. No need to include this kind of waiting in the timeout IMO.
| // wait for pod to be running (gather has completed) | ||
| log("waiting for gather to complete") | ||
| if err := o.waitForGatherToComplete(ctx, pod); err != nil { | ||
| if err := o.waitForGatherToComplete(gatherCtx, pod); err != nil { |
There was a problem hiding this comment.
Since you are passing a timeout context here, we don't need to use PollUntilContextTimeout and o.Timeout within this function, so it can be removed, I think. Not that it really matters, but better not to repeat the same thing on multiple places.
There was a problem hiding this comment.
I see. I think we could revert to ctx here as well.
There was a problem hiding this comment.
Although, the difference between passing gatherCtx and the PollUntil loop within each function is each one of those loops will timeout at 35 minutes. Instead of the overall gather timing out at the shared timeout.
Is that the behavior we want?
I think the user experience of setting --timeout is that I expect the command to terminate after that timeout is reached, not that the timeout is applied for sub steps of the overall command.
There was a problem hiding this comment.
Discussing some issues with Claude, namely that now only one of the phases is covered by gatherCtx:
The timeout in getGatherContainerLogs doesn't cover waitForGatherToComplete, so the gather phase can hang for up to 2x the timeout:
getGatherContainerLogscreatesgatherCtxwitho.Timeout(e.g. 10m).- Log streaming runs for 9m, then
gatherCtxexpires →DeadlineExceeded. - The error is silently swallowed (line 842).
waitForGatherToCompletestarts a fresho.Timeoutpoll — another 10m.
If the gather pod is truly stuck (never terminates), waitForGatherToComplete blocks for the full additional timeout — which is the Prow hang scenario this PR is trying to fix.
Suggested fix: lift gatherCtx into processNextWorkItem so it covers waitForGatherContainerRunning, getGatherContainerLogs, and waitForGatherToComplete under a single timeout. The copy phase stays on the parent ctx as intended.
// in processNextWorkItem, before the gather calls:
gatherCtx, gatherCancel := context.WithTimeout(ctx, o.Timeout)
defer gatherCancel()
if err := o.waitForGatherContainerRunning(gatherCtx, pod); err != nil { ... }
if err := o.getGatherContainerLogs(gatherCtx, pod); err != nil { ... }
if err := o.waitForGatherToComplete(gatherCtx, pod); err != nil { ... }
// copy phase uses ctx, not gatherCtx
if err := o.copyFilesFromPod(ctx, pod); err != nil { ... }I think the proposed solution is good in spirit. Wondering still whether to include waiting for the container to come up. Strictly speaking no. The point of the timeout is not to terminate oc after the given timeout, so the user can't expect oc to always unblock, I think. And it's not the case even now. What do you think?
There was a problem hiding this comment.
So Claude suggested the same fix for both of us. :)
I am OK with treating each step with its own timeout. That behavior wasn't clear to me before, but I understand it now.
I believe the issue when one or more nodes cannot be reached is purely from the lack of timeout in getGatherContainerLogs, so we can keep that as the focused change of this PR.
I am not sure if the PR tests will cover this scenario, so I will need to try it out to make sure it works as expected.
|
Also I am not sure about our policy, but I tend to remove |
I thought Red Hat policy was to identify commits so we know which ones are AI-assisted. Anyway, removed. Please check again. |
getGatherContainerLogs had no timeout, blocking forever if gather scripts ran long. Wrap all gather phases in a shared deadline context. Review feedback Revert context from two loops that already manage timeout on their own. Move timeout context within narrow function scope. Signed-off-by: Andrew Collins <ancollin@redhat.com>
There was a problem hiding this comment.
♻️ Duplicate comments (1)
pkg/cli/admin/mustgather/mustgather.go (1)
953-991: 🎯 Functional Correctness | 🟠 Major | 🏗️ Heavy liftPer-phase timeout budgets can compound beyond the documented
--timeoutsemantics.
getGatherContainerLogsnow derives its owngatherCtxwith a fresho.Timeoutbudget, on top ofwaitForGatherContainerRunning(line 1058, unchanged) already independently applying its owno.Timeoutviawait.PollUntilContextTimeout. IfwaitForGatherToCompletefollows the same pattern, the overall "gather" phase inprocessNextWorkItem(container-start wait → log stream → completion wait) could take up to ~3×o.Timeoutin the worst case, not the single boundedo.Timeoutthat the flag's own help text promises ("This timeout only applies to the data gathering phase"). This is the same concern previously raised by reviewers (tchap: "we don't need to usePollUntilContextTimeoutando.Timeoutwithin this function"; afcollins: "I think the user experience of setting--timeoutis that I expect the command to terminate after that timeout is reached"), and it does not appear resolved here.Separately, the comment at lines 954-956 claims
gatherCtxcovers "the entire gather lifecycle (waiting for container start, streaming logs, waiting for completion)", butgatherCtxis scoped only to this function's log-streaming/isGatherDoneloop —waitForGatherContainerRunningandwaitForGatherToComplete(called before/after, inprocessNextWorkItem) still use the plainctxwith their own separateo.Timeoutwindows. The comment should be corrected to reflect the actual (per-substep) scope, or the design should be changed to derive one shared deadline-scoped context inprocessNextWorkItemand pass it through all three phases (dropping the redundant internalo.Timeoutusage in each), consistent with the earlier reviewer feedback.Suggested direction (illustrative, needs coordination across the three phases)
func (o *MustGatherOptions) processNextWorkItem(ctx context.Context, ns string, pod *corev1.Pod) error { + // Single deadline covering the whole gather phase (start-wait, log + // streaming, completion-wait). Copying intentionally continues on ctx. + gatherCtx, gatherCancel := context.WithTimeout(ctx, o.Timeout) + defer gatherCancel() ... - if err := o.waitForGatherContainerRunning(ctx, pod); err != nil { + if err := o.waitForGatherContainerRunning(gatherCtx, pod); err != nil { ... - if err := o.getGatherContainerLogs(ctx, pod); err != nil { + if err := o.getGatherContainerLogs(gatherCtx, pod); err != nil { ... - if err := o.waitForGatherToComplete(ctx, pod); err != nil { + if err := o.waitForGatherToComplete(gatherCtx, pod); err != nil {And drop the now-redundant internal
context.WithTimeout(ctx, o.Timeout)/o.Timeout-based polling insidegetGatherContainerLogs/waitForGatherContainerRunning/waitForGatherToComplete.As per coding guidelines,
pkg/cli/**/*.goshould usecontext.Contextcorrectly for cancellation and timeouts — the concern here is that the current per-function contexts don't yield the single-overall-deadline behavior the--timeoutflag documents.#!/bin/bash # Confirm whether waitForGatherToComplete independently re-applies o.Timeout ast-grep run --pattern 'func (o *MustGatherOptions) waitForGatherToComplete($_, $_) $_ { $$$ }' --lang go pkg/cli/admin/mustgather/mustgather.go🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@pkg/cli/admin/mustgather/mustgather.go` around lines 953 - 991, The gather-phase timeout handling is still using separate per-step deadlines instead of one shared `--timeout` budget, so `processNextWorkItem`, `waitForGatherContainerRunning`, `getGatherContainerLogs`, and `waitForGatherToComplete` can compound their waits. Refactor the flow to derive a single deadline-scoped context once in `processNextWorkItem` and pass it through all three phases, removing the inner `context.WithTimeout(ctx, o.Timeout)` / `wait.PollUntilContextTimeout` usage. Also update the `getGatherContainerLogs` comment to match the actual scope if you keep any substep-specific context behavior.Source: Path instructions
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Duplicate comments:
In `@pkg/cli/admin/mustgather/mustgather.go`:
- Around line 953-991: The gather-phase timeout handling is still using separate
per-step deadlines instead of one shared `--timeout` budget, so
`processNextWorkItem`, `waitForGatherContainerRunning`,
`getGatherContainerLogs`, and `waitForGatherToComplete` can compound their
waits. Refactor the flow to derive a single deadline-scoped context once in
`processNextWorkItem` and pass it through all three phases, removing the inner
`context.WithTimeout(ctx, o.Timeout)` / `wait.PollUntilContextTimeout` usage.
Also update the `getGatherContainerLogs` comment to match the actual scope if
you keep any substep-specific context behavior.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository YAML (base), Central YAML (inherited)
Review profile: CHILL
Plan: Enterprise
Run ID: 765d1b13-c49c-456d-a2c0-5e88b8cae86e
📒 Files selected for processing (1)
pkg/cli/admin/mustgather/mustgather.go
|
@afcollins: all tests passed! Full PR test history. Your PR dashboard. DetailsInstructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository. I understand the commands that are listed here. |
Right. I think the right tag is |
getGatherContainerLogs had no timeout, blocking forever if gather scripts ran long. Wrap all gather phases in a shared deadline context.
Summary by CodeRabbit