Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
38 changes: 33 additions & 5 deletions packages/orchestrator/pkg/sandbox/nbd/dispatch.go
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,9 @@ import (
"errors"
"fmt"
"io"
"net"
"sync"
"syscall"
"time"

"go.opentelemetry.io/otel/attribute"
Expand Down Expand Up @@ -227,8 +229,7 @@ func (d *Dispatch) completeAsync(ctx context.Context, cmd command, perform func(
select {
case d.fatal <- err:
default:
d.logger.Error(ctx, "nbd command failed while the dispatcher was already failing",
append(cmd.fields(), zap.Error(err))...)
d.logCmdFailure(ctx, "nbd command failed while the dispatcher was already failing", cmd, err)
}
}()
}
Expand Down Expand Up @@ -384,6 +385,33 @@ func (d *Dispatch) Handle(ctx context.Context) error {
}
}

// isExpectedTeardownError reports whether err is the ordinary consequence of a
// sandbox shutting down rather than a genuine backend or socket failure. When a
// VM exits, in-flight commands observe the cancelled dispatch context
// (context.Canceled / context.DeadlineExceeded) and the reply socket is closed
// under us (net.ErrClosed, or EPIPE / "broken pipe" on a half-closed pipe).
// These are expected during teardown; logging them at Error drowns out the real
// backend failures that Error is meant to surface.
func isExpectedTeardownError(err error) bool {
return errors.Is(err, context.Canceled) ||
errors.Is(err, context.DeadlineExceeded) ||
errors.Is(err, net.ErrClosed) ||
errors.Is(err, syscall.EPIPE)
}

// logCmdFailure logs a failed NBD command, downgrading expected teardown errors
// to Warn so they cannot mask real failures logged at Error.
func (d *Dispatch) logCmdFailure(ctx context.Context, msg string, cmd command, err error) {
fields := append(cmd.fields(), zap.Error(err))
if isExpectedTeardownError(err) {
d.logger.Warn(ctx, msg, fields...)

return
}

d.logger.Error(ctx, msg, fields...)
}

func (d *Dispatch) cmdRead(ctx context.Context, cmd command) error {
if err := d.admit(); err != nil {
return err
Expand Down Expand Up @@ -431,7 +459,7 @@ func (d *Dispatch) cmdRead(ctx context.Context, cmd command) error {
// Per-request backend failure: signal it to the NBD client via the
// response error byte and keep the dispatch loop alive. Only
// writeResponse errors (dead NBD socket) escalate through d.fatal.
d.logger.Error(ctx, "nbd backend read failed", append(cmd.fields(), zap.Error(readErr))...)
d.logCmdFailure(ctx, "nbd backend read failed", cmd, readErr)
recordLegFault(ctx)

return d.writeResponse(1, cmd.handle, []byte{})
Expand Down Expand Up @@ -474,7 +502,7 @@ func (d *Dispatch) cmdWrite(ctx context.Context, cmd command, cmdData []byte) er
}

if writeErr != nil {
d.logger.Error(ctx, "nbd backend write failed", append(cmd.fields(), zap.Error(writeErr))...)
d.logCmdFailure(ctx, "nbd backend write failed", cmd, writeErr)
recordLegFault(ctx)

return d.writeResponse(1, cmd.handle, []byte{})
Expand Down Expand Up @@ -525,7 +553,7 @@ func (d *Dispatch) cmdWriteZeroes(ctx context.Context, cmd command) error {
var respErr uint32
if zeroErr != nil {
respErr = 1
d.logger.Error(ctx, "nbd backend punch failed", append(cmd.fields(), zap.Error(zeroErr))...)
d.logCmdFailure(ctx, "nbd backend punch failed", cmd, zeroErr)
recordLegFault(ctx)
}

Expand Down
94 changes: 94 additions & 0 deletions packages/orchestrator/pkg/sandbox/nbd/dispatch_teardown_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,94 @@
//go:build linux

package nbd

import (
"context"
"errors"
"fmt"
"io"
"net"
"syscall"
"testing"
)

// Regression for #3274: in-flight NBD reads/writes and reply-socket writes that
// fail because the sandbox is exiting must be classified as expected teardown
// noise (logged at Warn), while genuine backend failures must not be — they stay
// at Error. isExpectedTeardownError is the single predicate both levels hang off,
// so it is the thing worth locking down.
func TestIsExpectedTeardownError(t *testing.T) {
t.Parallel()

tests := []struct {
name string
err error
want bool
}{
{
name: "context canceled (dispatch ctx cancelled on VM exit)",
err: context.Canceled,
want: true,
},
{
name: "context canceled wrapped",
err: fmt.Errorf("read backend: %w", context.Canceled),
want: true,
},
{
name: "deadline exceeded",
err: context.DeadlineExceeded,
want: true,
},
{
name: "closed network connection (reply socket closed under us)",
err: net.ErrClosed,
want: true,
},
{
name: "closed network connection wrapped in OpError",
err: &net.OpError{Op: "write", Net: "unix", Err: net.ErrClosed},
want: true,
},
{
name: "broken pipe (EPIPE) wrapped in OpError",
err: &net.OpError{Op: "write", Net: "unix", Err: syscall.EPIPE},
want: true,
},
{
name: "bare EPIPE",
err: syscall.EPIPE,
want: true,
},
{
name: "real backend error must stay Error",
err: errors.New("backing store returned corrupt block"),
want: false,
},
{
name: "unexpected EOF is a real failure",
err: io.ErrUnexpectedEOF,
want: false,
},
{
name: "ECONNRESET is not treated as expected teardown",
err: syscall.ECONNRESET,
want: false,
},
{
name: "nil is not an error",
err: nil,
want: false,
},
}

for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
t.Parallel()

if got := isExpectedTeardownError(tt.err); got != tt.want {
t.Errorf("isExpectedTeardownError(%v) = %v, want %v", tt.err, got, tt.want)
}
})
}
}