Skip to content

Commit b970d64

Browse files
arkamare2b-bot[bot]
authored andcommitted
feat(orchestrator): count snapshot loads Firecracker refuses
GitOrigin-RevId: a66f7ccec33f90c2e17edb7fd8980f3a45d09d8c
1 parent 7ec416d commit b970d64

7 files changed

Lines changed: 379 additions & 0 deletions

File tree

‎packages/orchestrator/pkg/sandbox/fc/client.go‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,8 @@ import (
1212
"github.com/firecracker-microvm/firecracker-go-sdk"
1313
openapiruntime "github.com/go-openapi/runtime"
1414
"github.com/go-openapi/strfmt"
15+
"go.opentelemetry.io/otel/attribute"
16+
"go.opentelemetry.io/otel/metric"
1517

1618
"github.com/e2b-dev/infra/packages/orchestrator/pkg/sandbox/template"
1719
"github.com/e2b-dev/infra/packages/orchestrator/pkg/sandbox/uffd/memory"
@@ -80,6 +82,10 @@ func (c *apiClient) loadSnapshot(
8082

8183
_, err := c.client.Operations.LoadSnapshot(&snapshotConfig)
8284
if err != nil {
85+
reason := classifySnapshotLoadFailure(err)
86+
fcSnapshotLoadFailures.Add(ctx, 1, metric.WithAttributes(attribute.String("reason", string(reason))))
87+
span.SetAttributes(attribute.String("snapshot_load.failure_reason", string(reason)))
88+
8389
return fmt.Errorf("error loading snapshot: %w", err)
8490
}
8591

‎packages/orchestrator/pkg/sandbox/fc/fc_metrics.go‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -59,6 +59,11 @@ var (
5959
fcBlockFails = utils.Must(telemetry.GetCounter(fcMeter, telemetry.SandboxFCBlockFails))
6060
fcBlockNoAvailBuffer = utils.Must(telemetry.GetCounter(fcMeter, telemetry.SandboxFCBlockNoAvailBuffer))
6161

62+
// Refused snapshot loads, by reason. Recorded from the API error rather
63+
// than from the metrics FIFO: a refused load stops the Firecracker process
64+
// before it flushes, so its own metrics never carry the failure.
65+
fcSnapshotLoadFailures = utils.Must(telemetry.GetCounter(fcMeter, telemetry.SandboxFCSnapshotLoadFailures))
66+
6267
// Block histograms.
6368
fcBlockBytes = utils.Must(telemetry.GetHistogram(fcMeter, telemetry.SandboxFCBlockBytes))
6469
fcBlockCount = utils.Must(telemetry.GetHistogram(fcMeter, telemetry.SandboxFCBlockCount))
Lines changed: 102 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,102 @@
1+
//go:build linux
2+
3+
package fc
4+
5+
import (
6+
"context"
7+
"errors"
8+
"strings"
9+
10+
openapiruntime "github.com/go-openapi/runtime"
11+
12+
"github.com/e2b-dev/infra/packages/shared/pkg/fc/client/operations"
13+
"github.com/e2b-dev/infra/packages/shared/pkg/fc/models"
14+
)
15+
16+
// snapshotLoadFailureReason labels a refused snapshot load. It is deliberately
17+
// a small closed set: the fault text Firecracker returns is influenced by the
18+
// snapshot's own contents, so it is classified here and never emitted as a
19+
// metric attribute.
20+
type snapshotLoadFailureReason string
21+
22+
const (
23+
// snapshotLoadVcpuMSR is an MSR in the snapshot that the reading host's
24+
// kernel will not accept — a kernel difference, not a CPU one. Every such
25+
// host refuses the same snapshot, so its template is unusable, not slow.
26+
snapshotLoadVcpuMSR snapshotLoadFailureReason = "vcpu_msr"
27+
// snapshotLoadVcpuOther is any other vCPU restore failure.
28+
snapshotLoadVcpuOther snapshotLoadFailureReason = "vcpu_other"
29+
// snapshotLoadBadRequest is every other refusal, and the bucket a fault we
30+
// have not classified lands in: Firecracker answered 400 and did not name
31+
// the vCPUs. Memory backend, snapshot version and unreadable snapshot file
32+
// all arrive here, as does a reworded fault from a future version.
33+
snapshotLoadBadRequest snapshotLoadFailureReason = "bad_request"
34+
// snapshotLoadUnavailable is a non-400 answer: the load never reached the
35+
// snapshot.
36+
snapshotLoadUnavailable snapshotLoadFailureReason = "unavailable"
37+
// snapshotLoadTransport is the API socket being unreachable or answering
38+
// unintelligibly, which says nothing about the snapshot.
39+
snapshotLoadTransport snapshotLoadFailureReason = "transport"
40+
// snapshotLoadTimeout is the load overrunning the request deadline.
41+
// Firecracker never answered, but the sandbox never resumed either.
42+
snapshotLoadTimeout snapshotLoadFailureReason = "timeout"
43+
// snapshotLoadCanceled is the caller going away mid-load: not a broken
44+
// snapshot, and the one reason an alert leaves out.
45+
snapshotLoadCanceled snapshotLoadFailureReason = "canceled"
46+
)
47+
48+
// classifySnapshotLoadFailure maps an error from Firecracker's PUT
49+
// /snapshot/load to the reason attribute. err must be non-nil.
50+
//
51+
// Firecracker's answer is read before the context: a refusal that lands as the
52+
// caller goes away is still a refusal.
53+
func classifySnapshotLoadFailure(err error) snapshotLoadFailureReason {
54+
if badRequest, ok := errors.AsType[*operations.LoadSnapshotBadRequest](err); ok {
55+
return classifySnapshotLoadFault(badRequest.GetPayload())
56+
}
57+
58+
// Every other status arrives as the default response, including the 2xx
59+
// codes go-swagger reports as errors because they are undeclared.
60+
if _, ok := errors.AsType[*operations.LoadSnapshotDefault](err); ok {
61+
return snapshotLoadUnavailable
62+
}
63+
64+
if _, ok := errors.AsType[*openapiruntime.APIError](err); ok {
65+
return snapshotLoadUnavailable
66+
}
67+
68+
// No answer. The deadline is the orchestrator's own request timeout, so it
69+
// expiring is an overrun load rather than a caller losing interest.
70+
if errors.Is(err, context.DeadlineExceeded) {
71+
return snapshotLoadTimeout
72+
}
73+
74+
if errors.Is(err, context.Canceled) {
75+
return snapshotLoadCanceled
76+
}
77+
78+
return snapshotLoadTransport
79+
}
80+
81+
// classifySnapshotLoadFault reads the fault text of a 400. An absent payload
82+
// is still a refusal, so it counts as one.
83+
func classifySnapshotLoadFault(payload *models.Error) snapshotLoadFailureReason {
84+
if payload == nil {
85+
return snapshotLoadBadRequest
86+
}
87+
88+
// Firecracker nests the cause: "Failed to restore from snapshot: Failed to
89+
// build microVM from snapshot: Failed to restore vCPUs: ... Failed to set
90+
// all KVM MSRs for this vCPU." Match on the vCPU stage and then on the MSR
91+
// step within it, so a vCPU failure for another reason is still separated
92+
// from a memory-backend or version refusal.
93+
if !strings.Contains(payload.FaultMessage, "Failed to restore vCPUs") {
94+
return snapshotLoadBadRequest
95+
}
96+
97+
if strings.Contains(payload.FaultMessage, "KVM MSRs") {
98+
return snapshotLoadVcpuMSR
99+
}
100+
101+
return snapshotLoadVcpuOther
102+
}
Lines changed: 98 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,98 @@
1+
//go:build linux
2+
3+
package fc
4+
5+
import (
6+
"net"
7+
"net/http"
8+
"os"
9+
"testing"
10+
11+
"github.com/stretchr/testify/assert"
12+
"github.com/stretchr/testify/require"
13+
"go.opentelemetry.io/otel"
14+
"go.opentelemetry.io/otel/attribute"
15+
sdkmetric "go.opentelemetry.io/otel/sdk/metric"
16+
"go.opentelemetry.io/otel/sdk/metric/metricdata"
17+
18+
"github.com/e2b-dev/infra/packages/shared/pkg/telemetry"
19+
)
20+
21+
type stubSnapfile string
22+
23+
func (s stubSnapfile) Path() string { return string(s) }
24+
func (s stubSnapfile) Close() error { return nil }
25+
26+
// The same refusal, as Firecracker words it, replayed by the stub.
27+
const msrFaultResponse = `{"fault_message":"Load snapshot error: Failed to restore from snapshot: Failed to build microVM from snapshot: Failed to restore vCPUs: Failed to run action on vcpu: Failed to set all KVM MSRs for this vCPU. Only a partial write was done."}`
28+
29+
// The classifier is unit-tested on its own; this covers the wiring instead —
30+
// that a refusal on the real loadSnapshot path reaches the counter, under the
31+
// reason the fault deserves, with the attribute key an alert will group by. A
32+
// dropped Add or a renamed attribute is invisible in the classifier's tests
33+
// and would only show up as an alert that never fires.
34+
//
35+
//nolint:paralleltest // otel.SetMeterProvider mutates process state
36+
func TestLoadSnapshotRecordsRefusal(t *testing.T) {
37+
reader := sdkmetric.NewManualReader()
38+
otel.SetMeterProvider(sdkmetric.NewMeterProvider(sdkmetric.WithReader(reader)))
39+
40+
// Not t.TempDir(): its path embeds the full test name and overflows the
41+
// 108-char unix sun_path limit.
42+
dir, err := os.MkdirTemp("", "fc") //nolint:usetesting // t.TempDir embeds the test name and overflows the unix sun_path limit
43+
require.NoError(t, err)
44+
t.Cleanup(func() { _ = os.RemoveAll(dir) })
45+
46+
socket := dir + "/fc.sock"
47+
listener, err := new(net.ListenConfig).Listen(t.Context(), "unix", socket)
48+
require.NoError(t, err)
49+
50+
mux := http.NewServeMux()
51+
mux.HandleFunc("PUT /snapshot/load", func(w http.ResponseWriter, _ *http.Request) {
52+
w.Header().Set("Content-Type", "application/json")
53+
w.WriteHeader(http.StatusBadRequest)
54+
_, _ = w.Write([]byte(msrFaultResponse))
55+
})
56+
server := &http.Server{Handler: mux} //nolint:gosec // no timeouts needed for a stub on a private socket
57+
go func() { _ = server.Serve(listener) }()
58+
t.Cleanup(func() { _ = server.Close() })
59+
60+
// uffdReady is never closed: the load fails before it is waited on.
61+
err = newApiClient(socket).loadSnapshot(t.Context(), dir+"/uffd.sock", make(chan struct{}), stubSnapfile(dir+"/snapfile"), false, false)
62+
require.Error(t, err)
63+
64+
assert.Equal(t, int64(1), counterValue(t, reader, string(telemetry.SandboxFCSnapshotLoadFailures), "reason", string(snapshotLoadVcpuMSR)))
65+
}
66+
67+
// counterValue sums the data points of one counter carrying the given
68+
// attribute, and fails when the counter was never recorded at all.
69+
func counterValue(t *testing.T, reader sdkmetric.Reader, name, attrKey, attrValue string) int64 {
70+
t.Helper()
71+
72+
var collected metricdata.ResourceMetrics
73+
require.NoError(t, reader.Collect(t.Context(), &collected))
74+
75+
for _, scope := range collected.ScopeMetrics {
76+
for _, recorded := range scope.Metrics {
77+
if recorded.Name != name {
78+
continue
79+
}
80+
81+
sum, ok := recorded.Data.(metricdata.Sum[int64])
82+
require.Truef(t, ok, "%s is not an int64 sum: %T", name, recorded.Data)
83+
84+
var total int64
85+
for _, point := range sum.DataPoints {
86+
if value, found := point.Attributes.Value(attribute.Key(attrKey)); found && value.Emit() == attrValue {
87+
total += point.Value
88+
}
89+
}
90+
91+
return total
92+
}
93+
}
94+
95+
t.Fatalf("%s was never recorded", name)
96+
97+
return 0
98+
}
Lines changed: 112 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,112 @@
1+
//go:build linux
2+
3+
package fc
4+
5+
import (
6+
"context"
7+
"errors"
8+
"fmt"
9+
"net"
10+
"testing"
11+
12+
openapiruntime "github.com/go-openapi/runtime"
13+
"github.com/stretchr/testify/assert"
14+
15+
"github.com/e2b-dev/infra/packages/shared/pkg/fc/client/operations"
16+
"github.com/e2b-dev/infra/packages/shared/pkg/fc/models"
17+
)
18+
19+
// Firecracker's fault for an MSR the reading host's kernel refuses. Kept whole,
20+
// as it arrives: the classifier matches two nested stages inside it.
21+
const msrFault = "Load snapshot error: Failed to restore from snapshot: Failed to build microVM from snapshot: Failed to restore vCPUs: Failed to run action on vcpu: Failed to set all KVM MSRs for this vCPU. Only a partial write was done."
22+
23+
func badRequest(fault string) error {
24+
return &operations.LoadSnapshotBadRequest{Payload: &models.Error{FaultMessage: fault}}
25+
}
26+
27+
func TestClassifySnapshotLoadFailure(t *testing.T) {
28+
t.Parallel()
29+
30+
for _, tc := range []struct {
31+
name string
32+
err error
33+
want snapshotLoadFailureReason
34+
}{
35+
{
36+
name: "msr fault names the vcpu and the msr step",
37+
err: badRequest(msrFault),
38+
want: snapshotLoadVcpuMSR,
39+
},
40+
{
41+
// The reason exists so that an MSR alert does not absorb every
42+
// other way vCPU restore can fail.
43+
name: "vcpu restore failing elsewhere is not an msr failure",
44+
err: badRequest("Load snapshot error: Failed to restore from snapshot: Failed to build microVM from snapshot: Failed to restore vCPUs: Failed to run action on vcpu: Failed to set the TSC frequency."),
45+
want: snapshotLoadVcpuOther,
46+
},
47+
{
48+
name: "refusal that does not reach the vcpus",
49+
err: badRequest("Load snapshot error: Failed to restore from snapshot: Cannot deserialize the microVM state: Snapshot file was created by a different version"),
50+
want: snapshotLoadBadRequest,
51+
},
52+
{
53+
// A later Firecracker rewording the fault must still count as a
54+
// refusal, so the total stays complete and only the breakdown
55+
// loses precision.
56+
name: "unrecognized fault text still counts as a refusal",
57+
err: badRequest("Load snapshot error: something we have never seen"),
58+
want: snapshotLoadBadRequest,
59+
},
60+
{
61+
name: "400 without a payload is still a refusal",
62+
err: &operations.LoadSnapshotBadRequest{},
63+
want: snapshotLoadBadRequest,
64+
},
65+
{
66+
name: "wrapped fault is classified through the wrapping",
67+
err: fmt.Errorf("error loading snapshot: %w", badRequest(msrFault)),
68+
want: snapshotLoadVcpuMSR,
69+
},
70+
{
71+
name: "non-400 status never reached the snapshot",
72+
err: operations.NewLoadSnapshotDefault(500),
73+
want: snapshotLoadUnavailable,
74+
},
75+
{
76+
name: "api error never reached the snapshot",
77+
err: openapiruntime.NewAPIError("load snapshot", nil, 503),
78+
want: snapshotLoadUnavailable,
79+
},
80+
{
81+
name: "unreachable socket says nothing about the snapshot",
82+
err: fmt.Errorf("post unix socket: %w", &net.OpError{Op: "dial", Err: errors.New("connection refused")}),
83+
want: snapshotLoadTransport,
84+
},
85+
{
86+
// The one reason an alert leaves out, so it must not absorb a load
87+
// that never finished.
88+
name: "caller cancellation is not a broken snapshot",
89+
err: fmt.Errorf("load snapshot: %w", context.Canceled),
90+
want: snapshotLoadCanceled,
91+
},
92+
{
93+
// The orchestrator's own request timeout: the load overran.
94+
name: "deadline is a load that never finished",
95+
err: fmt.Errorf("load snapshot: %w", context.DeadlineExceeded),
96+
want: snapshotLoadTimeout,
97+
},
98+
{
99+
// Firecracker can answer while the caller is already gone. Reading
100+
// the cancel instead would drop a dead template from the total.
101+
name: "an answer outranks a cancel that arrived with it",
102+
err: fmt.Errorf("load snapshot: %w", errors.Join(badRequest(msrFault), context.Canceled)),
103+
want: snapshotLoadVcpuMSR,
104+
},
105+
} {
106+
t.Run(tc.name, func(t *testing.T) {
107+
t.Parallel()
108+
109+
assert.Equal(t, tc.want, classifySnapshotLoadFailure(tc.err))
110+
})
111+
}
112+
}

0 commit comments

Comments
 (0)