Skip to content

fix(orchestrator): log expected NBD teardown errors at Warn, not Error - #3737

Open
AdaAibaby wants to merge 1 commit into
e2b-dev:mainfrom
AdaAibaby:fix/nbd-dispatch-teardown-log-level
Open

AdaAibaby wants to merge 1 commit into
e2b-dev:mainfrom
AdaAibaby:fix/nbd-dispatch-teardown-log-level

Conversation

@AdaAibaby

Copy link
Copy Markdown
Contributor

Problem

When a Firecracker VM exits, in-flight NBD commands and the reply socket fail in predictable, non-fault ways — yet all of them were logged at ERROR, so every normal teardown with in-flight I/O produced a burst of ERROR lines that drown out the real backend failures ERROR is meant to surface (#3274):

  • cmdRead / cmdWrite / cmdWriteZeroes select on the dispatch context, so an in-flight backend call observes context.Canceled (or DeadlineExceeded) the instant the sandbox is torn down.
  • completeAsync's reply-socket write fails with use of closed network connection (net.ErrClosed) or broken pipe (EPIPE) once the client side is gone.

Fix — dispatch.go

  • Add isExpectedTeardownError(err) — true for context.Canceled, context.DeadlineExceeded, net.ErrClosed, syscall.EPIPE.
  • Add logCmdFailure(ctx, msg, cmd, err) and route all four failure logs through it: expected teardown errors go to Warn, everything else stays at Error.

Genuine backend errors (corrupt block, ECONNRESET, unexpected EOF) still surface at Error.

Before (every teardown with in-flight I/O):

level=error msg="nbd backend read failed"  error="context canceled"
level=error msg="nbd backend write failed" error="context canceled"
level=error msg="nbd command failed while the dispatcher was already failing" error="write unix @->@: use of closed network connection"

After: the same lines at level=warn; real backend faults unchanged at level=error.

Tests — dispatch_teardown_test.go

Table-driven test over the classifier (the single predicate both log levels hang off): wrapped context.Canceled, net.ErrClosed / EPIPE inside *net.OpError (how a closed-socket write actually surfaces), plus the negatives that must stay Error (ECONNRESET, unexpected EOF, a plain error, nil). go build ./... and go vet clean; full nbd package green.

Scope

Revives only the NBD-dispatch half of the closed #3277. Its other half — the FC metrics flusher select-race guard (#3275) — is already fixed on main by 50c64bee8 ("stop flushing Firecracker metrics after the VM exits"), so it is intentionally dropped. #3275 is CLOSED COMPLETED; #3274 is still open.

Adapted to main's refactor since the original PR (single completeAsync error log, command.fields(), injected d.logger). The fix is also broader-but-precise vs the original: the original only special-cased context.Canceled on the backend path and blanket-downgraded the fatal path; here one classifier covers both backend-cancel and closed-socket errors and leaves real failures at Error.

Closes #3274. Supersedes #3277 (closed for inactivity / merge drift; maintainer invited a fresh PR against current main).

When a Firecracker VM exits, in-flight NBD commands and the reply socket
fail in predictable ways that are not backend faults:

  - cmdRead/cmdWrite/cmdWriteZeroes select on the dispatch context, so an
    in-flight backend call observes context.Canceled (or DeadlineExceeded)
    the moment the sandbox is torn down.
  - completeAsync's reply-socket write fails with "use of closed network
    connection" (net.ErrClosed) or "broken pipe" (EPIPE) once the client
    side is gone.

All four paths logged these at Error, so every normal teardown with
in-flight I/O produced a burst of ERROR lines that drown out the real
backend failures Error is meant to surface (e2b-dev#3274).

Introduce isExpectedTeardownError (context.Canceled, context.DeadlineExceeded,
net.ErrClosed, syscall.EPIPE) and route all four failure logs through a new
logCmdFailure helper that downgrades those to Warn and keeps everything else
at Error. Genuine backend errors (corrupt block, ECONNRESET, unexpected EOF)
still surface at Error.

Adds dispatch_teardown_test.go: a table-driven test over the classifier
covering wrapped context errors, net.ErrClosed/EPIPE inside *net.OpError (how
a closed-socket write actually surfaces), and the negatives that must stay
Error.

Scope note: this PR revives only the NBD-dispatch half of the closed e2b-dev#3277.
Its other half — the FC metrics flusher select-race guard (e2b-dev#3275) — is
already fixed on main by 50c64be ("stop flushing Firecracker metrics after
the VM exits"), so it is intentionally left out. e2b-dev#3275 is CLOSED COMPLETED;
e2b-dev#3274 is still open. Adapted to main's refactor (single completeAsync error
log, command.fields(), injected d.logger). Closes e2b-dev#3274. Supersedes e2b-dev#3277.

This branch has not been deployed

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

Projects

None yet

Development

Successfully merging this pull request may close these issues.

orchestrator: NBD dispatch logs context.Canceled and closed-socket errors at ERROR level after normal VM exit

2 participants