diff --git a/plugin/appstore/supervisor.go b/plugin/appstore/supervisor.go index 0d0c562..523d23d 100644 --- a/plugin/appstore/supervisor.go +++ b/plugin/appstore/supervisor.go @@ -168,6 +168,12 @@ type supervisor struct { ready map[string]bool // app_id → socket has appeared at least once crashes map[string]*crashRecord // app_id → sliding-window crash counter appCancel map[string]context.CancelFunc // app_id → cancel its per-app context (used to stop a supervise goroutine on detected uninstall) + + // sigMu guards sigFails. Kept separate from mu because the + // signature-failure bookkeeping happens inside scanInstalled, which + // must not hold the main lock while walking the filesystem. + sigMu sync.Mutex + sigFails map[string]*sigFailRecord // install-dir name → manifest-signature failure state } func newSupervisor(cfg Config, deps Deps, logger *log.Logger) *supervisor { @@ -183,6 +189,7 @@ func newSupervisor(cfg Config, deps Deps, logger *log.Logger) *supervisor { ready: map[string]bool{}, crashes: map[string]*crashRecord{}, appCancel: map[string]context.CancelFunc{}, + sigFails: map[string]*sigFailRecord{}, } } @@ -288,6 +295,109 @@ type installedApp struct { Sideloaded bool } +// Signature-failure backoff/quarantine bounds. A manifest whose ed25519 +// signature does not verify is skipped by scanInstalled, so it is never +// added to the installed map and gets re-examined on EVERY rescan tick. +// Without throttling that produced hundreds of thousands of identical +// "signature verification failed" log lines (the ~2s hot loop this fix +// addresses). These bounds dedup the log per (dir, manifest-hash), back +// off between re-verifications, and quarantine a persistently-bad app. +const ( + // sigBackoffStart is the first re-verify delay after a signature + // failure (matches the old fixed hot-loop cadence for one attempt). + sigBackoffStart = 2 * time.Second + // sigBackoffMax caps the re-verify delay so a bad app is retried + // rarely rather than every rescan tick. + sigBackoffMax = 5 * time.Minute + // sigQuarantineAfter is the number of consecutive same-hash + // signature failures after which the app is considered quarantined. + // Quarantine only slows re-verification to the sigBackoffMax tier; + // it never crashes the supervisor — the bad app is merely isolated. + sigQuarantineAfter = 5 +) + +// sigFailRecord tracks a single install dir's manifest-signature failure +// state so identical failures are logged once and retried with backoff. +type sigFailRecord struct { + hash string // sha256 hex of the manifest bytes that failed + fails int // consecutive failures for this exact hash + backoff time.Duration // current re-verify delay + nextRetry time.Time // earliest time to re-run VerifySignature + logged bool // failure already logged for this hash (dedup) + quarantined bool // quarantine line already emitted for this hash +} + +// sha256Hex returns the hex-encoded sha256 of b. Used to key +// signature-failure dedup on manifest content so a changed manifest +// re-attempts and re-logs. +func sha256Hex(b []byte) string { + sum := sha256.Sum256(b) + return hex.EncodeToString(sum[:]) +} + +// shouldAttemptSignature reports whether scanInstalled should run the +// ed25519 signature check for the app in dirName whose manifest bytes +// hash to `hash`. A never-failed app, or one whose manifest changed +// (new hash), always attempts. A same-hash failure is attempted only +// once its backoff timer has elapsed — this is what stops the hot loop. +func (s *supervisor) shouldAttemptSignature(dirName, hash string) bool { + s.sigMu.Lock() + defer s.sigMu.Unlock() + rec, ok := s.sigFails[dirName] + if !ok || rec.hash != hash { + return true + } + return !time.Now().Before(rec.nextRetry) +} + +// noteSignatureFailure records a manifest signature-verification failure +// for the app in dirName. It logs at most ONCE per distinct manifest +// hash (an identical failure on the next rescan tick is silent), applies +// capped exponential backoff between retries, and emits a single +// quarantine line after sigQuarantineAfter consecutive same-hash +// failures. A changed manifest (different hash) resets state and re-logs. +func (s *supervisor) noteSignatureFailure(dirName, appID, hash string, verr error) { + s.sigMu.Lock() + rec, ok := s.sigFails[dirName] + if !ok || rec.hash != hash { + rec = &sigFailRecord{hash: hash, backoff: sigBackoffStart} + s.sigFails[dirName] = rec + } else { + rec.backoff = nextBackoff(rec.backoff, sigBackoffMax) + } + rec.fails++ + rec.nextRetry = time.Now().Add(rec.backoff) + firstForHash := !rec.logged + rec.logged = true + failsN := rec.fails + emitQuarantine := failsN >= sigQuarantineAfter && !rec.quarantined + if emitQuarantine { + rec.quarantined = true + } + s.sigMu.Unlock() + + if firstForHash { + s.logger.Printf("app=%s (%s): manifest signature verification failed: %v — deduping identical failures, retrying with backoff", appID, dirName, verr) + } + if emitQuarantine { + s.logger.Printf("app=%s (%s): quarantined after %d consecutive signature failures for manifest %s — retrying only on slow backoff until the manifest changes or is re-installed", appID, dirName, failsN, hash[:12]) + } +} + +// clearSignatureFailure drops any signature-failure state for dirName. +// Called when the signature verifies so a later transient failure starts +// fresh and re-logs. Emits a one-line recovery note only if the app was +// previously failing (keeps the happy path silent). +func (s *supervisor) clearSignatureFailure(dirName, appID string) { + s.sigMu.Lock() + _, existed := s.sigFails[dirName] + delete(s.sigFails, dirName) + s.sigMu.Unlock() + if existed { + s.logger.Printf("app=%s (%s): manifest signature now verifies — cleared signature quarantine", appID, dirName) + } +} + // scanInstalled walks InstallRoot, reads each `/manifest.json`, and // returns the verified-by-syntax set. Sha256 verification is per-launch // (in run()), not per-scan, so a corrupted binary surfaces at the right @@ -343,8 +453,19 @@ func (s *supervisor) scanInstalled() ([]*installedApp, error) { // to the release-signed catalogue: it must equal the publisher key // the catalogue pins for this app id. Both are required; sideloading // (above) is the explicit, local opt-out of this chain. + // + // Either check failing must NOT hot-loop: a skipped app is + // never registered, so it is re-examined on every rescan tick. + // We dedup the log by manifest hash, back off between + // re-verifications, and quarantine after repeated failures. + hash := sha256Hex(data) + if !s.shouldAttemptSignature(e.Name(), hash) { + // Still in backoff/quarantine for this exact manifest — + // skip silently (no re-verify, no log line). + continue + } if err := m.VerifySignature(); err != nil { - s.logger.Printf("skip %s: signature verification failed: %v", e.Name(), err) + s.noteSignatureFailure(e.Name(), m.ID, hash, err) continue } var cataloguePub string @@ -352,9 +473,13 @@ func (s *supervisor) scanInstalled() ([]*installedApp, error) { cataloguePub, _ = s.cfg.CataloguePublisher(m.ID) } if err := m.VerifyTrustAnchor(cataloguePub); err != nil { - s.logger.Printf("skip %s: publisher not trusted: %v", e.Name(), err) + s.noteSignatureFailure(e.Name(), m.ID, hash, err) continue } + // Full trust chain verified — clear any prior failure state + // so a fixed re-install is picked up cleanly and a later + // transient failure re-logs. + s.clearSignatureFailure(e.Name(), m.ID) } // Reject path traversal in manifest.binary.path. Without this // a manifest containing binary.path="../../../bin/sh" (or any diff --git a/plugin/appstore/zz5_sigstorm_test.go b/plugin/appstore/zz5_sigstorm_test.go new file mode 100644 index 0000000..db78b23 --- /dev/null +++ b/plugin/appstore/zz5_sigstorm_test.go @@ -0,0 +1,285 @@ +package appstore + +import ( + "bytes" + "crypto/ed25519" + "crypto/rand" + "crypto/sha256" + "encoding/base64" + "encoding/json" + "fmt" + "log" + "os" + "path/filepath" + "strings" + "testing" + "time" + + "github.com/pilot-protocol/app-store/pkg/manifest" +) + +// writeBadSigAppDir creates //manifest.json with a manifest +// that passes Parse + Validate but whose ed25519 signature does NOT +// verify: the payload is signed with a throwaway key that differs from +// the published publisher key. This is the exact shape that made +// scanInstalled log "signature verification failed" on every rescan +// tick. Returns the install-dir path. +func writeBadSigAppDir(t *testing.T, root, id string) string { + t.Helper() + dir := filepath.Join(root, id) + if err := os.MkdirAll(dir, 0o700); err != nil { + t.Fatalf("mkdir %s: %v", dir, err) + } + + // Published key (goes in the manifest) ... + pub, _, err := ed25519.GenerateKey(rand.Reader) + if err != nil { + t.Fatalf("generate publisher key: %v", err) + } + // ... but sign with a DIFFERENT key so verification fails. + _, wrongPriv, err := ed25519.GenerateKey(rand.Reader) + if err != nil { + t.Fatalf("generate wrong key: %v", err) + } + pubB64 := base64.StdEncoding.EncodeToString(pub) + + template := strings.NewReplacer("ID", id, "PUBKEY", pubB64).Replace(`{ + "id": "ID", + "manifest_version": 1, + "app_version": "0.0.0", + "protection": "shareable", + "binary": {"runtime": "go", "path": "bin/x", "sha256": "0123456789abcdef0123456789abcdef0123456789abcdef0123456789abcdef"}, + "exposes": ["ID.method"], + "grants": [ + {"cap": "fs.read", "target": "$APP/data.db"} + ], + "store": { + "publisher": "ed25519:PUBKEY", + "signature": "" + } + }`) + + m, err := manifest.Parse([]byte(template)) + if err != nil { + t.Fatalf("parse template: %v", err) + } + grantsJSON, _ := json.Marshal(m.Grants) + grantsHash := sha256.Sum256(grantsJSON) + payload := fmt.Sprintf("%s:%s:%d:%s:%x", + m.Store.Publisher, m.ID, m.ManifestVersion, m.Binary.SHA256, grantsHash) + sig := ed25519.Sign(wrongPriv, []byte(payload)) // wrong signer → fails verify + m.Store.Signature = base64.StdEncoding.EncodeToString(sig) + + raw, err := json.Marshal(m) + if err != nil { + t.Fatalf("marshal manifest: %v", err) + } + if err := os.WriteFile(filepath.Join(dir, "manifest.json"), raw, 0o644); err != nil { + t.Fatalf("write manifest: %v", err) + } + return dir +} + +// bufLogger returns a logger writing into buf, for asserting on emitted lines. +func bufLogger(buf *bytes.Buffer) *log.Logger { + return log.New(buf, "", 0) +} + +// sigTestConfig returns a Config that pins the catalogue publisher to the +// fixed test key, so a writeValidAppDir manifest passes the FULL trust +// chain (signature + trust anchor) on the catalogue path. +func sigTestConfig(root string) Config { + return Config{InstallRoot: root, CataloguePublisher: testCatPub} +} + +// TestSignatureFailure_NoLogStorm reproduces the bug: an app whose +// manifest signature fails verification used to be re-scanned and +// re-logged on every rescan tick (683k identical lines observed). With +// dedup + backoff the identical failure must be logged exactly once no +// matter how many rescans fire. +func TestSignatureFailure_NoLogStorm(t *testing.T) { + t.Parallel() + root := t.TempDir() + writeBadSigAppDir(t, root, "io.bad.sig") + + var buf bytes.Buffer + sup := newSupervisor(sigTestConfig(root), Deps{}, bufLogger(&buf)) + + // Simulate 200 rescan ticks in a tight loop (the hot loop). + const ticks = 200 + for i := 0; i < ticks; i++ { + apps, err := sup.scanInstalled() + if err != nil { + t.Fatalf("scan %d: %v", i, err) + } + if len(apps) != 0 { + t.Fatalf("scan %d returned %d apps; a bad-signature app must be skipped", i, len(apps)) + } + } + + got := strings.Count(buf.String(), "manifest signature verification failed") + if got != 1 { + t.Fatalf("signature-failure logged %d times over %d rescans; want exactly 1 (dedup)", got, ticks) + } + + // The app must be recorded as failing + throttled, not silently forgotten. + sup.sigMu.Lock() + rec, ok := sup.sigFails["io.bad.sig"] + sup.sigMu.Unlock() + if !ok { + t.Fatal("expected a sigFails record for the bad app") + } + if rec.fails != 1 { + // Only the first tick should have actually re-run VerifySignature; + // the remaining ticks are throttled by the backoff timer. + t.Fatalf("fails = %d; want 1 (subsequent ticks must be throttled, not re-verified)", rec.fails) + } + if sup.shouldAttemptSignature("io.bad.sig", rec.hash) { + t.Fatal("app should be in backoff (shouldAttemptSignature=false) right after a failure") + } +} + +// TestSignatureFailure_BackoffGrowsAndQuarantines forces re-verification +// (by expiring the backoff timer each round) and asserts: retries are +// throttled via growing backoff, the app is quarantined after +// sigQuarantineAfter consecutive failures, and — crucially — the failure +// is STILL logged only once because the manifest hash never changed. +func TestSignatureFailure_BackoffGrowsAndQuarantines(t *testing.T) { + t.Parallel() + root := t.TempDir() + writeBadSigAppDir(t, root, "io.bad.sig") + + var buf bytes.Buffer + sup := newSupervisor(sigTestConfig(root), Deps{}, bufLogger(&buf)) + + var lastBackoff time.Duration + for i := 0; i < sigQuarantineAfter+3; i++ { + if _, err := sup.scanInstalled(); err != nil { + t.Fatalf("scan %d: %v", i, err) + } + // Expire the backoff timer so the NEXT scan actually re-verifies. + sup.sigMu.Lock() + rec := sup.sigFails["io.bad.sig"] + if rec != nil { + if i > 0 && rec.backoff < lastBackoff { + t.Fatalf("backoff shrank at round %d: %s < %s", i, rec.backoff, lastBackoff) + } + lastBackoff = rec.backoff + rec.nextRetry = time.Now().Add(-time.Second) + } + sup.sigMu.Unlock() + } + + sup.sigMu.Lock() + rec := sup.sigFails["io.bad.sig"] + sup.sigMu.Unlock() + if rec == nil { + t.Fatal("missing sigFails record") + } + if !rec.quarantined { + t.Fatalf("app not quarantined after %d failures", rec.fails) + } + if rec.backoff <= sigBackoffStart { + t.Fatalf("backoff did not grow: %s", rec.backoff) + } + if got := strings.Count(buf.String(), "manifest signature verification failed"); got != 1 { + t.Fatalf("failure logged %d times; want 1 even across many retries (same hash)", got) + } + if got := strings.Count(buf.String(), "quarantined after"); got != 1 { + t.Fatalf("quarantine logged %d times; want exactly 1", got) + } +} + +// TestSignatureFailure_ChangedManifestReLogs asserts a NEW/changed +// manifest (different content hash) escapes the dedup: it re-attempts +// verification and re-logs, so a genuinely different bad manifest isn't +// masked by a previous one's quarantine. +func TestSignatureFailure_ChangedManifestReLogs(t *testing.T) { + t.Parallel() + root := t.TempDir() + writeBadSigAppDir(t, root, "io.bad.sig") + + var buf bytes.Buffer + sup := newSupervisor(sigTestConfig(root), Deps{}, bufLogger(&buf)) + + if _, err := sup.scanInstalled(); err != nil { + t.Fatalf("scan 1: %v", err) + } + // Rewrite the app with a fresh (still-bad) manifest → new content hash. + writeBadSigAppDir(t, root, "io.bad.sig") + if _, err := sup.scanInstalled(); err != nil { + t.Fatalf("scan 2: %v", err) + } + + if got := strings.Count(buf.String(), "manifest signature verification failed"); got != 2 { + t.Fatalf("changed manifest logged %d times; want 2 (a new hash must re-log)", got) + } +} + +// TestSignatureFailure_RecoveryClearsQuarantine asserts that once the +// full trust chain verifies (operator re-installs a properly signed, +// catalogue-pinned manifest), the quarantine state is cleared, a recovery +// line is emitted, and the app is admitted by scanInstalled. +func TestSignatureFailure_RecoveryClearsQuarantine(t *testing.T) { + t.Parallel() + root := t.TempDir() + writeBadSigAppDir(t, root, "io.fix.me") + + var buf bytes.Buffer + sup := newSupervisor(sigTestConfig(root), Deps{}, bufLogger(&buf)) + + if apps, err := sup.scanInstalled(); err != nil || len(apps) != 0 { + t.Fatalf("initial scan: apps=%d err=%v; want 0 apps skipped", len(apps), err) + } + sup.sigMu.Lock() + _, failing := sup.sigFails["io.fix.me"] + sup.sigMu.Unlock() + if !failing { + t.Fatal("expected failure record before recovery") + } + + // Operator re-installs with a valid, catalogue-pinned signature. + writeValidAppDir(t, root, "io.fix.me") + apps, err := sup.scanInstalled() + if err != nil { + t.Fatalf("recovery scan: %v", err) + } + if len(apps) != 1 { + t.Fatalf("recovery scan returned %d apps; want 1 (now admitted)", len(apps)) + } + sup.sigMu.Lock() + _, stillFailing := sup.sigFails["io.fix.me"] + sup.sigMu.Unlock() + if stillFailing { + t.Fatal("quarantine state not cleared after a successful verify") + } + if !strings.Contains(buf.String(), "signature now verifies") { + t.Fatal("expected a recovery log line") + } +} + +// TestTrustAnchorFailure_NoLogStorm covers the OTHER catalogue failure +// mode: a manifest with a valid self-signature but an untrusted publisher +// (fails VerifyTrustAnchor). It is skipped and re-examined every tick just +// like a bad signature, so it must also be deduped to a single log line. +func TestTrustAnchorFailure_NoLogStorm(t *testing.T) { + t.Parallel() + root := t.TempDir() + writeUntrustedSignedAppDir(t, root, "io.untrusted.pub") + + var buf bytes.Buffer + sup := newSupervisor(sigTestConfig(root), Deps{}, bufLogger(&buf)) + + for i := 0; i < 100; i++ { + apps, err := sup.scanInstalled() + if err != nil { + t.Fatalf("scan %d: %v", i, err) + } + if len(apps) != 0 { + t.Fatalf("scan %d returned %d apps; an untrusted-publisher app must be skipped", i, len(apps)) + } + } + if got := strings.Count(buf.String(), "manifest signature verification failed"); got != 1 { + t.Fatalf("trust-anchor failure logged %d times over 100 rescans; want exactly 1 (dedup)", got) + } +}