fix(auditdb): close four locker defects found reviewing the rework

Postgres re-acquisition only ever inserted, so an enrollment ID dropped from a
live anchor kept its lease row. AssertLocksHeld and the heartbeat's renewal both
count this replica's un-expired rows for the anchor and require exactly as many
as the session recorded, so each leftover row failed both: writes were rejected
with "locks lost before write", the heartbeat gave up on its first tick, and once
the TTL passed the abandoned lease became claimable while this replica still
believed it held it. The in-memory backend released it and had a test saying so,
but the conformance suite covered only the same-set and widening cases, so
nothing compared the two backends here.

The in-memory unlockAnchor sampled whether the anchor still held anything before
releasing the anchor's lock and acted on it after taking the map lock, leaving
room for a waiter to run a whole acquisition in between and this caller to evict
an anchor that did hold permits. Nothing could reach them afterwards, so every
later audit touching those IDs blocked until its own deadline for the lifetime of
the process.

A live anchor's enrollment-ID set may now shrink or stay the same but never grow;
widening fails with ErrLockSetWidened. Deadlock freedom rests on every caller
taking shared IDs in one canonical order, and that order can only be imposed over
the IDs of a single call — an anchor that keeps earlier permits while waiting for
new ones holds locks outside it, so two anchors widening into each other's IDs
waited on each other forever, and permanently, since AcquireLocks holds the
anchor's lock across the blocking acquisition and so blocked the ReleaseLocks
that would have broken the cycle. Audit acquires once per anchor, so no caller
needs to widen. store.go no longer claims that lock ordering alone prevents
deadlock, because for incremental acquisition it did not.

The in-memory locker also had no waiting budget of its own, so a caller with no
deadline blocked forever and no failure it produced could carry
ErrLockAcquireTimeout. It now bounds itself with acquireDeadline, defaulting to
the same minute as the Postgres backend.

In the auditor, isRetriableLockError read whether the caller was gone from the
error rather than from ctx. A locker's own budget elapsing with nothing contending
surfaces as a bare context.DeadlineExceeded, so that stopped the retry loop after
one attempt at exactly the transient database failures it exists to survive. The
lock-conflict counter is now incremented only for errors carrying
ErrLockContention, as the error-classification table already promised, so
shutdown cancellations and database outages no longer inflate the metric
operators alert on.

Each fix has a test verified to fail without it, including two new conformance
cases for the shrinking and rejected-widening halves of the refresh contract and
one that deliberately passes no caller deadline, which is what hid the missing
budget.

Signed-off-by: AkramBitar <akram@il.ibm.com>

Author: AkramBitar

docs/configuration.md

@@ -319,6 +319,16 @@ token:
           #   "memory"   – in-process mutex (default, single-replica only)
           #   "postgres" – PostgreSQL lease-table (multi-replica)
           backend: memory
+          # memory section is read only when backend == "memory".
+          memory:
+            # acquireDeadline bounds how long one acquisition waits for an EID held
+            # by another anchor. Every backend bounds its own waiting so that a
+            # caller which passes no deadline still gets an answer, and so that
+            # spending the whole budget can be reported as such; auditor.lock does
+            # not retry an acquisition that already exhausted it. Defaults to the
+            # same 1m as the postgres backend, so switching backends does not
+            # silently change how long an audit can block.
+            acquireDeadline: 1m
           # postgres section is read only when backend == "postgres".
           postgres:
             # ttl is the lease duration for each EID lock row.

docs/services/auditor.md

@@ -87,7 +87,11 @@ Both backends implement the same contract, defined on the `Locker` interface, be
 
 **`AssertLocksHeld` detects lost locks, not absent ones.** It fails only when a lease this replica held has since expired or been taken over. An anchor that holds nothing succeeds — whether because the request yielded no enrollment IDs, or because the caller never locked anything for it. The latter is a supported flow: an auditor may call `Validate` (which takes no locks) and then `Append`, as the dvp and nft sample views do.
 
-**`AcquireLocks` is all-or-nothing, and never gives up ground.** A failed call holds none of the EIDs it had reached for, and leaves untouched whatever the anchor already held from an earlier successful call. Re-acquiring under a live anchor is a refresh: the EIDs it already holds are kept, new ones are added, and ones it no longer needs are released. Acquiring an *empty* set is a successful acquisition of nothing — it must not, and does not, release what the anchor is already holding.
+**`AcquireLocks` is all-or-nothing, and never gives up ground.** A failed call holds none of the EIDs it had reached for, and leaves untouched whatever the anchor already held from an earlier successful call. Acquiring an *empty* set is a successful acquisition of nothing — it must not, and does not, release what the anchor is already holding.
+
+**Re-acquiring a live anchor may shrink its EID set, never grow it.** A refresh keeps the EIDs still named and releases the ones dropped from the set; naming an EID the anchor does not already hold fails with `ErrLockSetWidened`. That restriction is what keeps the lockers deadlock-free. Deadlock freedom rests on every caller taking shared EIDs in one canonical order, and that order can only be imposed over the EIDs of a single call — an anchor that keeps earlier locks while waiting for new ones is holding locks outside it, so two anchors widening into each other's EIDs wait on each other indefinitely. `Audit` acquires once per anchor and releases when done, so no caller needs to widen.
+
+**Each backend bounds its own waiting.** A caller that passes no deadline still gets an answer: the Postgres backend stops after `acquireDeadline`, and the in-memory backend after its own `acquireDeadline`. Without a budget of its own a backend could only ever stop when the caller's context did, and could never report `ErrLockAcquireTimeout` — the signal `auditor.Service` reads to tell "already waited in full" from "worth another attempt".
 
 **Release always runs.** `ReleaseLocks` is idempotent, safe on an anchor that never acquired anything, and safe to `defer`. Its statement is deliberately detached from the caller's context, since the usual case is a deferred release on a context that is already cancelled and a skipped release would leave the EIDs locked against every replica until the lease TTL expired. It carries its own short internal deadline so a stuck release cannot outlive the call that issued it.
 
@@ -100,10 +104,16 @@ Callers act on the outcome of a failed acquisition, so both backends classify it
 | Another anchor holds an EID and the waiting budget ran out | `ErrLockContention` + `ErrLockAcquireTimeout` | A real conflict, already waited out in full; retrying only adds delay |
 | Another anchor holds an EID, but a transient failure or a cancelled caller ended the wait | `ErrLockContention` | A real conflict, not yet waited out; a later attempt may succeed |
 | The caller cancelled or ran out of time while nothing held the EIDs | neither (plain context error) | Not a conflict, and not counted as one |
+| The backend's own waiting budget elapsed while nothing held the EIDs | neither (plain context error) | Not a conflict; worth retrying while the caller's context is still live |
+| The anchor asked for an EID it does not already hold | `ErrLockSetWidened` | A caller error, not a conflict: every attempt reproduces it |
 | The database failed | neither; the underlying error is preserved | An infrastructure fault, reported as itself rather than as contention |
 
 The distinction is drawn from whether an attempt actually lost a race for an EID — not from which context expired first. `acquireDeadline` defaults to a minute, so a request-scoped caller context is almost always the shorter of the two, and keying off it would mean the Postgres backend hardly ever reported contention in production.
 
+Only the two `ErrLockContention` rows count towards `auditor_audit_lock_conflicts_total`. The rows that are not conflicts are not counted as ones, so a graceful-shutdown cancellation or a database outage does not inflate the metric operators alert on for contention.
+
+Whether another attempt is worth making is read from the caller's context rather than from the error, because the two rows carrying a plain context error are indistinguishable by the error alone: the caller having given up is final, whereas the backend's own budget elapsing is exactly the transient case `auditor.lock` exists to retry. See `isRetriableLockError`.
+
 ### Configuration
 
 Configure under `token.tms.<name>.auditor.locker` (see [Configuration](../configuration.md#optional-tokentmsauditorlocker)):

token/services/auditor/auditor.go

@@ -178,7 +178,13 @@ func (a *Service) Audit(ctx context.Context, tx Transaction) (*token.InputStream
 	// Acquire locks with retry and exponential backoff to prevent livelock
 	logger.DebugfContext(ctx, "audit transaction [%s], acquire locks with retry", tx.ID())
 	if err := a.acquireLocksWithRetry(ctx, string(request.Anchor), eids); err != nil {
-		a.metrics.AuditLockConflicts.Add(1)
+		// Only a genuine conflict counts towards the conflict metric. Counting every
+		// failure meant a graceful-shutdown cancellation or a database outage — neither
+		// of which involves a second holder — inflated the one signal operators are
+		// told to alert on for contention.
+		if errors.Is(err, auditdb.ErrLockContention) {
+			a.metrics.AuditLockConflicts.Add(1)
+		}
 
 		return nil, nil, err
 	}
@@ -219,7 +225,7 @@ func (a *Service) acquireLocksWithRetry(ctx context.Context, anchor string, eids
 			return true, nil
 		}
 
-		return !isRetriableLockError(err), err
+		return !isRetriableLockError(ctx, err), err
 	})
 	if err != nil {
 		return errors.WithMessagef(err, "failed to acquire locks for anchor [%s]", anchor)
@@ -230,13 +236,26 @@ func (a *Service) acquireLocksWithRetry(ctx context.Context, anchor string, eids
 
 // isRetriableLockError reports whether re-running AcquireLocks stands a chance of
 // a different outcome. Most failures do — a contended lock may be free by now, a
-// database blip may have passed — but two do not: ErrLockAcquireTimeout means the
-// locker already spent its whole waiting budget, so an identical attempt would
-// just spend it again, and a context error means the caller is no longer waiting.
-func isRetriableLockError(err error) bool {
+// database blip may have passed — but three do not: ErrLockAcquireTimeout means
+// the locker already spent its whole waiting budget, so an identical attempt would
+// just spend it again; ErrLockSetWidened is a caller error that every attempt will
+// reproduce; and a caller whose own context is done is no longer waiting for an
+// answer.
+//
+// Whether the caller is gone is read from ctx, not from the error. The lockers
+// bound their own waiting, and a budget of their own that elapses with nothing
+// contending surfaces as a bare context.DeadlineExceeded — indistinguishable, by
+// the error alone, from the caller's deadline elapsing. Classifying it from the
+// error stopped the auditor after a single attempt at exactly the transient
+// database failures this retry exists to survive, while ctx was still perfectly
+// live.
+func isRetriableLockError(ctx context.Context, err error) bool {
+	if ctx.Err() != nil {
+		return false
+	}
+
 	return !errors.Is(err, auditdb.ErrLockAcquireTimeout) &&
-		!errors.Is(err, context.Canceled) &&
-		!errors.Is(err, context.DeadlineExceeded)
+		!errors.Is(err, auditdb.ErrLockSetWidened)
 }
 
 // Append adds the passed transaction to the auditor database, reusing the

token/services/auditor/auditor_test.go

@@ -14,6 +14,8 @@ import (
 	"time"
 
 	"github.com/LFDT-Panurus/panurus/token"
+	commondrivermock "github.com/LFDT-Panurus/panurus/token/core/common/driver/mock"
+	"github.com/LFDT-Panurus/panurus/token/core/common/metrics"
 	drivermock "github.com/LFDT-Panurus/panurus/token/driver/mock"
 	tokenmock "github.com/LFDT-Panurus/panurus/token/mock"
 	"github.com/LFDT-Panurus/panurus/token/services/auditor"
@@ -1222,3 +1224,184 @@ func TestService_AcquireLocksWithRetry_EmptyEnrollmentIDs(t *testing.T) {
 	require.NoError(t, err)
 	assert.Equal(t, 1, mockLocker.GetCallCount())
 }
+
+// newTestServiceWithMockLockerAndMetrics is newTestServiceWithMockLocker with a
+// metrics provider the caller can read back.
+func newTestServiceWithMockLockerAndMetrics(
+	t *testing.T, mockLocker *mockAuditLocker, mp metrics.Provider,
+) *auditor.Service {
+	t.Helper()
+
+	fakeStore := newFakeStore()
+	storeService, err := auditdb.NewStoreService(fakeStore, auditdb.WithLocker(mockLocker))
+	require.NoError(t, err)
+
+	return auditor.NewService(
+		token.TMSID{},
+		nil, // networkProvider
+		storeService,
+		nil, // tokenDB
+		nil, // tmsProvider
+		nil, // finalityTracer
+		mp,
+		nil, // checkService
+		nil, // lockConfig (uses defaults)
+	)
+}
+
+// countingCounter records the total added, so a test can assert on whether a
+// metric was touched at all.
+type countingCounter struct {
+	mu    sync.Mutex
+	total float64
+}
+
+func (c *countingCounter) With(...string) metrics.Counter { return c }
+
+func (c *countingCounter) Add(delta float64) {
+	c.mu.Lock()
+	defer c.mu.Unlock()
+	c.total += delta
+}
+
+func (c *countingCounter) Total() float64 {
+	c.mu.Lock()
+	defer c.mu.Unlock()
+
+	return c.total
+}
+
+// lockConflictProvider hands out countingCounter for the lock-conflict metric and
+// discards everything else.
+func lockConflictProvider() (metrics.Provider, *countingCounter) {
+	conflicts := &countingCounter{}
+	mp := &commondrivermock.MetricsProvider{}
+	mp.NewCounterStub = func(opts metrics.CounterOpts) metrics.Counter {
+		if opts.Name == "auditor_audit_lock_conflicts_total" {
+			return conflicts
+		}
+
+		return &countingCounter{}
+	}
+	mp.NewHistogramStub = func(metrics.HistogramOpts) metrics.Histogram { return discardHistogram{} }
+	mp.NewGaugeStub = func(metrics.GaugeOpts) metrics.Gauge { return discardGauge{} }
+
+	return mp, conflicts
+}
+
+type discardHistogram struct{}
+
+func (discardHistogram) With(...string) metrics.Histogram { return discardHistogram{} }
+func (discardHistogram) Observe(float64)                  {}
+
+type discardGauge struct{}
+
+func (discardGauge) With(...string) metrics.Gauge { return discardGauge{} }
+func (discardGauge) Add(float64)                  {}
+func (discardGauge) Set(float64)                  {}
+
+// TestService_AcquireLocksWithRetry_RetriesTransientFailureWithLiveCaller covers
+// the classification of a failure that carries a context error but did not come
+// from the caller giving up. When a locker's own acquisition budget elapses with
+// nothing contending, it returns a bare context.DeadlineExceeded and no sentinel —
+// see the Postgres backend's default branch. Deciding from the error alone made
+// that final, so the auditor stopped after one attempt at exactly the transient
+// database failures this retry exists to survive, while its own context was still
+// perfectly live. Whether the caller is gone is a property of ctx, not of the
+// error.
+func TestService_AcquireLocksWithRetry_RetriesTransientFailureWithLiveCaller(t *testing.T) {
+	attempts := 0
+	mockLocker := newMockAuditLocker(func(context.Context, string, ...string) error {
+		attempts++
+		if attempts < 3 {
+			return errors.Wrap(context.DeadlineExceeded, "acquire eid leases")
+		}
+
+		return nil
+	})
+	svc := newTestServiceWithMockLocker(t, mockLocker)
+
+	_, _, err := svc.Audit(context.Background(), &auditmock.Transaction{
+		IDStub: func() string { return "tx-lock-transient" },
+		RequestStub: func() *token.Request {
+			return token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-lock-transient"))
+		},
+	})
+
+	require.NoError(t, err)
+	assert.Equal(t, 3, mockLocker.GetCallCount(),
+		"a locker whose own budget elapsed must be retried while the caller is still waiting")
+}
+
+// TestService_AcquireLocksWithRetry_StopsWhenCallerIsGone is the other half: once
+// the caller's context is done there is nobody left to hand the locks to, so the
+// loop must stop regardless of what the error says.
+func TestService_AcquireLocksWithRetry_StopsWhenCallerIsGone(t *testing.T) {
+	ctx, cancel := context.WithCancel(context.Background())
+	// Contention is the most retriable failure there is, so this pins the decision on
+	// the caller having gone rather than on the error. The cancellation happens
+	// inside the first attempt, so the retry loop does reach the locker once.
+	mockLocker := newMockAuditLocker(func(context.Context, string, ...string) error {
+		cancel()
+
+		return auditdb.ErrLockContention
+	})
+	svc := newTestServiceWithMockLocker(t, mockLocker)
+
+	_, _, err := svc.Audit(ctx, &auditmock.Transaction{
+		IDStub: func() string { return "tx-lock-caller-gone" },
+		RequestStub: func() *token.Request {
+			return token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-lock-caller-gone"))
+		},
+	})
+
+	require.Error(t, err)
+	assert.Equal(t, 1, mockLocker.GetCallCount(), "a cancelled caller must not be retried for")
+}
+
+// TestService_Audit_CountsOnlyRealLockConflicts pins the lock-conflict metric to
+// what the error-classification table in docs/services/auditor.md promises: a
+// failure with no second holder involved is "not a conflict, and not counted as
+// one". The counter was incremented for every acquisition failure, so
+// graceful-shutdown cancellations and database outages inflated the one signal
+// operators are told to alert on for contention.
+func TestService_Audit_CountsOnlyRealLockConflicts(t *testing.T) {
+	t.Run("contention is counted", func(t *testing.T) {
+		mp, conflicts := lockConflictProvider()
+		mockLocker := newMockAuditLocker(func(context.Context, string, ...string) error {
+			return errors.Join(auditdb.ErrLockContention, auditdb.ErrLockAcquireTimeout)
+		})
+		svc := newTestServiceWithMockLockerAndMetrics(t, mockLocker, mp)
+
+		_, _, err := svc.Audit(context.Background(), &auditmock.Transaction{
+			IDStub: func() string { return "tx-conflict" },
+			RequestStub: func() *token.Request {
+				return token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-conflict"))
+			},
+		})
+
+		require.Error(t, err)
+		assert.InDelta(t, 1, conflicts.Total(), 0)
+	})
+
+	t.Run("a cancelled caller is not counted", func(t *testing.T) {
+		mp, conflicts := lockConflictProvider()
+		mockLocker := newMockAuditLocker(func(ctx context.Context, _ string, _ ...string) error {
+			return ctx.Err()
+		})
+		svc := newTestServiceWithMockLockerAndMetrics(t, mockLocker, mp)
+
+		ctx, cancel := context.WithCancel(context.Background())
+		cancel()
+		_, _, err := svc.Audit(ctx, &auditmock.Transaction{
+			IDStub: func() string { return "tx-cancelled" },
+			RequestStub: func() *token.Request {
+				return token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-cancelled"))
+			},
+		})
+
+		require.Error(t, err)
+		assert.Zero(t, conflicts.Total(),
+			"nothing held the enrollment IDs, so the failure is not a lock conflict")
+	})
+}

token/services/auditor/metrics.go

@@ -16,8 +16,11 @@ type Metrics struct {
 	// invocation (lock acquisition included), in seconds.
 	AuditDuration metrics.Histogram
 
-	// AuditLockConflicts counts calls to Audit() that failed because
-	// AcquireLocks returned an error (e.g. contention or timeout).
+	// AuditLockConflicts counts calls to Audit() that failed because another
+	// anchor held one of the enrollment IDs, i.e. those whose error carries
+	// ErrLockContention. Failures with no second holder involved — a cancelled
+	// caller, a database outage — are not conflicts and are deliberately not
+	// counted here, so that alerting on this metric measures contention only.
 	AuditLockConflicts metrics.Counter
 
 	// AppendDuration is a histogram of the total wall-clock time for each

token/services/storage/auditdb/locker.go

@@ -29,6 +29,7 @@ var (
 	ErrLockAcquireTimeout  = locker.ErrLockAcquireTimeout
 	ErrLockLost            = locker.ErrLockLost
 	ErrLockNotHeld         = locker.ErrLockNotHeld
+	ErrLockSetWidened      = locker.ErrLockSetWidened
 	ErrLockerOwnerRequired = locker.ErrLockerOwnerRequired
 )
 

token/services/storage/auditdb/locker/config.go

@@ -9,6 +9,7 @@ package locker
 import (
 	"time"
 
+	"github.com/LFDT-Panurus/panurus/token/services/storage/auditdb/locker/memory"
 	lockerpostgres "github.com/LFDT-Panurus/panurus/token/services/storage/auditdb/locker/postgres"
 )
 
@@ -24,6 +25,7 @@ const (
 // It is read from the TMS configuration under the key "auditor.locker".
 type Config struct {
 	Backend  Backend               `yaml:"backend"`
+	Memory   memory.Config         `yaml:"memory"`
 	Postgres lockerpostgres.Config `yaml:"postgres"`
 }
 
@@ -32,6 +34,9 @@ type Config struct {
 func DefaultConfig() Config {
 	return Config{
 		Backend: BackendMemory,
+		Memory: memory.Config{
+			AcquireDeadline: memory.DefaultAcquireDeadline,
+		},
 		Postgres: lockerpostgres.Config{
 			TTL:             30 * time.Second,
 			AcquireBackoff:  100 * time.Millisecond,