F6 deeper half: poll agent /disks/format/status on the 15s client timeout (slow USB mkfs runs detached) — agentapi.FormatStatus + awaitAgentFormat; then mount+register. Found on the live leg.

2026-07-17 09:41:50 +02:00
parent 0025a3b090
commit 0515d153db
4 changed files with 142 additions and 3 deletions
@@ -19,7 +19,13 @@ Closes two `VALIDATION-n100-baremetal-2026-07-16.md` findings. Green:
  is the LAST step (marker-last, Scenario B) and every prior step is idempotent (`AddStoragePath`
  dedups) → a crash leaves at most an unregistered orphan, never a broken/duplicate registration.
  Red-proof `TestStorageInit_DetachedSurvivesClientDisconnect` (pre-fix: cancelled-ctx chain fails at
-  mount, NOT registered → FAIL; fixed: detached job registers exactly once).
+  mount, NOT registered → FAIL; fixed: detached job registers exactly once). **Deeper half (found on
+  the live leg — a 64 GB USB):** a slow mkfs outruns the agentapi client's 15 s `Timeout`; the agent
+  runs it DETACHED and records the job, so `runStorageInit` now POLLS the agent's
+  `GET /disks/format/status` (new `agentapi.Client.FormatStatus`) to the terminal outcome on a client
+  timeout, then continues to mount+register (the F6 root-cause's "mkfs continues detached; poll the
+  status"). Test `TestStorageInit_PollsAgentFormatStatusOnTimeout` (timeout→done registers;
+  timeout→failed surfaces the error, no register).
 - **F7 (LOW) — the "Vissza" (Back) anchor on `/storage/init` and `/storage/attach` now routes to
  `/storage`** (was `/settings`). The init success link also points to `/storage` (where the new
  drive appears). Test `TestStorageWizardBackAnchors_PointToStorage`.
@@ -661,6 +661,30 @@ func (c *Client) FormatDisk(ctx context.Context, device, fstype string, confirme
 	return out, nil
 }

+// FormatStatusResult mirrors GET /disks/format/status (F20-BUG3): the most-recent / in-flight format
+// job on the host. Phase ∈ idle | running | done | failed. The drive-init flow polls this to follow a
+// mkfs that outran the 15 s client timeout — the agent runs the mkfs DETACHED and keeps the record, so
+// the client can learn the real outcome instead of assuming failure (F6).
+type FormatStatusResult struct {
+	Phase  string `json:"phase"`
+	Device string `json:"device"`
+	FSType string `json:"fstype"`
+	Error  string `json:"error"`
+}
+
+// FormatStatus fetches the agent's most-recent format-job record.
+func (c *Client) FormatStatus(ctx context.Context) (FormatStatusResult, error) {
+	var out FormatStatusResult
+	body, err := c.get(ctx, "/disks/format/status")
+	if err != nil {
+		return out, err
+	}
+	if err := json.Unmarshal(body, &out); err != nil {
+		return out, fmt.Errorf("agentapi: decode /disks/format/status: %w", err)
+	}
+	return out, nil
+}
+
 // ---- NAS network storage (Part A2 → agent A1 /netstorage/*) ------------------------------
 //
 // A NAS share is a DISTINCT storage class from a drive: the controller proxies add/list/remove to the
@@ -31,6 +31,7 @@ type diskAgent interface {
 	Disks(ctx context.Context) (agentapi.DisksResponse, error)
 	ListCandidates(ctx context.Context) (agentapi.CandidatesResult, error)
 	FormatDisk(ctx context.Context, device, fstype string, confirmed bool, durableID string) (agentapi.FormatResult, error)
+	FormatStatus(ctx context.Context) (agentapi.FormatStatusResult, error)
 	AssignDisk(ctx context.Context, uuid, where, fstype, options string) error
 	EjectDisk(ctx context.Context, where string) (agentapi.EjectResult, error)
 	Decommission(ctx context.Context, where string) (agentapi.DecommissionResult, error)
@@ -133,11 +134,18 @@ func (s *Server) runStorageInit(ctx context.Context, agent diskAgent, device, fs
 		}
 		return res, nil // STOP — no bypass; the UI surfaces Opsign.
 	}
-	if err != nil {
+	if err != nil && !isAgentTimeout(err) {
 		return storageInitResult{}, fmt.Errorf("formázás sikertelen: %w", err)
 	}
 	if !fr.Formatted {
-		return storageInitResult{}, fmt.Errorf("az eszköz nem lett megformázva (%s)", fr.Reason)
+		// A slow mkfs (e.g. a large USB) outran the agent client's 15 s timeout — the agent runs the
+		// mkfs DETACHED and records the job, so we POLL GET /disks/format/status to the terminal
+		// outcome (F6: "mkfs continues detached; poll the status") and only THEN continue to
+		// mount+register. A real (non-timeout) format failure surfaced above already.
+		fr, err = s.awaitAgentFormat(ctx, agent, device)
+		if err != nil {
+			return storageInitResult{}, err
+		}
 	}
 	// 2. Resolve the NEW fs UUID. A freshly-formatted RAW device isn't in /disks (not enrolled yet), so
 	// resolve via the raw-device scan too (Impl-2b) — the device now appears there with its new durable_id.
@@ -196,6 +204,56 @@ func (s *Server) runStorageAttach(ctx context.Context, agent diskAgent, device,
 	return storageInitResult{Registered: true, Where: stable}, nil
 }

+// isAgentTimeout reports whether a FormatDisk error is the agent-client's 15 s timeout (the mkfs is
+// then running DETACHED agent-side) rather than a real format failure — so we poll the status instead
+// of surfacing it as a failure (F6). A confirm/refuse verdict is returned as a typed error and is
+// matched BEFORE this, so it never reaches here.
+func isAgentTimeout(err error) bool {
+	if err == nil {
+		return false
+	}
+	if errors.Is(err, context.DeadlineExceeded) {
+		return true
+	}
+	s := err.Error()
+	return strings.Contains(s, "Client.Timeout") || strings.Contains(s, "deadline exceeded") || strings.Contains(s, "awaiting headers")
+}
+
+// awaitAgentFormat follows a mkfs that outran the agent-client timeout: the agent runs it detached and
+// records the job, so we poll GET /disks/format/status until it leaves `running` (F6). Returns a
+// Formatted result on a `done` job, or an error on `failed` / idle (no job) / a persistent poll error /
+// ctx expiry. Transient poll errors are tolerated up to a small budget (the agent may be busy).
+func (s *Server) awaitAgentFormat(ctx context.Context, agent diskAgent, device string) (agentapi.FormatResult, error) {
+	t := time.NewTicker(2 * time.Second)
+	defer t.Stop()
+	consecutiveErrs := 0
+	for {
+		st, err := agent.FormatStatus(ctx)
+		if err != nil {
+			consecutiveErrs++
+			if consecutiveErrs >= 5 {
+				return agentapi.FormatResult{}, fmt.Errorf("a formázás állapota nem kérdezhető le: %w", err)
+			}
+		} else {
+			consecutiveErrs = 0
+			switch st.Phase {
+			case "done": // the agent's format-job terminal phases (internal/localapi/formatjob.go)
+				return agentapi.FormatResult{Device: device, Formatted: true}, nil
+			case "failed":
+				return agentapi.FormatResult{}, fmt.Errorf("formázás sikertelen: %s", st.Error)
+			case "idle":
+				return agentapi.FormatResult{}, fmt.Errorf("a formázás nem indult el az eszközön (%s)", device)
+				// "running" (or an unexpected phase) → keep polling
+			}
+		}
+		select {
+		case <-ctx.Done():
+			return agentapi.FormatResult{}, ctx.Err()
+		case <-t.C:
+		}
+	}
+}
+
 // reEnrollClearMarker un-retires a re-plugged decommissioned drive (Change 4): clears the soft marker
 // and restores Schedulable so its apps' "missing storage" indicator clears. Returns true if it acted.
 func (s *Server) reEnrollClearMarker(where string) (bool, error) {
@@ -40,6 +40,9 @@ type mockAgent struct {
 	assignCalls       []assignCall
 	disksCalls        int
 	formatCalls       []formatCall
+	formatStatus      agentapi.FormatStatusResult
+	formatStatusErr   error
+	formatStatusCalls int
 	guestAttachCalls  []string
 	decommissionCalls []string
 	guestRebootCalls  int
@@ -65,6 +68,10 @@ func (m *mockAgent) FormatDisk(_ context.Context, device, fstype string, confirm
 	m.formatCalls = append(m.formatCalls, formatCall{device, fstype, durableID, confirmed})
 	return m.formatRes, m.formatErr
 }
+func (m *mockAgent) FormatStatus(context.Context) (agentapi.FormatStatusResult, error) {
+	m.formatStatusCalls++
+	return m.formatStatus, m.formatStatusErr
+}
 func (m *mockAgent) AssignDisk(ctx context.Context, uuid, where, fstype, _ string) error {
 	// Respect cancellation — a mount over a dead client/request context fails (this is the F6 bug's
 	// mechanism: a disconnect after format aborts the mount+register leg). Background ctx never
@@ -274,6 +281,50 @@ func TestStorageInit_DetachedSurvivesClientDisconnect(t *testing.T) {
 	})
 }

+// F6 deeper half — a slow mkfs outruns the agent-client's 15 s timeout; the agent runs it detached,
+// so the controller must POLL GET /disks/format/status and continue to mount+register on `done`
+// (rather than reporting the timeout as a failure). Observed live on a 64 GB USB.
+func TestStorageInit_PollsAgentFormatStatusOnTimeout(t *testing.T) {
+	t.Run("timeout_then_done_registers", func(t *testing.T) {
+		s := testServer(t)
+		agent := &mockAgent{
+			formatErr:    context.DeadlineExceeded, // the 15 s client timeout — mkfs continues detached
+			formatStatus: agentapi.FormatStatusResult{Phase: "done", Device: "/dev/sdb1"},
+			disks: agentapi.DisksResponse{Disks: []agentapi.DiskInfo{
+				{Name: "felhom-usb", BackingDevice: "/dev/sdb1", DurableID: "uuid:NEW-9999"},
+			}},
+		}
+		res, err := s.runStorageInit(context.Background(), agent, "/dev/sdb1", "ext4", "/mnt/hdd1", "HDD", true, false, "", nil)
+		if err != nil {
+			t.Fatalf("expected success via the format-status poll, got %v", err)
+		}
+		if !res.Registered {
+			t.Fatal("expected registered after the format-status poll (F6)")
+		}
+		if agent.formatStatusCalls == 0 {
+			t.Fatal("the agent format-status was never polled")
+		}
+		if len(agent.assignCalls) != 1 {
+			t.Fatalf("expected exactly one mount after poll-done: %+v", agent.assignCalls)
+		}
+	})
+
+	t.Run("timeout_then_failed_surfaces_error", func(t *testing.T) {
+		s := testServer(t)
+		agent := &mockAgent{
+			formatErr:    context.DeadlineExceeded,
+			formatStatus: agentapi.FormatStatusResult{Phase: "failed", Device: "/dev/sdb1", Error: "mkfs exploded"},
+		}
+		_, err := s.runStorageInit(context.Background(), agent, "/dev/sdb1", "ext4", "/mnt/hdd1", "HDD", true, false, "", nil)
+		if err == nil {
+			t.Fatal("a failed detached format must surface an error, not register")
+		}
+		if len(s.settings.GetStoragePaths()) != 0 {
+			t.Fatalf("a failed format must NOT register: %+v", s.settings.GetStoragePaths())
+		}
+	})
+}
+
 // F7 (VALIDATION-n100) — the "Vissza" (Back) anchor on the init/attach wizards must route to
 // /storage, not /settings. One assertion per template.
 func TestStorageWizardBackAnchors_PointToStorage(t *testing.T) {