diff --git a/audit/internal/app/app.go b/audit/internal/app/app.go index 6a5d359..0315090 100644 --- a/audit/internal/app/app.go +++ b/audit/internal/app/app.go @@ -180,6 +180,16 @@ func New(sys *platform.System) *App { platform.SetJobBoundaryHook(func(string) { requestBlackboxSync(DefaultExportDir) }) + // For the actual load step of a diagnostic (nvbandwidth, memtester, + // stress-ng, dcgmi diag...) — as opposed to the cheap discovery/inventory + // steps around it — block until blackbox has actually copied the + // evidence that the load is about to start onto removable media, and + // again once it finishes. Best-effort: a stuck blackbox target logs a + // warning (see runSyncBracketHook in sat.go) rather than blocking the + // diagnostic itself. + platform.SetSyncBracketHook(func(jobName, phase string) error { + return requestBlackboxSyncAndWait(DefaultExportDir, DefaultBlackboxStatePath, blackboxSyncBracketTimeout) + }) return a } diff --git a/audit/internal/app/blackbox.go b/audit/internal/app/blackbox.go index 5ca6971..ce8c2da 100644 --- a/audit/internal/app/blackbox.go +++ b/audit/internal/app/blackbox.go @@ -15,6 +15,7 @@ import ( "sort" "strings" "sync" + "syscall" "time" "bee/audit/internal/platform" @@ -33,6 +34,13 @@ const ( // output reaches removable media promptly instead of waiting out // whatever the current adaptive flush period happens to be. blackboxKickFileName = ".blackbox-kick" + + // blackboxSyncBracketTimeout bounds how long a syncBracket-marked SAT job + // (see platform.SetSyncBracketHook) blocks waiting for blackbox to catch + // up before/after the actual load step. Generous relative to the normal + // sub-second kick-to-sync latency, but bounded so a genuinely stuck or + // unplugged target can't hang the diagnostic indefinitely. + blackboxSyncBracketTimeout = 20 * time.Second ) // blackboxKickPollInterval is how often an idle worker checks the kick file @@ -53,6 +61,64 @@ func requestBlackboxSync(exportDir string) { _ = os.WriteFile(path, []byte(now.Format(time.RFC3339Nano)+"\n"), 0644) } +// blackboxSyncWaitPollInterval is how often requestBlackboxSyncAndWait +// re-reads the state file while waiting for a sync to catch up. A package +// var so tests can shrink it. +var blackboxSyncWaitPollInterval = 200 * time.Millisecond + +// requestBlackboxSyncAndWait kicks every enrolled blackbox target and blocks +// until each one has completed a sync cycle that started at or after this +// call, or until timeout elapses. Use this (instead of the fire-and-forget +// requestBlackboxSync) around an event where losing the data to a crash +// before it reaches removable media would matter — e.g. bracket a risky load +// step so its own SAT job directory (and the fact that it started at all) is +// durable on the flash drive before the load runs, and durable again once it +// finishes. +// +// Returns nil once caught up. Returns an error naming what didn't catch up +// (timeout, or a target stuck "degraded") — callers should treat that as +// best-effort informational (log it) rather than fail the job over it: a +// blackbox problem should not block the diagnostic the operator actually +// asked for. +func requestBlackboxSyncAndWait(exportDir, statePath string, timeout time.Duration) error { + requestedAt := blackboxNow() + requestBlackboxSync(exportDir) + + deadline := time.Now().Add(timeout) + for { + state, err := ReadBlackboxState(statePath) + if err == nil { + if ok, pending := blackboxStateCaughtUp(state, requestedAt); ok { + return nil + } else if time.Now().After(deadline) { + return fmt.Errorf("blackbox sync did not catch up within %s (pending: %s)", timeout, pending) + } + } else if time.Now().After(deadline) { + return fmt.Errorf("blackbox sync wait: could not read state after %s: %w", timeout, err) + } + time.Sleep(blackboxSyncWaitPollInterval) + } +} + +// blackboxStateCaughtUp reports whether every non-degraded enrolled target +// has synced at or after requestedAt. No targets enrolled counts as caught +// up (nothing to wait for — e.g. no removable media plugged in). A target +// stuck "degraded" (mount/copy failing) is skipped rather than waited on +// forever; its enrollment ID is named in the returned pending string so +// callers can log which target is the reason a real wait timed out. +func blackboxStateCaughtUp(state BlackboxState, requestedAt time.Time) (bool, string) { + for _, t := range state.Targets { + if t.Status == "degraded" { + continue + } + syncedAt, err := time.Parse(time.RFC3339Nano, t.LastSyncAtUTC) + if err != nil || syncedAt.Before(requestedAt) { + return false, t.EnrollmentID + } + } + return true, "" +} + // blackboxKickModTime returns the kick file's mtime, or the zero Time if it // doesn't exist yet (nothing has requested a sync since boot). func blackboxKickModTime(exportDir string) time.Time { @@ -270,7 +336,7 @@ func DisableBlackboxTarget(device, enrollmentID string) error { } func (rt *blackboxRuntime) reconcile() { - discovered, _ := rt.discoverMarkedTargets() + discovered, _ := rt.discoverMarkedTargets(rt.trackedDevices()) rt.mu.Lock() defer rt.mu.Unlock() @@ -311,7 +377,35 @@ func (rt *blackboxRuntime) stopAll() { } } -func (rt *blackboxRuntime) discoverMarkedTargets() ([]discoveredBlackboxTarget, error) { +// trackedDevices returns the already-enrolled targets, keyed by device path, +// for every worker currently running. Used by discoverMarkedTargets to skip +// re-mounting devices a worker already owns. +func (rt *blackboxRuntime) trackedDevices() map[string]discoveredBlackboxTarget { + rt.mu.Lock() + defer rt.mu.Unlock() + known := make(map[string]discoveredBlackboxTarget, len(rt.workers)) + for _, worker := range rt.workers { + worker.mu.Lock() + if worker.target.Device != "" { + known[worker.target.Device] = discoveredBlackboxTarget{ + marker: worker.marker, + target: worker.target, + } + } + worker.mu.Unlock() + } + return known +} + +// discoverMarkedTargets probes removable media for the bee-blackbox marker. +// known holds devices a worker is already running against (see +// trackedDevices) — those are reported back as-is, without mounting, since +// mounting/unmounting the same device on every discovery tick (every +// blackboxDiscoverInterval) fights the worker's own mount for the device and +// was observed to slow its actual sync cycle by an order of magnitude on +// FUSE-backed filesystems (NTFS via ntfs-3g). Only devices with no running +// worker get probed. +func (rt *blackboxRuntime) discoverMarkedTargets(known map[string]discoveredBlackboxTarget) ([]discoveredBlackboxTarget, error) { targets, err := rt.system.ListRemovableTargets() if err != nil { return nil, err @@ -322,6 +416,11 @@ func (rt *blackboxRuntime) discoverMarkedTargets() ([]discoveredBlackboxTarget, if target.Device == "" { continue } + if cached, ok := known[target.Device]; ok { + cached.target = target + out = append(out, cached) + continue + } mountpoint, mountedByBee, err := ensureMountedTarget(target, "probe") if err != nil { continue @@ -578,7 +677,11 @@ func (rt *blackboxRuntime) persistStateLocked() { Mountpoint: worker.mountpoint, } if !worker.lastSyncAt.IsZero() { - targetState.LastSyncAtUTC = worker.lastSyncAt.Format(time.RFC3339) + // Nanosecond precision, not RFC3339's default seconds — a sync + // that lands in the same wall-clock second as a kick request + // must still compare as "after" it (see blackboxStateCaughtUp), + // which second-only precision can get wrong. + targetState.LastSyncAtUTC = worker.lastSyncAt.Format(time.RFC3339Nano) } if worker.lastDuration > 0 { targetState.LastCycleDuration = worker.lastDuration.String() @@ -647,7 +750,15 @@ func ensureMountedTarget(target platform.RemovableTarget, suffix string) (mountp if err := os.MkdirAll(mountpoint, 0755); err != nil { return "", false, err } - if raw, err := blackboxExecCommand("mount", target.Device, mountpoint).CombinedOutput(); err != nil { + // -o sync makes every write to the target synchronous at the VFS layer + // (no page-cache write-back to lose on a hard reset) instead of relying + // solely on the explicit syscall.Sync() calls in writeFileAtomic/ + // unmountTarget to flush it after the fact. Those explicit syncs stay in + // place as a fallback (e.g. for target.Mountpoint above, an + // already-mounted filesystem we don't control the options of) — with -o + // sync already doing the work, they become a fast no-op most of the time + // instead of the primary durability mechanism. + if raw, err := blackboxExecCommand("mount", "-o", "sync", target.Device, mountpoint).CombinedOutput(); err != nil { return "", false, formatBlackboxMountTargetError(target, string(raw), err) } if err := ensureWritableBlackboxMountpoint(mountpoint); err != nil { @@ -658,7 +769,7 @@ func ensureMountedTarget(target platform.RemovableTarget, suffix string) (mountp } func unmountTarget(mountpoint string) error { - _ = blackboxExecCommand("sync").Run() + syscall.Sync() raw, err := blackboxExecCommand("umount", mountpoint).CombinedOutput() if err != nil { msg := strings.TrimSpace(string(raw)) @@ -812,8 +923,15 @@ func writeFileAtomic(path string, data []byte, perm os.FileMode) error { return syncFilesystem(filepath.Dir(path)) } +// syncFilesystem flushes pending writes to durable storage. Uses the sync(2) +// syscall directly rather than spawning /bin/sync — writeFileAtomic calls +// this once per copied file (syncDirectoryTree can touch hundreds of files +// per cycle), and syscall.Sync() does the same flush without a fork+exec per +// call. path is unused (sync(2) always flushes system-wide; kept as a +// parameter for call-site clarity about which tree the caller cares about). func syncFilesystem(path string) error { - return blackboxExecCommand("sync").Run() + syscall.Sync() + return nil } func ensureWritableBlackboxMountpoint(mountpoint string) error { diff --git a/audit/internal/app/blackbox_sync_wait_test.go b/audit/internal/app/blackbox_sync_wait_test.go new file mode 100644 index 0000000..4644459 --- /dev/null +++ b/audit/internal/app/blackbox_sync_wait_test.go @@ -0,0 +1,107 @@ +package app + +import ( + "path/filepath" + "testing" + "time" +) + +func TestBlackboxStateCaughtUp(t *testing.T) { + requestedAt := time.Date(2026, 7, 27, 12, 0, 0, 0, time.UTC) + + t.Run("no targets enrolled", func(t *testing.T) { + ok, pending := blackboxStateCaughtUp(BlackboxState{}, requestedAt) + if !ok || pending != "" { + t.Fatalf("ok=%v pending=%q, want ok=true pending=\"\"", ok, pending) + } + }) + + t.Run("target synced after request", func(t *testing.T) { + state := BlackboxState{Targets: []BlackboxTargetStatus{ + {EnrollmentID: "bb-1", Status: "running", LastSyncAtUTC: requestedAt.Add(time.Second).Format(time.RFC3339)}, + }} + ok, _ := blackboxStateCaughtUp(state, requestedAt) + if !ok { + t.Fatalf("want caught up") + } + }) + + t.Run("target synced before request is not caught up", func(t *testing.T) { + state := BlackboxState{Targets: []BlackboxTargetStatus{ + {EnrollmentID: "bb-1", Status: "running", LastSyncAtUTC: requestedAt.Add(-time.Second).Format(time.RFC3339)}, + }} + ok, pending := blackboxStateCaughtUp(state, requestedAt) + if ok || pending != "bb-1" { + t.Fatalf("ok=%v pending=%q, want ok=false pending=bb-1", ok, pending) + } + }) + + t.Run("degraded target is skipped, not waited on", func(t *testing.T) { + state := BlackboxState{Targets: []BlackboxTargetStatus{ + {EnrollmentID: "bb-1", Status: "degraded", LastSyncAtUTC: ""}, + }} + ok, _ := blackboxStateCaughtUp(state, requestedAt) + if !ok { + t.Fatalf("want a degraded target to not block catch-up") + } + }) + + t.Run("one caught up, one not — overall not caught up", func(t *testing.T) { + state := BlackboxState{Targets: []BlackboxTargetStatus{ + {EnrollmentID: "bb-1", Status: "running", LastSyncAtUTC: requestedAt.Add(time.Second).Format(time.RFC3339)}, + {EnrollmentID: "bb-2", Status: "running", LastSyncAtUTC: requestedAt.Add(-time.Second).Format(time.RFC3339)}, + }} + ok, pending := blackboxStateCaughtUp(state, requestedAt) + if ok || pending != "bb-2" { + t.Fatalf("ok=%v pending=%q, want ok=false pending=bb-2", ok, pending) + } + }) +} + +func TestRequestBlackboxSyncAndWaitReturnsOnceStateCatchesUp(t *testing.T) { + exportDir := t.TempDir() + statePath := filepath.Join(t.TempDir(), "blackbox-state.json") + + old := blackboxSyncWaitPollInterval + blackboxSyncWaitPollInterval = 5 * time.Millisecond + t.Cleanup(func() { blackboxSyncWaitPollInterval = old }) + + // No state file yet — simulates blackbox not running / nothing enrolled. + // Write a caught-up state shortly after the call starts, from another + // goroutine, mimicking a worker finishing a sync cycle mid-wait. + go func() { + time.Sleep(20 * time.Millisecond) + state := BlackboxState{Targets: []BlackboxTargetStatus{ + {EnrollmentID: "bb-1", Status: "running", LastSyncAtUTC: blackboxNow().Format(time.RFC3339Nano)}, + }} + _ = writeJSONAtomic(statePath, state) + }() + + err := requestBlackboxSyncAndWait(exportDir, statePath, time.Second) + if err != nil { + t.Fatalf("requestBlackboxSyncAndWait error: %v", err) + } +} + +func TestRequestBlackboxSyncAndWaitTimesOut(t *testing.T) { + exportDir := t.TempDir() + statePath := filepath.Join(t.TempDir(), "blackbox-state.json") + + old := blackboxSyncWaitPollInterval + blackboxSyncWaitPollInterval = 5 * time.Millisecond + t.Cleanup(func() { blackboxSyncWaitPollInterval = old }) + + // State never catches up (stuck in the past) — the target is not + // degraded, so this must time out rather than return immediately. + state := BlackboxState{Targets: []BlackboxTargetStatus{ + {EnrollmentID: "bb-1", Status: "running", LastSyncAtUTC: time.Unix(0, 0).UTC().Format(time.RFC3339)}, + }} + if err := writeJSONAtomic(statePath, state); err != nil { + t.Fatalf("writeJSONAtomic: %v", err) + } + + err := requestBlackboxSyncAndWait(exportDir, statePath, 30*time.Millisecond) + if err == nil { + t.Fatalf("want a timeout error") + } +} diff --git a/audit/internal/platform/nvidia_bandwidth_socket.go b/audit/internal/platform/nvidia_bandwidth_socket.go index b3a4072..74b46ae 100644 --- a/audit/internal/platform/nvidia_bandwidth_socket.go +++ b/audit/internal/platform/nvidia_bandwidth_socket.go @@ -31,16 +31,22 @@ func gpuBandwidthSocketGroups(gpuIndices []int, logFunc func(string)) [][]int { } byNode := map[int][]int{} + var unresolved []int for _, idx := range gpuIndices { node, ok := nodes[idx] if !ok { if logFunc != nil { - logFunc(fmt.Sprintf("nvbandwidth: no NUMA node resolved for GPU %d; running all GPUs as one group", idx)) + logFunc(fmt.Sprintf("nvbandwidth: no NUMA node resolved for GPU %d; will fold it into a resolved socket group instead of dropping the split", idx)) } - return [][]int{gpuIndices} + unresolved = append(unresolved, idx) + continue } byNode[node] = append(byNode[node], idx) } + // Fewer than two resolved sockets means there's nothing to split either + // way: every GPU's node is unknown, or every resolved GPU shares one + // socket. A single unresolved GPU among an otherwise clean multi-socket + // system shouldn't cost us the split, so only bail out here. if len(byNode) < 2 { return [][]int{gpuIndices} } @@ -55,6 +61,14 @@ func gpuBandwidthSocketGroups(gpuIndices []int, logFunc func(string)) [][]int { for _, node := range sortedNodes { groups = append(groups, dedupeSortedIndices(byNode[node])) } + if len(unresolved) > 0 { + // Fold into the last group rather than running unresolved GPUs in a + // group of their own — a lone GPU can't run a GPU-to-GPU bandwidth + // test by itself, and the point of the split is to isolate the + // sockets we *do* know about, not to also isolate the unknown one. + last := len(groups) - 1 + groups[last] = dedupeSortedIndices(append(groups[last], unresolved...)) + } return groups } diff --git a/audit/internal/platform/nvidia_bandwidth_socket_test.go b/audit/internal/platform/nvidia_bandwidth_socket_test.go index 9b7bfef..8ae8b32 100644 --- a/audit/internal/platform/nvidia_bandwidth_socket_test.go +++ b/audit/internal/platform/nvidia_bandwidth_socket_test.go @@ -91,6 +91,33 @@ func TestGPUBandwidthSocketGroupsSplitsBySocket(t *testing.T) { } } +func TestGPUBandwidthSocketGroupsFoldsUnresolvedIntoLastGroup(t *testing.T) { + // GPU 4's NUMA node fails to resolve (e.g. a flaky sysfs read), but the + // other 5 GPUs still clearly span two sockets — the split should survive + // and GPU 4 should ride along with the last group rather than being + // tested alone or collapsing the whole thing to one pass. + fakeNvidiaSmiBusIDs(t, "0, 00000000:05:00.0\n1, 00000000:06:00.0\n2, 00000000:76:00.0\n3, 00000000:77:00.0\n4, 00000000:F4:00.0\n5, 00000000:F5:00.0\n") + fakeNUMANodes(t, map[string]string{ + "0000:05:00.0": "0\n", + "0000:06:00.0": "0\n", + "0000:76:00.0": "0\n", + "0000:77:00.0": "0\n", + // GPU 4 (F4:00.0) deliberately missing. + "0000:F5:00.0": "1\n", + }) + + groups := gpuBandwidthSocketGroups([]int{0, 1, 2, 3, 4, 5}, nil) + if len(groups) != 2 { + t.Fatalf("groups=%v want 2 groups", groups) + } + if joinIndexList(groups[0]) != "0,1,2,3" { + t.Fatalf("groups[0]=%v want 0,1,2,3", groups[0]) + } + if joinIndexList(groups[1]) != "4,5" { + t.Fatalf("groups[1]=%v want 4,5 (unresolved GPU 4 folded into last group)", groups[1]) + } +} + func TestGPUBandwidthSocketGroupsFallsBackToSingleGroup(t *testing.T) { t.Run("single NUMA node", func(t *testing.T) { fakeNvidiaSmiBusIDs(t, "0, 00000000:05:00.0\n1, 00000000:06:00.0\n") diff --git a/audit/internal/platform/sat.go b/audit/internal/platform/sat.go index 9609d2a..207e746 100644 --- a/audit/internal/platform/sat.go +++ b/audit/internal/platform/sat.go @@ -83,6 +83,34 @@ func SetJobBoundaryHook(hook func(jobName string)) { satJobBoundaryHook = hook } +// satSyncBracketHook, if set, is called synchronously immediately before and +// after a satJob marked syncBracket runs — i.e. around the actual load +// command of a diagnostic (nvbandwidth, memtester, stress-ng, dcgmi diag...), +// not the cheap discovery/inventory steps around it. phase is "before" or +// "after". Unlike satJobBoundaryHook (fire-and-forget, fires after every +// job), this is meant to block until an external blackbox sync has actually +// reached removable media, so that a crash during the load itself still +// leaves durable evidence that the load started (and, on the far side, that +// it finished). Nil by default. An error is logged, never fails the job — +// a stuck blackbox target must not block the diagnostic the operator asked +// for. +var satSyncBracketHook func(jobName, phase string) error + +// SetSyncBracketHook installs the callback invoked synchronously before and +// after a syncBracket-marked SAT job. Pass nil to clear it. +func SetSyncBracketHook(hook func(jobName, phase string) error) { + satSyncBracketHook = hook +} + +func runSyncBracketHook(job satJob, phase string, logFunc func(string)) { + if !job.syncBracket || satSyncBracketHook == nil { + return + } + if err := satSyncBracketHook(job.name, phase); err != nil && logFunc != nil { + logFunc(fmt.Sprintf("%s: blackbox sync wait (%s) did not complete cleanly: %v", job.name, phase, err)) + } +} + var ( satExecCommand = exec.Command satLookPath = exec.LookPath @@ -463,7 +491,7 @@ func (s *System) RunNCCLTests(ctx context.Context, baseDir string, gpuIndices [] satJob{name: "02-all-reduce-perf.log", cmd: []string{ "all_reduce_perf", "-b", "512M", "-e", "4G", "-f", "2", "-g", strconv.Itoa(gpuCount), "--iters", "20", - }, env: nvidiaVisibleDevicesEnv(selected)}, + }, env: nvidiaVisibleDevicesEnv(selected), syncBracket: true}, ), logFunc) } @@ -502,11 +530,12 @@ func (s *System) RunNvidiaOfficialComputePack(ctx context.Context, baseDir strin satJob{name: "01-nvidia-smi-q.log", cmd: []string{"nvidia-smi", "-q"}}, satJob{name: "02-dcgmi-version.log", cmd: []string{"dcgmi", "-v"}}, satJob{ - name: "03-dcgmproftester.log", - cmd: profCmd, - env: profEnv, - collectGPU: true, - gpuIndices: selected, + name: "03-dcgmproftester.log", + cmd: profCmd, + env: profEnv, + collectGPU: true, + gpuIndices: selected, + syncBracket: true, }, satJob{name: "04-nvidia-smi-after.log", cmd: []string{"nvidia-smi", "--query-gpu=index,name,temperature.gpu,power.draw,utilization.gpu,memory.used,memory.total", "--format=csv,noheader,nounits"}}, ), logFunc) @@ -528,10 +557,11 @@ func (s *System) RunNvidiaTargetedPowerPack(ctx context.Context, baseDir string, satJob{name: "01-nvidia-smi-q.log", cmd: []string{"nvidia-smi", "-q"}}, satJob{name: "02-dcgmi-discovery.log", cmd: []string{"dcgmi", "discovery", "-l"}, informational: true, retries: 2}, satJob{ - name: "03-dcgmi-targeted-power.log", - cmd: nvidiaDCGMNamedDiagCommand("targeted_power", normalizeNvidiaBurnDuration(durationSec), selected), - collectGPU: true, - gpuIndices: selected, + name: "03-dcgmi-targeted-power.log", + cmd: nvidiaDCGMNamedDiagCommand("targeted_power", normalizeNvidiaBurnDuration(durationSec), selected), + collectGPU: true, + gpuIndices: selected, + syncBracket: true, }, satJob{name: "04-nvidia-smi-after.log", cmd: []string{"nvidia-smi", "--query-gpu=index,name,temperature.gpu,power.draw,utilization.gpu,memory.used,memory.total", "--format=csv,noheader,nounits"}}, ), logFunc) @@ -553,10 +583,11 @@ func (s *System) RunNvidiaPulseTestPack(ctx context.Context, baseDir string, dur satJob{name: "01-nvidia-smi-q.log", cmd: []string{"nvidia-smi", "-q"}}, satJob{name: "02-dcgmi-discovery.log", cmd: []string{"dcgmi", "discovery", "-l"}, informational: true, retries: 2}, satJob{ - name: "03-dcgmi-pulse-test.log", - cmd: nvidiaDCGMNamedDiagCommand("pulse_test", normalizeNvidiaBurnDuration(durationSec), selected), - collectGPU: true, - gpuIndices: selected, + name: "03-dcgmi-pulse-test.log", + cmd: nvidiaDCGMNamedDiagCommand("pulse_test", normalizeNvidiaBurnDuration(durationSec), selected), + collectGPU: true, + gpuIndices: selected, + syncBracket: true, }, satJob{name: "04-nvidia-smi-after.log", cmd: []string{"nvidia-smi", "--query-gpu=index,name,temperature.gpu,power.draw,utilization.gpu,memory.used,memory.total", "--format=csv,noheader,nounits"}}, ), logFunc) @@ -591,27 +622,30 @@ func (s *System) RunNvidiaBandwidthPack(ctx context.Context, baseDir string, gpu socketGroups := gpuBandwidthSocketGroups(selected, logFunc) if len(socketGroups) <= 1 { jobs = append(jobs, satJob{ - name: fmt.Sprintf("%02d-dcgmi-nvbandwidth.log", step), - cmd: nvidiaDCGMNamedDiagCommand("nvbandwidth", 0, selected), - collectGPU: true, - gpuIndices: selected, + name: fmt.Sprintf("%02d-dcgmi-nvbandwidth.log", step), + cmd: nvidiaDCGMNamedDiagCommand("nvbandwidth", 0, selected), + collectGPU: true, + gpuIndices: selected, + syncBracket: true, }) step++ } else { for i, group := range socketGroups { jobs = append(jobs, satJob{ - name: fmt.Sprintf("%02d-dcgmi-nvbandwidth-socket%d.log", step, i), - cmd: nvidiaDCGMNamedDiagCommand("nvbandwidth", 0, group), - collectGPU: true, - gpuIndices: group, + name: fmt.Sprintf("%02d-dcgmi-nvbandwidth-socket%d.log", step, i), + cmd: nvidiaDCGMNamedDiagCommand("nvbandwidth", 0, group), + collectGPU: true, + gpuIndices: group, + syncBracket: true, }) step++ } jobs = append(jobs, satJob{ - name: fmt.Sprintf("%02d-dcgmi-nvbandwidth-all.log", step), - cmd: nvidiaDCGMNamedDiagCommand("nvbandwidth", 0, selected), - collectGPU: true, - gpuIndices: selected, + name: fmt.Sprintf("%02d-dcgmi-nvbandwidth-all.log", step), + cmd: nvidiaDCGMNamedDiagCommand("nvbandwidth", 0, selected), + collectGPU: true, + gpuIndices: selected, + syncBracket: true, }) step++ } @@ -655,10 +689,11 @@ func (s *System) RunNvidiaTargetedStressValidatePack(ctx context.Context, baseDi satJob{name: "01-nvidia-smi-q.log", cmd: []string{"nvidia-smi", "-q"}}, satJob{name: "02-dcgmi-discovery.log", cmd: []string{"dcgmi", "discovery", "-l"}, informational: true, retries: 2}, satJob{ - name: "03-dcgmi-targeted-stress.log", - cmd: nvidiaDCGMNamedDiagCommand("targeted_stress", normalizeNvidiaBurnDuration(durationSec), selected), - collectGPU: true, - gpuIndices: selected, + name: "03-dcgmi-targeted-stress.log", + cmd: nvidiaDCGMNamedDiagCommand("targeted_stress", normalizeNvidiaBurnDuration(durationSec), selected), + collectGPU: true, + gpuIndices: selected, + syncBracket: true, }, satJob{name: "04-nvidia-smi-after.log", cmd: []string{"nvidia-smi", "--query-gpu=index,name,temperature.gpu,power.draw,utilization.gpu,memory.used,memory.total", "--format=csv,noheader,nounits"}}, ), logFunc) @@ -716,7 +751,7 @@ func (s *System) RunMemoryAcceptancePack(ctx context.Context, baseDir string, si } return runAcceptancePackCtx(ctx, baseDir, "memory", []satJob{ {name: "01-free-before.log", cmd: []string{"free", "-h"}}, - {name: "02-memtester.log", cmd: []string{"timeout", fmt.Sprintf("%d", timeoutSec), "memtester", fmt.Sprintf("%dM", sizeMB), fmt.Sprintf("%d", passes)}}, + {name: "02-memtester.log", cmd: []string{"timeout", fmt.Sprintf("%d", timeoutSec), "memtester", fmt.Sprintf("%dM", sizeMB), fmt.Sprintf("%d", passes)}, syncBracket: true}, {name: "03-free-after.log", cmd: []string{"free", "-h"}}, }, logFunc) } @@ -737,7 +772,7 @@ func (s *System) RunMemoryStressPack(ctx context.Context, baseDir string, durati "--vm-method", "all", "--timeout", fmt.Sprintf("%d", seconds), "--metrics-brief", - }}, + }, syncBracket: true}, {name: "03-free-after.log", cmd: []string{"free", "-h"}}, }, logFunc) } @@ -765,7 +800,7 @@ func (s *System) RunCPUAcceptancePack(ctx context.Context, baseDir string, durat return runAcceptancePackCtx(ctx, baseDir, "cpu", []satJob{ {name: "01-lscpu.log", cmd: []string{"lscpu"}}, {name: "02-sensors-before.log", cmd: []string{"sensors"}}, - {name: "03-stress-ng.log", cmd: []string{"stress-ng", "--cpu", "0", "--cpu-method", "all", "--timeout", fmt.Sprintf("%d", durationSec)}}, + {name: "03-stress-ng.log", cmd: []string{"stress-ng", "--cpu", "0", "--cpu-method", "all", "--timeout", fmt.Sprintf("%d", durationSec)}, syncBracket: true}, {name: "04-sensors-after.log", cmd: []string{"sensors"}}, }, logFunc) } @@ -819,6 +854,7 @@ func (s *System) RunStorageAcceptancePack(ctx context.Context, baseDir string, e } name := fmt.Sprintf("%s-%02d-%s.log", prefix, cmdIndex+1, job.name) livePath := filepath.Join(runDir, name) + runSyncBracketHook(job, "before", logFunc) out, err := runSATCommandCtx(ctx, verboseLog, job.name, job.cmd, nil, logFunc, livePath) deviceOutputs[job.name] = out if writeErr := os.WriteFile(livePath, out, 0644); writeErr != nil { @@ -827,17 +863,23 @@ func (s *System) RunStorageAcceptancePack(ctx context.Context, baseDir string, e if satJobBoundaryHook != nil { satJobBoundaryHook(name) } + // smartctl -t short only launches the self-test on the drive firmware and + // returns immediately ("Testing has begun"); unlike `nvme device-self-test + // --wait`, smartctl has no blocking mode, so we must poll the drive + // ourselves until the self-test actually finishes. Hold the "after" sync + // until that poll completes — the self-test itself, not just its launch, + // is the load worth having durable evidence of. + deferSyncBracketAfter := job.name == "smartctl-self-test-short" && err == nil + if !deferSyncBracketAfter { + runSyncBracketHook(job, "after", logFunc) + } status, rc := classifySATResult(job.name, out, err) stats.Add(status) key := filepath.Base(devPath) + "_" + strings.ReplaceAll(job.name, "-", "_") fmt.Fprintf(&summary, "%s_rc=%d\n", key, rc) fmt.Fprintf(&summary, "%s_status=%s\n", key, status) - // smartctl -t short only launches the self-test on the drive firmware and - // returns immediately ("Testing has begun"); unlike `nvme device-self-test - // --wait`, smartctl has no blocking mode, so we must poll the drive - // ourselves until the self-test actually finishes. - if job.name == "smartctl-self-test-short" && err == nil { + if deferSyncBracketAfter { statusName := "smartctl-self-test-status" statusOut := waitForSmartctlSelfTest(ctx, verboseLog, devPath, logFunc) deviceOutputs[statusName] = statusOut @@ -845,6 +887,7 @@ func (s *System) RunStorageAcceptancePack(ctx context.Context, baseDir string, e if writeErr := os.WriteFile(filepath.Join(runDir, statusFile), statusOut, 0644); writeErr != nil { return "", writeErr } + runSyncBracketHook(job, "after", logFunc) sStatus, sRC := classifySATResult(statusName, statusOut, nil) stats.Add(sStatus) sKey := filepath.Base(devPath) + "_" + strings.ReplaceAll(statusName, "-", "_") @@ -878,6 +921,11 @@ type satJob struct { // retries is the number of extra attempts (with a short backoff) if the // job's first run fails. Used for jobs racing nv-hostengine startup. retries int + // syncBracket marks a job as the actual load step of a pack (as opposed + // to the cheap inventory/discovery steps around it) — see + // satSyncBracketHook. Set this on the command that can hang or crash the + // host, not on nvidia-smi/dcgmi discovery calls. + syncBracket bool } type satStats struct { @@ -903,7 +951,7 @@ func nvidiaSATJobs() []satJob { satJob{name: "02-dmidecode-baseboard.log", cmd: []string{"dmidecode", "-t", "baseboard"}}, satJob{name: "03-dmidecode-system.log", cmd: []string{"dmidecode", "-t", "system"}}, satJob{name: "04-nvidia-bug-report.log", cmd: []string{"nvidia-bug-report.sh", "--output-file", "{{run_dir}}/nvidia-bug-report.log"}}, - satJob{name: "05-bee-gpu-burn.log", cmd: []string{"bee-gpu-burn", "--seconds", "5", "--size-mb", "64"}}, + satJob{name: "05-bee-gpu-burn.log", cmd: []string{"bee-gpu-burn", "--seconds", "5", "--size-mb", "64"}, syncBracket: true}, ) } @@ -924,7 +972,7 @@ func nvidiaDCGMJobs(diagLevel int, gpuIndices []int) []satJob { satJob{name: "02-dmidecode-baseboard.log", cmd: []string{"dmidecode", "-t", "baseboard"}}, satJob{name: "03-dmidecode-system.log", cmd: []string{"dmidecode", "-t", "system"}}, satJob{name: "04-dcgmi-discovery.log", cmd: []string{"dcgmi", "discovery", "-l"}, informational: true, retries: 2}, - satJob{name: "05-dcgmi-diag.log", cmd: diagArgs, gpuIndices: gpuIndices}, + satJob{name: "05-dcgmi-diag.log", cmd: diagArgs, gpuIndices: gpuIndices, syncBracket: true}, ) } @@ -1016,6 +1064,7 @@ func runAcceptancePackCtx(ctx context.Context, baseDir, prefix string, jobs []sa } if err == nil { + runSyncBracketHook(job, "before", logFunc) for attempt := 0; ; attempt++ { if job.collectGPU { out, err = runSATCommandWithMetrics(ctx, verboseLog, job.name, cmd, job.env, job.gpuIndices, runDir, logFunc) @@ -1053,6 +1102,7 @@ func runAcceptancePackCtx(ctx context.Context, baseDir, prefix string, jobs []sa if satJobBoundaryHook != nil { satJobBoundaryHook(job.name) } + runSyncBracketHook(job, "after", logFunc) if ctx.Err() != nil { return "", ctx.Err() } @@ -1383,7 +1433,7 @@ func storageSATCommands(devPath string, extended bool) []satJob { {name: "nvme-smart-log", cmd: []string{"nvme", "smart-log", devPath, "-o", "json"}}, } if extended { - jobs = append(jobs, satJob{name: "nvme-device-self-test", cmd: []string{"nvme", "device-self-test", devPath, "-s", "1", "--wait"}}) + jobs = append(jobs, satJob{name: "nvme-device-self-test", cmd: []string{"nvme", "device-self-test", devPath, "-s", "1", "--wait"}, syncBracket: true}) } return jobs } @@ -1391,7 +1441,7 @@ func storageSATCommands(devPath string, extended bool) []satJob { {name: "smartctl-health", cmd: []string{"smartctl", "-H", "-A", "-i", devPath}}, } if extended { - jobs = append(jobs, satJob{name: "smartctl-self-test-short", cmd: []string{"smartctl", "-t", "short", devPath}}) + jobs = append(jobs, satJob{name: "smartctl-self-test-short", cmd: []string{"smartctl", "-t", "short", devPath}, syncBracket: true}) } return jobs } diff --git a/audit/internal/platform/sat_live_output_test.go b/audit/internal/platform/sat_live_output_test.go index 3ad91ea..484d9fb 100644 --- a/audit/internal/platform/sat_live_output_test.go +++ b/audit/internal/platform/sat_live_output_test.go @@ -2,9 +2,11 @@ package platform import ( "context" + "fmt" "os" "os/exec" "path/filepath" + "strings" "testing" ) @@ -95,3 +97,56 @@ func TestRunAcceptancePackCtxInvokesJobBoundaryHook(t *testing.T) { t.Fatalf("seen=%v want [01-a.log 02-b.log]", seen) } } + +func TestRunAcceptancePackCtxInvokesSyncBracketHookOnlyForMarkedJobs(t *testing.T) { + old := satSyncBracketHook + t.Cleanup(func() { satSyncBracketHook = old }) + + var calls []string + SetSyncBracketHook(func(jobName, phase string) error { + calls = append(calls, jobName+":"+phase) + return nil + }) + + oldExecCommand := satExecCommand + satExecCommand = func(name string, args ...string) *exec.Cmd { + return exec.Command(name, args...) + } + t.Cleanup(func() { satExecCommand = oldExecCommand }) + + dir := t.TempDir() + _, err := runAcceptancePackCtx(context.Background(), dir, "test-pack", []satJob{ + {name: "01-inventory.log", cmd: []string{"printf", "a\n"}}, + {name: "02-load.log", cmd: []string{"printf", "b\n"}, syncBracket: true}, + }, nil) + if err != nil { + t.Fatalf("runAcceptancePackCtx error: %v", err) + } + + want := []string{"02-load.log:before", "02-load.log:after"} + if len(calls) != len(want) { + t.Fatalf("calls=%v want %v", calls, want) + } + for i := range want { + if calls[i] != want[i] { + t.Fatalf("calls=%v want %v", calls, want) + } + } +} + +func TestRunSyncBracketHookLogsErrorWithoutFailingJob(t *testing.T) { + old := satSyncBracketHook + t.Cleanup(func() { satSyncBracketHook = old }) + SetSyncBracketHook(func(jobName, phase string) error { + return fmt.Errorf("blackbox target unreachable") + }) + + var logged []string + runSyncBracketHook(satJob{name: "02-load.log", syncBracket: true}, "before", func(line string) { + logged = append(logged, line) + }) + + if len(logged) != 1 || !strings.Contains(logged[0], "02-load.log") || !strings.Contains(logged[0], "blackbox target unreachable") { + t.Fatalf("logged=%v want a single line naming the job and the error", logged) + } +} diff --git a/iso/builder/auto/config b/iso/builder/auto/config index 3db5bae..4e4d6b1 100755 --- a/iso/builder/auto/config +++ b/iso/builder/auto/config @@ -38,7 +38,6 @@ lb config noauto \ --linux-flavours "amd64" \ --linux-packages "${LB_LINUX_PACKAGES}" \ --memtest memtest86+ \ - --hostname "${LB_HOSTNAME}" \ --iso-volume "${LB_ISO_VOLUME}" \ --iso-application "EASY-BEE-${BEE_GPU_VENDOR_UPPER:-NVIDIA}" \ --bootappend-live "boot=live live-media=/dev/disk/by-label/${LB_ISO_VOLUME} live-media-label=${LB_ISO_VOLUME} components video=1920x1080 console=ttyS0,115200n8 console=tty0 loglevel=3 systemd.show_status=1 username=bee user-fullname=Bee modprobe.blacklist=nouveau,snd_hda_intel,snd_hda_codec_realtek,snd_hda_codec_generic,soundcore" \ @@ -46,3 +45,10 @@ lb config noauto \ --apt-recommends false \ --chroot-squashfs-compression-type zstd \ "${@}" + +# live-build (1:20230502, bookworm) has no `lb config --hostname` flag: the +# chroot_hostname helper zeroes /etc/hostname to "localhost.localdomain" for +# the duration of package installation and restores it afterwards from this +# includes file, so this is the only supported way to set it. +mkdir -p config/includes.chroot_before_packages/etc +echo "${LB_HOSTNAME}" > config/includes.chroot_before_packages/etc/hostname