amadan
host: root logs a held-release request's fields only after validation, quoted (Task 7b fix round 2, P3-2)
A refused request logged its host, action and version as received, so the authenticated agent could forge lines in instance-control's journal. A request that fails validation now logs a fixed sentence and the quoted error; a validated one logs its fields with %q, as do the staged and published lines.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2 files changed,
+65
−3
internal/host/movesheldrelease_linux_test.go+55 −0internal/host/movesheldrelease_root.go+10 −3
diff --git a/internal/host/movesheldrelease_linux_test.go b/internal/host/movesheldrelease_linux_test.go| index a6e69b940..1ee8a683e 100644 |
| --- a/internal/host/movesheldrelease_linux_test.go |
| +++ b/internal/host/movesheldrelease_linux_test.go |
| @@ -3,13 +3,16 @@ |
| package host |
| import ( |
| + "bytes" |
| "context" |
| "errors" |
| + "log" |
| "net" |
| "net/http" |
| "os" |
| "path/filepath" |
| "strings" |
| + "sync" |
| "testing" |
| "time" |
| @@ -202,3 +205,55 @@ func TestHeldReleaseOverTheRootSocket(t *testing.T) { |
| } |
| }) |
| } |
| + |
| +// syncBuffer is a log sink the server goroutine and the test share. |
| +type syncBuffer struct { |
| + mu sync.Mutex |
| + b bytes.Buffer |
| +} |
| + |
| +func (s *syncBuffer) Write(p []byte) (int, error) { |
| + s.mu.Lock() |
| + defer s.mu.Unlock() |
| + return s.b.Write(p) |
| +} |
| + |
| +func (s *syncBuffer) String() string { |
| + s.mu.Lock() |
| + defer s.mu.Unlock() |
| + return s.b.String() |
| +} |
| + |
| +// TestHeldReleaseRootLogsOnlyValidatedFields (fix round 2, P3-2): root |
| +// never logs a request's fields before they pass validation, so the |
| +// authenticated agent cannot forge lines in instance-control's journal; |
| +// after validation it logs them quoted. |
| +func TestHeldReleaseRootLogsOnlyValidatedFields(t *testing.T) { |
| + ctx := context.Background() |
| + f := newHRFixture(t) |
| + f.root.Authenticate = func(context.Context, net.Conn) (StopPeer, error) { return hrPeer, nil } |
| + var logs syncBuffer |
| + prev := log.Writer() |
| + log.SetOutput(&logs) |
| + t.Cleanup(func() { log.SetOutput(prev) }) |
| + client := newHeldReleaseRootClient(serveClaimRoot(t, ClaimRootWithLaunch{HeldRelease: f.root})) |
| + |
| + forged := f.request(heldReleasePublish) |
| + forged.Host = "a.go.example.com\nmoves: FORGED publication of v9" |
| + forged.Version = "v7\nmoves: FORGED" |
| + if _, err := client.HeldRelease(ctx, forged); err == nil { |
| + t.Fatal("a malformed request was accepted") |
| + } |
| + stale := f.request(heldReleasePublish) |
| + stale.Session = 99 |
| + if _, err := client.HeldRelease(ctx, stale); !errors.Is(err, release.ErrStaleHeldStage) { |
| + t.Fatalf("a stale request: %v", err) |
| + } |
| + out := logs.String() |
| + if strings.Contains(out, "FORGED") { |
| + t.Fatalf("root logged an unvalidated field:\n%s", out) |
| + } |
| + if !strings.Contains(out, `"`+p1Host+`"`) { |
| + t.Fatalf("root did not log the validated request quoted:\n%s", out) |
| + } |
| +} |
diff --git a/internal/host/movesheldrelease_root.go b/internal/host/movesheldrelease_root.go| index 6e59057a7..390871a20 100644 |
| --- a/internal/host/movesheldrelease_root.go |
| +++ b/internal/host/movesheldrelease_root.go |
| @@ -102,7 +102,14 @@ func (h *movesHeldReleaseRoot) ServeHTTP(w http.ResponseWriter, r *http.Request) |
| } |
| out, err := h.Serve(r.Context(), peer, q) |
| if err != nil { |
| - log.Printf("moves: %s: held release %s of %s refused: %v", q.Host, q.Action, q.Version, err) |
| + // Fix round 2, P3-2: a request's fields reach the log only once they |
| + // have passed validation, and then quoted, as is the error, so the |
| + // agent cannot forge a line in instance-control's journal. |
| + if q.validate() != nil { |
| + log.Printf("moves: held release refused: a malformed request: %q", err.Error()) |
| + } else { |
| + log.Printf("moves: %q: held release %q of %q refused: %q", q.Host, q.Action, q.Version, err.Error()) |
| + } |
| http.Error(w, "refused", heldReleaseStatus(err)) |
| return |
| } |
| @@ -296,7 +303,7 @@ func (h *movesHeldReleaseRoot) stageRelease(ctx context.Context, actor hostbox.A |
| if _, err := stage(ctx, h.Store, h.Pub, h.Ratchet(), h.OptDir, heldReleaseRoute(q), q.Version, h.Proof()); err != nil { |
| return heldReleaseResponse{}, err |
| } |
| - log.Printf("moves: %s: held release %s staged for %s (no publication)", q.Host, q.Version, q.MoveID) |
| + log.Printf("moves: %q: held release %q staged for %q (no publication)", q.Host, q.Version, q.MoveID) |
| return heldReleaseResponse{Schema: heldReleaseSchema, RequestID: q.RequestID, Outcome: heldReleaseOutcomeStaged}, nil |
| } |
| @@ -443,7 +450,7 @@ func (h *movesHeldReleaseRoot) publishRelease(ctx context.Context, actor hostbox |
| // the same release, and it errs again until a receipt persists. |
| return heldReleaseResponse{}, fmt.Errorf("%w: %v", errHeldReleaseReceipt, err) |
| } |
| - log.Printf("moves: %s: held release %s published for %s at %s %q", q.Host, q.Version, q.MoveID, q.Kind, q.Phase) |
| + log.Printf("moves: %q: held release %q published for %q at %q %q", q.Host, q.Version, q.MoveID, q.Kind, q.Phase) |
| return heldReleaseResponse{Schema: heldReleaseSchema, RequestID: q.RequestID, Outcome: heldReleaseOutcomePublished}, nil |
| } |