diff --git a/.context/TASKS.md b/.context/TASKS.md index ca443972..1cce02aa 100644 --- a/.context/TASKS.md +++ b/.context/TASKS.md @@ -38,15 +38,17 @@ the name-based policy work. - [x] Fix broken CI integration test #source:jira.xml #added:2026-07-14 #done:2026-07-16 (stale: CI has been green for several weeks; closed on user confirmation) - [x] Fix broken recovery/restore flow #source:jira.xml #added:2026-07-14 #done:2026-07-16 (the drill exposed a real boot-order deadlock: an un-initialized Nexus never started its listener, so the emergency restore route was unreachable when every Keeper died; fixed by recovering from Keepers in the background, and the recovery loop now stands down once an operator restore supplies the root key. Verified live by make drill-recovery) - [x] Fix `spike cipher` stream mode (broken; owner: Murat); JSON mode fix unblocks encryption-as-a-service demo/docs #source:jira.xml #added:2026-07-14 #done:2026-07-15 (stale: both cipher streaming and file modes verified passing via the make start checks on 2026-07-15) -- [ ] Retry sqlite operations with exponential backoff on transient locks (all of `app/nexus/internal/state/persist`) → ideas/research-db-resilience.md #source:jira.xml #added:2026-07-14 -- [ ] Bound the Bootstrap keeper-wait loop with a configurable timeout/max-attempts instead of looping forever → ideas/research-db-resilience.md #source:jira.xml #added:2026-07-14 -- [ ] Make `env` accessors return sentinel errors instead of calling `log.FatalLn` (removes env→log circular dep, makes them testable) → ideas/research-env-error-handling.md #source:jira.xml #added:2026-07-14 +- [x] Retry sqlite operations with exponential backoff on transient locks → ideas/research-db-resilience.md #source:jira.xml #added:2026-07-14 #done:2026-07-16 (withSerializableTx retries SQLITE_BUSY/SQLITE_LOCKED with exponential backoff at the single choke point every write flows through; reads rely on WAL plus the busy_timeout DSN parameter and honor the operation deadline; note the DB ops live under state/backend/sqlite/persist these days, not state/persist) +- [x] Bound the Bootstrap keeper-wait loop with a configurable timeout/max-attempts instead of looping forever → ideas/research-db-resilience.md #source:jira.xml #added:2026-07-14 #done:2026-07-16 (stale: superseded by the SDK retry migration; broadcastToKeeper bounds each keeper with retry.WithMaxAttempts, a per-keeper context timeout, and configurable backoff intervals — app/bootstrap/internal/net/dispatch.go — and broadcast.go bounds init verification with WithMaxElapsedTime) +- [ ] Make `env` accessors return sentinel errors instead of calling `log.FatalLn` (removes env→log circular dep, makes them testable) → ideas/research-env-error-handling.md #source:jira.xml #added:2026-07-14 (2026-07-16: the offending accessors now live in spike-sdk-go config/env, so the sentinel-error refactor is an upstream SDK change; the in-repo share is adapting callers once the SDK ships it) +- [ ] Fix Pilot printing normal output to stderr: cobra Print* writes to OutOrStderr and the root command never calls SetOut, so data output (secrets included) lands on stderr and `spike secret get x > file.txt` yields an empty file; every harness script compensates with 2>&1. Set the root command output writer to stdout and audit scripts/docs for reliance on the old behavior. #added:2026-07-16 ### Phase 2: SDK Extraction `#priority:medium` - [ ] Graduate generic internal helpers to spike-sdk-go (nonce/crypto, Shamir verify, permission (de)serialize, validation, trust/spiffeid, URL builders, `GCMNonceSize`, `Id()`, canonical permission set) → ideas/research-sdk-extraction.md #source:jira.xml #added:2026-07-14 ### Phase 3: Testing `#priority:medium` - [ ] Make `make test` concurrent again (currently serialized by env setup) → ideas/research-cli-testing.md #source:jira.xml #added:2026-07-14 +- [ ] Move the sqlite state tests off the real ~/.spike/data/spike.db to t.TempDir(): make test deletes the live dev environment database mid-run (bit us twice on 2026-07-15 and 2026-07-16), and shared global state is part of why tests are serialized with -p 1. #added:2026-07-16 - [ ] Add integration tests: root key cached/recovered/not-re-initialized; secret & policy CRUD; Pilot denies when Nexus uninitialized / warns when unreachable → ideas/research-cli-testing.md #source:jira.xml #added:2026-07-14 - [ ] Raise CLI command coverage to 60%+ via unit + HTTP-mock tests; fix `t.Skip()`ed tests; DI-refactor `sendShardsToKeepers` → ideas/research-cli-testing.md #source:jira.xml #added:2026-07-14 - [x] `start.sh` should exercise recovery/restore and encryption/decryption #source:jira.xml #added:2026-07-14 #done:2026-07-16 (encryption/decryption checks live in start.sh since the policy-validation rework; recovery/restore is exercised by make drill-recovery, kept as a separate second-terminal script deliberately so the crash simulation never runs inside the normal startup path) @@ -60,7 +62,7 @@ the name-based policy work. - [ ] Refactor `app/spike/internal/cmd/secret/get.go` to extract the repeated marshal-and-print helpers #source:jira.xml #added:2026-07-14 ### Phase 5: Ops & Config `#priority:low` -- [ ] Wire the SDK's `env.DatabaseOperationTimeoutVal()` (spike-sdk-go config/env/database.go) into the Nexus DB path; SPIKE does not call it yet → ideas/research-db-resilience.md #source:jira.xml #added:2026-07-14 (retargeted 2026-07-14: the old in-repo accessor was removed and the accessor now lives in the SDK) +- [x] Wire the SDK's `env.DatabaseOperationTimeoutVal()` (spike-sdk-go config/env/database.go) into the Nexus DB path → ideas/research-db-resilience.md #source:jira.xml #added:2026-07-14 #done:2026-07-16 (wired as a context deadline via operationContext in the sqlite persist layer: writes through withSerializableTx and all four read entry points honor SPIKE_NEXUS_DB_OPERATION_TIMEOUT, default 15s) - [-] Move `const maxShardID = 1000` to env-var configuration #source:jira.xml #added:2026-07-14 #skipped:2026-07-14 (obsolete: the constant no longer exists anywhere in the repo or SDK) - [ ] Add a configurable SVID-source acquisition timeout (go-spiffe context) so lookups don't wait forever #source:jira.xml #added:2026-07-14 - [ ] Add a Nexus `/status` endpoint; Pilot warns when Nexus not ready; Bootstrap uses it instead of the k8s Jobs API #source:jira.xml #added:2026-07-14 diff --git a/app/nexus/internal/state/backend/sqlite/persist/dbretry.go b/app/nexus/internal/state/backend/sqlite/persist/dbretry.go new file mode 100644 index 00000000..663ce07a --- /dev/null +++ b/app/nexus/internal/state/backend/sqlite/persist/dbretry.go @@ -0,0 +1,69 @@ +// \\ SPIKE: Secure your secrets with SPIFFE. — https://spike.ist/ +// \\\\\ Copyright 2024-present SPIKE contributors. +// \\\\\\\ SPDX-License-Identifier: Apache-2.0 + +package persist + +import ( + "context" + "strings" + "time" + + "github.com/spiffe/spike-sdk-go/config/env" +) + +// Retry pacing for transient SQLite failures. The overall duration is +// bounded by the operation deadline (see operationContext), so these +// values only shape how densely attempts are packed inside that window. +const ( + dbRetryInitialInterval = 100 * time.Millisecond + dbRetryMaxInterval = 2 * time.Second +) + +// operationContext bounds a database operation with the configured +// SPIKE_NEXUS_DB_OPERATION_TIMEOUT deadline. A zero or negative timeout +// disables the deadline, in which case the parent context is returned +// unchanged with a no-op cancel function. +// +// Parameters: +// - ctx: The parent context. +// +// Returns: +// - context.Context: The possibly deadline-bound context. +// - context.CancelFunc: The cancel function; callers must defer it. +func operationContext( + ctx context.Context, +) (context.Context, context.CancelFunc) { + timeout := env.DatabaseOperationTimeoutVal() + if timeout <= 0 { + return ctx, func() {} + } + return context.WithTimeout(ctx, timeout) +} + +// transientDBError reports whether err is a transient SQLite failure +// (SQLITE_BUSY or SQLITE_LOCKED) that is worth retrying. These surface +// when a competing transaction holds the database lock for longer than +// the driver's busy timeout. Anything else is treated as permanent. +// +// The check matches the driver's error strings rather than its typed +// error codes: the typed API (sqlite3.Error) only compiles with cgo, +// and the repository's lint pass runs with CGO_ENABLED=0. Error +// messages survive SDKError wrapping, so the whole chain is covered. +// +// Parameters: +// - err: The error to inspect. May be nil. +// +// Returns: +// - bool: true if the error is a transient SQLite lock error. +func transientDBError(err error) bool { + if err == nil { + return false + } + + // SQLITE_BUSY renders as "database is locked" and SQLITE_LOCKED as + // "database table is locked" in the mattn/go-sqlite3 driver. + msg := err.Error() + return strings.Contains(msg, "database is locked") || + strings.Contains(msg, "database table is locked") +} diff --git a/app/nexus/internal/state/backend/sqlite/persist/dbretry_test.go b/app/nexus/internal/state/backend/sqlite/persist/dbretry_test.go new file mode 100644 index 00000000..a24bdf79 --- /dev/null +++ b/app/nexus/internal/state/backend/sqlite/persist/dbretry_test.go @@ -0,0 +1,148 @@ +// \\ SPIKE: Secure your secrets with SPIFFE. — https://spike.ist/ +// \\\\\ Copyright 2024-present SPIKE contributors. +// \\\\\\\ SPDX-License-Identifier: Apache-2.0 + +package persist + +import ( + "context" + "database/sql" + "errors" + "testing" + + "github.com/spiffe/spike-sdk-go/config/env" + sdkErrors "github.com/spiffe/spike-sdk-go/errors" +) + +func newMemoryDataStore(t *testing.T) *DataStore { + db, openErr := sql.Open("sqlite3", ":memory:") + if openErr != nil { + t.Fatalf("failed to open an in-memory database: %v", openErr) + return nil + } + t.Cleanup(func() { _ = db.Close() }) + return &DataStore{db: db} +} + +// busyErr mimics how a SQLITE_BUSY failure ("database is locked" in the +// mattn/go-sqlite3 driver) surfaces from the persist layer: wrapped in +// an SDKError chain. +func busyErr() *sdkErrors.SDKError { + return sdkErrors.ErrEntityQueryFailed.Wrap( + errors.New("database is locked"), + ) +} + +func TestTransientDBError(t *testing.T) { + tests := []struct { + name string + err error + want bool + }{ + { + name: "raw busy error", + err: errors.New("database is locked"), + want: true, + }, + { + name: "raw locked error", + err: errors.New("database table is locked"), + want: true, + }, + { + name: "SDKError-wrapped busy error", + err: busyErr(), + want: true, + }, + { + name: "other sqlite error", + err: errors.New("UNIQUE constraint failed: policies.name"), + want: false, + }, + { + name: "plain error", + err: errors.New("boom"), + want: false, + }, + { + name: "nil error", + err: nil, + want: false, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + if got := transientDBError(tt.err); got != tt.want { + t.Errorf("transientDBError() = %v, want %v", got, tt.want) + } + }) + } +} + +func TestWithSerializableTx_RetriesTransientErrors(t *testing.T) { + s := newMemoryDataStore(t) + + attempts := 0 + err := s.withSerializableTx(context.Background(), "test", + func(_ *sql.Tx) *sdkErrors.SDKError { + attempts++ + if attempts < 3 { + return busyErr() + } + return nil + }) + + if err != nil { + t.Fatalf("expected success after retries, got: %v", err) + return + } + if attempts != 3 { + t.Errorf("expected 3 attempts, got %d", attempts) + } +} + +func TestWithSerializableTx_PermanentErrorDoesNotRetry(t *testing.T) { + s := newMemoryDataStore(t) + + permanent := sdkErrors.ErrEntityInvalid.Clone() + attempts := 0 + err := s.withSerializableTx(context.Background(), "test", + func(_ *sql.Tx) *sdkErrors.SDKError { + attempts++ + return permanent + }) + + if err == nil { + t.Fatal("expected the permanent error to surface") + return + } + if !err.Is(sdkErrors.ErrEntityInvalid) { + t.Errorf("expected ErrEntityInvalid, got: %v", err) + } + if attempts != 1 { + t.Errorf("expected exactly 1 attempt, got %d", attempts) + } +} + +func TestWithSerializableTx_TimeoutBoundsRetries(t *testing.T) { + t.Setenv(env.NexusDBOperationTimeout, "300ms") + + s := newMemoryDataStore(t) + + attempts := 0 + err := s.withSerializableTx(context.Background(), "test", + func(_ *sql.Tx) *sdkErrors.SDKError { + attempts++ + return busyErr() + }) + + if err == nil { + t.Fatal("expected an error once the operation deadline expired") + return + } + if attempts < 2 { + t.Errorf("expected at least 2 attempts before the deadline,"+ + " got %d", attempts) + } +} diff --git a/app/nexus/internal/state/backend/sqlite/persist/policy.go b/app/nexus/internal/state/backend/sqlite/persist/policy.go index b8014f8e..c4df40bb 100644 --- a/app/nexus/internal/state/backend/sqlite/persist/policy.go +++ b/app/nexus/internal/state/backend/sqlite/persist/policy.go @@ -149,6 +149,9 @@ func (s *DataStore) LoadPolicy( validation.NonNilContextOrDie(ctx, fName) + ctx, cancel := operationContext(ctx) + defer cancel() + s.mu.RLock() defer s.mu.RUnlock() @@ -246,6 +249,9 @@ func (s *DataStore) LoadAllPolicies( validation.NonNilContextOrDie(ctx, fName) + ctx, cancel := operationContext(ctx) + defer cancel() + s.mu.RLock() defer s.mu.RUnlock() diff --git a/app/nexus/internal/state/backend/sqlite/persist/secret.go b/app/nexus/internal/state/backend/sqlite/persist/secret.go index 13d3a9f0..1efbb99d 100644 --- a/app/nexus/internal/state/backend/sqlite/persist/secret.go +++ b/app/nexus/internal/state/backend/sqlite/persist/secret.go @@ -228,6 +228,9 @@ func (s *DataStore) LoadAllSecrets( validation.NonNilContextOrDie(ctx, fName) + ctx, cancel := operationContext(ctx) + defer cancel() + s.mu.RLock() defer s.mu.RUnlock() diff --git a/app/nexus/internal/state/backend/sqlite/persist/secret_load.go b/app/nexus/internal/state/backend/sqlite/persist/secret_load.go index cbbf7dfe..c77e82b2 100644 --- a/app/nexus/internal/state/backend/sqlite/persist/secret_load.go +++ b/app/nexus/internal/state/backend/sqlite/persist/secret_load.go @@ -62,6 +62,9 @@ func (s *DataStore) loadSecretInternal( validation.NonNilContextOrDie(ctx, fName) + ctx, cancel := operationContext(ctx) + defer cancel() + var secret kv.Value var ( nonce []byte diff --git a/app/nexus/internal/state/backend/sqlite/persist/tx.go b/app/nexus/internal/state/backend/sqlite/persist/tx.go index 60e19fcb..4eb02000 100644 --- a/app/nexus/internal/state/backend/sqlite/persist/tx.go +++ b/app/nexus/internal/state/backend/sqlite/persist/tx.go @@ -10,15 +10,23 @@ import ( sdkErrors "github.com/spiffe/spike-sdk-go/errors" "github.com/spiffe/spike-sdk-go/log" + "github.com/spiffe/spike-sdk-go/retry" "github.com/spiffe/spike-sdk-go/validation" ) // withSerializableTx executes fn within a serializable transaction. // It handles begin, commit, and automatic rollback on error. // -// The function acquires a write lock on the DataStore for the duration of the -// transaction to ensure thread safety. The transaction uses serializable -// isolation level for strict consistency. +// The function acquires a write lock on the DataStore for the duration of +// the transaction to ensure thread safety. The transaction uses +// serializable isolation level for strict consistency. +// +// SQLite can fail transiently (SQLITE_BUSY, SQLITE_LOCKED) when a +// competing transaction holds the database lock for longer than the +// driver's busy timeout, so the whole begin-execute-commit cycle is +// retried with exponential backoff for those errors. All other errors +// surface immediately. The overall operation is bounded by the +// SPIKE_NEXUS_DB_OPERATION_TIMEOUT deadline. // // Parameters: // - ctx: Context for the database operation @@ -27,7 +35,8 @@ import ( // // Returns: // - *sdkErrors.SDKError: nil on success, or an error if transaction -// operations fail or fn returns an error +// operations fail, fn returns a permanent error, or the retries are +// exhausted func (s *DataStore) withSerializableTx( ctx context.Context, fName string, @@ -38,6 +47,57 @@ func (s *DataStore) withSerializableTx( s.mu.Lock() defer s.mu.Unlock() + opCtx, cancel := operationContext(ctx) + defer cancel() + + var permanentErr *sdkErrors.SDKError + _, retryErr := retry.Do(opCtx, func() (bool, *sdkErrors.SDKError) { + txErr := s.attemptSerializableTx(opCtx, fName, fn) + if txErr == nil { + return true, nil + } + + if transientDBError(txErr) { + warnErr := *txErr.Clone() + warnErr.Msg = "transient SQLite error: will retry" + log.WarnErr(fName, warnErr) + return false, txErr + } + + // A permanent error: capture it and stop the retrier. Returning + // success here only ends the retry loop; the captured error is + // what the caller receives. + permanentErr = txErr + return true, nil + }, + retry.WithBackOffOptions( + retry.WithInitialInterval(dbRetryInitialInterval), + retry.WithMaxInterval(dbRetryMaxInterval), + ), + ) + + if permanentErr != nil { + return permanentErr + } + return retryErr +} + +// attemptSerializableTx runs a single begin-execute-commit attempt. The +// caller must hold the DataStore write lock. +// +// Parameters: +// - ctx: Context for the database operation +// - fName: Function name for logging purposes +// - fn: The work to execute within the transaction +// +// Returns: +// - *sdkErrors.SDKError: nil on success, or an error if transaction +// operations fail or fn returns an error +func (s *DataStore) attemptSerializableTx( + ctx context.Context, + fName string, + fn func(tx *sql.Tx) *sdkErrors.SDKError, +) *sdkErrors.SDKError { tx, beginErr := s.db.BeginTx( ctx, &sql.TxOptions{Isolation: sql.LevelSerializable}, )