Skip to content

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

Description

@AdaAibaby

Describe the bug

When a sandbox VM exits (normally or abnormally), the NBD dispatch loop in packages/orchestrator/pkg/sandbox/nbd/dispatch.go logs in-flight read/write failures at ERROR level, even when the errors are expected consequences of VM shutdown (context.Canceled, use of closed network connection). This produces false-alarm ERROR logs on every sandbox teardown.

Observed log lines

level=error msg="nbd backend read failed" error="context canceled" nbd_op=read ...
level=error msg="nbd error cmd read"      error="write unix @->@: use of closed network connection" ...
level=error msg="nbd backend write failed" error="context canceled" nbd_op=write ...
level=error msg="nbd error cmd write"     error="write unix @->@: write: broken pipe" ...

Root cause

In cmdRead() (line ~336) and cmdWrite() (line ~403), backend failures are unconditionally logged at ERROR regardless of whether the error is an expected shutdown signal:

// dispatch.go line 336
logger.L().Error(ctx, "nbd backend read failed",
    zap.Error(readErr), ...)

// dispatch.go line 358 — response write to closed socket
logger.L().Error(ctx, "nbd error cmd read",
    zap.Error(err), ...)

When the VM exits, the sandbox context is cancelled → context.Canceled propagates to all in-flight ReadAt/WriteAt calls and to socket writes on the now-closed NBD Unix socket. All of this is expected, but every in-flight request at the moment of VM exit emits an ERROR.

Expected behavior

  • context.Canceled / context.DeadlineExceeded backend errors → Debug or Warn
  • use of closed network connection / broken pipe response-write errors → Warn (the dispatch loop's fatal channel already handles the fatal case; the default: branch is only reached when the channel is full, meaning shutdown is already in progress)

Impact

  • Noisy ERROR logs on every sandbox teardown
  • Drowns out real storage/backend errors that should trigger alerts

Suggested fix

Differentiate by error type in the logging calls:

if errors.Is(readErr, context.Canceled) || errors.Is(readErr, context.DeadlineExceeded) {
    logger.L().Debug(ctx, "nbd backend read cancelled (VM exiting)", zap.Error(readErr), ...)
} else {
    logger.L().Error(ctx, "nbd backend read failed", zap.Error(readErr), ...)
}

Similarly for cmdWrite and the response-write error paths.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions