Skip to content

Commit 891263a

Browse files
committed
fix(storage): align keystore cleanup semantics, error chains and facade tests (#2045)
Signed-off-by: AkramBitar <akram@il.ibm.com>
1 parent 1025c2c commit 891263a

12 files changed

Lines changed: 360 additions & 25 deletions

File tree

cmd/skicleanup/cobra/signers/runner.go

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,8 @@ func Run(ctx context.Context, stores *Stores, batchSize int) error {
3434
extractor := cleanup.NewSKIExtractor()
3535
extractor.RegisterProvider(idemix.IdentityTypeString, idemix.NewSKIProvider())
3636
extractor.RegisterProvider(idemixnym.IdentityTypeString, idemixnym.NewSKIProvider(stores.Identity))
37+
// X.509 deliberately derives no SKIs, so orphaned X.509 signers report no keys to delete:
38+
// an X.509 key belongs to the wallet, not to a single token. See cleanup.NoopSKIProvider.
3739
extractor.RegisterProvider(x509.IdentityTypeString, cleanup.NewNoopSKIProvider())
3840

3941
var s stats

docs/services/storage/keystore_cleanup.md

Lines changed: 52 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -53,14 +53,16 @@ The SKI (Subject Key Identifier) extraction system uses a pluggable provider arc
5353
3. **Built-in Providers**:
5454
- **IdemixSKIProvider**: Extracts SKI from Idemix NymPublicKey
5555
- **IdemixNymSKIProvider**: Extracts SKI from Idemix pseudonym identities
56-
- **NoopSKIProvider**: Returns empty SKI list (used for X.509)
56+
- **NoopSKIProvider**: Derives no SKIs, marking an identity type as deliberately excluded from
57+
cleanup. Registered for X.509 — see [X.509 is intentionally out of scope](#x509-is-intentionally-out-of-scope)
5758
- **FallbackSKIProvider**: Computes SHA256 hash of identity bytes as SKI (default)
5859

5960
**Provider Registration:**
6061
```go
6162
extractor := NewSKIExtractor()
6263
extractor.RegisterProvider("idemix", idemix.NewSKIProvider())
6364
extractor.RegisterProvider("idemixnym", idemixnym.NewSKIProvider(identityStore))
65+
// X.509 keys belong to the wallet, not to individual tokens: deliberately never cleaned up
6466
extractor.RegisterProvider("x509", NewNoopSKIProvider())
6567
// Fallback provider is used for any unregistered types
6668
```
@@ -72,6 +74,28 @@ extractor.RegisterProvider("x509", NewNoopSKIProvider())
7274
4. If not found, uses fallback provider (SHA256 hash)
7375
5. Returns list of SKI strings in hexadecimal format
7476

77+
### X.509 is intentionally out of scope
78+
79+
X.509 is registered with `NoopSKIProvider`, so **no keystore key is ever deleted for an
80+
X.509-owned token**. This is deliberate, not an unimplemented provider.
81+
82+
An X.509 owner identity is a long-lived, non-anonymous certificate: `x509.KeyManager` reports
83+
`Anonymous() == false` and always serves the same identity descriptor. Its private key therefore
84+
belongs to the **wallet**, not to any individual token — the same key signs every token that
85+
wallet ever owns, and it remains in use long after those tokens are spent. A real X.509 SKI
86+
provider would make the cleanup sweep delete the wallet's own signing key as soon as the first of
87+
its tokens aged past the TTL, permanently breaking the wallet.
88+
89+
The Idemix providers are the opposite case: their SKIs identify a one-shot pseudonym key created
90+
for a single recipient identity. That key is dead once its token is deleted, which is exactly what
91+
makes it safe to remove.
92+
93+
**Consequence to be aware of:** a deleted X.509-owned token still gets a row in
94+
`token_ski_cleanups`, because the cleanup manager records "no key material to delete" the same way
95+
it records a completed deletion. For X.509 that row means *nothing to clean*, not *keys were
96+
removed*. Do not read the `token_ski_cleanups` table as evidence that X.509 key material was
97+
purged.
98+
7599
### Interfaces
76100

77101
#### Storage Interface
@@ -264,7 +288,8 @@ cleanupManager := cleanup.NewServiceManager(
264288
- Get keystore for TMS
265289
- Derive SKIs from owner identity using appropriate provider
266290
- Delete each SKI from keystore
267-
- Mark token as cleaned in database (even on partial success)
291+
- Mark token as cleaned in database **only if every key was deleted** (or if the owner type has
292+
no keys to delete at all)
268293
7. **Release Leadership**: Close leadership lock
269294
8. **Wait**: Sleep until next scan interval
270295
9. **Repeat**: Go to step 2
@@ -281,16 +306,26 @@ The cleanup service handles errors gracefully with specific retry behavior:
281306

282307
### Key Deletion Errors
283308

284-
- **All keys fail to delete**: Token is NOT marked as cleaned; will retry on next sweep
285-
- **Some keys fail to delete**: Token IS marked as cleaned (partial success); logs warnings for failed keys
286-
- **No SKIs derived**: Token IS marked as cleaned to avoid infinite retries; logs warning
309+
Key deletion is **all-or-nothing** per token:
310+
311+
- **Any key fails to delete**: Token is NOT marked as cleaned; the whole token is retried on the
312+
next sweep. The returned error joins every per-key cause, so callers can inspect them with
313+
`errors.Is`/`errors.As`
314+
- **All keys deleted**: Token IS marked as cleaned
315+
- **No SKIs derived**: Token IS marked as cleaned to avoid infinite retries; logs warning. This is
316+
the normal path for X.509 — see
317+
[X.509 is intentionally out of scope](#x509-is-intentionally-out-of-scope)
287318

288319
### Rationale
289320

290-
This error handling strategy balances reliability with forward progress:
291-
- Complete failures trigger retries (transient errors may resolve)
292-
- Partial successes are recorded to avoid reprocessing successfully deleted keys
293-
- Empty SKI cases are marked complete to prevent infinite retry loops
321+
Marking a token cleaned while some of its key material is still in the keystore would turn a
322+
transient database error into a permanent, un-retriable key-retention hole: the token would never
323+
be selected again, so the surviving key would never be deleted. Retrying the whole token is safe
324+
and cheap because `Keystore.Delete` is idempotent — re-deleting the keys that already succeeded
325+
costs one no-op call each.
326+
327+
Empty SKI cases are still marked complete, otherwise every sweep would rescan the same tokens
328+
forever.
294329

295330
### Other Errors
296331

@@ -395,11 +430,12 @@ Key metrics to monitor:
395430
- **Error Rate**: Failed cleanup attempts (check logs for details)
396431
- **Leadership Changes**: Frequency of leader election (should be stable)
397432
- **Processing Time**: Duration of each cleanup sweep
398-
- **Partial Failures**: Tokens with some keys deleted but not all
433+
- **Retried Tokens**: Tokens that failed at least one key deletion and are still pending. A token
434+
stuck here across many sweeps means a key deletion is failing persistently, not transiently
399435

400436
**Log Levels:**
401437
- `INFO`: Successful cleanup operations, manager start/stop
402-
- `WARN`: Partial failures, key not found, leadership issues
438+
- `WARN`: Failed key deletions, key not found, leadership issues
403439
- `DEBUG`: Detailed sweep information, SKI derivation, leadership acquisition
404440

405441
## Security Considerations
@@ -408,7 +444,11 @@ Key metrics to monitor:
408444
- **Idempotency**: Safe to retry cleanup operations
409445
- **Audit Trail**: `token_ski_cleanups` table provides cleanup history with timestamps and instance tracking
410446
- **Key Isolation**: Only deletes keys for deleted tokens, never active tokens
411-
- **Partial Success Handling**: Prevents infinite retries while maintaining audit trail
447+
- **All-or-Nothing Marking**: A token is only recorded as cleaned once *all* of its keys are gone,
448+
so a failed deletion can never be silently forgotten
449+
- **X.509 Exclusion**: X.509 key material is never deleted by design — a `token_ski_cleanups` row
450+
for an X.509-owned token means "nothing to clean". See
451+
[X.509 is intentionally out of scope](#x509-is-intentionally-out-of-scope)
412452
- **Instance Tracking**: `cleaned_by` field records which instance performed cleanup
413453

414454
## Comparison with Recovery Service

token/services/storage/endorserdb/store.go

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -112,7 +112,7 @@ func newStoreService(p dbdriver.EndorserStore) (*StoreService, error) {
112112
func (d *StoreService) ValidationRecords(ctx context.Context, params QueryValidationRecordsParams) (*ValidationRecordsIterator, error) {
113113
it, err := d.db.QueryValidations(ctx, params)
114114
if err != nil {
115-
return nil, errors.Errorf("failed to query validation records: %s", err)
115+
return nil, errors.Wrapf(err, "failed to query validation records")
116116
}
117117

118118
return &ValidationRecordsIterator{it: it}, nil
@@ -152,9 +152,9 @@ func (d *StoreService) SetStatus(ctx context.Context, txID string, status dbdriv
152152

153153
return errors.Wrapf(err, "failed setting status [%s][%s]", txID, dbdriver.TxStatusMessage[status])
154154
}
155+
// No Rollback() here: once Commit() fails the driver transaction is already finalized, so
156+
// rolling back is a guaranteed no-op. This matches AppendValidationRecord above and ttxdb.
155157
if err := w.Commit(); err != nil {
156-
w.Rollback()
157-
158158
return errors.Wrapf(err, "failed committing status [%s][%s]", txID, dbdriver.TxStatusMessage[status])
159159
}
160160

Lines changed: 57 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,57 @@
1+
/*
2+
Copyright IBM Corp. All Rights Reserved.
3+
4+
SPDX-License-Identifier: Apache-2.0
5+
*/
6+
7+
package endorserdb
8+
9+
import (
10+
"context"
11+
"testing"
12+
13+
"github.com/LFDT-Panurus/panurus/token/services/storage/db/common"
14+
dbdriver "github.com/LFDT-Panurus/panurus/token/services/storage/db/driver"
15+
"github.com/hyperledger-labs/fabric-smart-client/pkg/utils/errors"
16+
"github.com/stretchr/testify/assert"
17+
"github.com/stretchr/testify/require"
18+
)
19+
20+
// errQueryFailed is a sentinel standing in for a driver-level cause a caller may want to match,
21+
// such as sql.ErrNoRows or a driver sentinel error.
22+
var errQueryFailed = errors.New("driver query failed")
23+
24+
// failingEndorserStore is an EndorserStore whose QueryValidations always fails with
25+
// errQueryFailed.
26+
type failingEndorserStore struct{}
27+
28+
func (failingEndorserStore) Close() error { return nil }
29+
30+
func (failingEndorserStore) NewEndorserStoreTransaction() (dbdriver.EndorserStoreTransaction, error) {
31+
return nil, errQueryFailed
32+
}
33+
34+
func (failingEndorserStore) QueryValidations(context.Context, dbdriver.QueryValidationRecordsParams) (dbdriver.ValidationRecordsIterator, error) {
35+
return nil, errQueryFailed
36+
}
37+
38+
func (failingEndorserStore) GetStatus(context.Context, string) (dbdriver.TxStatus, string, error) {
39+
return dbdriver.Unknown, "", errQueryFailed
40+
}
41+
42+
// TestValidationRecordsPreservesErrorChain checks that a driver failure surfaced by
43+
// ValidationRecords stays matchable with errors.Is. Building the error by interpolating the cause
44+
// into a new message (errors.Errorf with %s) would break every caller that switches on the
45+
// underlying cause.
46+
func TestValidationRecordsPreservesErrorChain(t *testing.T) {
47+
store := &StoreService{
48+
StatusSupport: common.NewStatusSupport(),
49+
db: failingEndorserStore{},
50+
}
51+
52+
it, err := store.ValidationRecords(t.Context(), QueryValidationRecordsParams{})
53+
require.Error(t, err)
54+
assert.Nil(t, it)
55+
require.ErrorIs(t, err, errQueryFailed, "the driver cause must remain unwrappable")
56+
assert.Contains(t, err.Error(), "failed to query validation records")
57+
}
Lines changed: 119 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,119 @@
1+
/*
2+
Copyright IBM Corp. All Rights Reserved.
3+
4+
SPDX-License-Identifier: Apache-2.0
5+
*/
6+
7+
package endorserdb_test
8+
9+
import (
10+
"testing"
11+
12+
"github.com/LFDT-Panurus/panurus/token"
13+
driver2 "github.com/LFDT-Panurus/panurus/token/driver"
14+
"github.com/LFDT-Panurus/panurus/token/sdk/tms"
15+
config2 "github.com/LFDT-Panurus/panurus/token/services/config"
16+
"github.com/LFDT-Panurus/panurus/token/services/storage/db/multiplexed"
17+
"github.com/LFDT-Panurus/panurus/token/services/storage/db/sql/sqlite"
18+
"github.com/LFDT-Panurus/panurus/token/services/storage/endorserdb"
19+
"github.com/hyperledger-labs/fabric-smart-client/platform/view/services/config"
20+
sqlite2 "github.com/hyperledger-labs/fabric-smart-client/platform/view/services/storage/driver/sql/sqlite"
21+
"github.com/stretchr/testify/assert"
22+
"github.com/stretchr/testify/require"
23+
_ "modernc.org/sqlite"
24+
)
25+
26+
// newStoreServiceManager builds a store service manager backed by the SQLite configuration in
27+
// ./testdata/sqlite.
28+
func newStoreServiceManager(t *testing.T) endorserdb.StoreServiceManager {
29+
t.Helper()
30+
// create a new config service by loading the config file
31+
cp, err := config.NewProvider("./testdata/sqlite")
32+
require.NoError(t, err)
33+
34+
return endorserdb.NewStoreServiceManager(
35+
tms.NewConfigServiceWrapper(config2.NewService(cp)),
36+
multiplexed.NewDriver(cp, sqlite.NewNamedDriver(cp, sqlite2.NewDbProvider())),
37+
)
38+
}
39+
40+
func TestDB(t *testing.T) {
41+
manager := newStoreServiceManager(t)
42+
_, err := manager.StoreServiceByTMSId(token.TMSID{Network: "pineapple", Namespace: "ns"})
43+
require.NoError(t, err)
44+
_, err = manager.StoreServiceByTMSId(token.TMSID{Network: "grapes", Namespace: "ns"})
45+
require.NoError(t, err)
46+
}
47+
48+
// TestValidationRecordsLifecycle exercises the facade end to end against SQLite:
49+
// AppendValidationRecord, GetStatus, SetStatus and ValidationRecords.
50+
func TestValidationRecordsLifecycle(t *testing.T) {
51+
ctx := t.Context()
52+
manager := newStoreServiceManager(t)
53+
store, err := manager.StoreServiceByTMSId(token.TMSID{Network: "pineapple", Namespace: "ns"})
54+
require.NoError(t, err)
55+
56+
meta := map[string][]byte{"key": []byte("value")}
57+
require.NoError(t, store.AppendValidationRecord(ctx, "lifecycle-1", []byte("tr1"), meta, driver2.PPHash("pp")))
58+
require.NoError(t, store.AppendValidationRecord(ctx, "lifecycle-2", []byte("tr2"), nil, driver2.PPHash("pp")))
59+
60+
// a freshly appended record is pending
61+
status, message, err := store.GetStatus(ctx, "lifecycle-1")
62+
require.NoError(t, err)
63+
assert.Equal(t, endorserdb.Pending, status)
64+
assert.Empty(t, message)
65+
66+
// the records are queryable, with metadata and token request round-tripped
67+
records := readValidationRecords(t, store, endorserdb.QueryValidationRecordsParams{
68+
Filter: func(record *endorserdb.ValidationRecord) bool {
69+
return record.TxID == "lifecycle-1" || record.TxID == "lifecycle-2"
70+
},
71+
})
72+
require.Len(t, records, 2)
73+
assert.Equal(t, "lifecycle-1", records[0].TxID)
74+
assert.Equal(t, []byte("tr1"), records[0].TokenRequest)
75+
assert.Equal(t, meta, records[0].Metadata)
76+
assert.Equal(t, "lifecycle-2", records[1].TxID)
77+
assert.Equal(t, []byte("tr2"), records[1].TokenRequest)
78+
79+
// SetStatus is reflected by GetStatus...
80+
require.NoError(t, store.SetStatus(ctx, "lifecycle-1", endorserdb.Confirmed, "all good"))
81+
status, message, err = store.GetStatus(ctx, "lifecycle-1")
82+
require.NoError(t, err)
83+
assert.Equal(t, endorserdb.Confirmed, status)
84+
assert.Equal(t, "all good", message)
85+
86+
// ...and by the Statuses filter of ValidationRecords
87+
confirmed := readValidationRecords(t, store, endorserdb.QueryValidationRecordsParams{
88+
Statuses: []endorserdb.TxStatus{endorserdb.Confirmed},
89+
Filter: func(record *endorserdb.ValidationRecord) bool {
90+
return record.TxID == "lifecycle-1" || record.TxID == "lifecycle-2"
91+
},
92+
})
93+
require.Len(t, confirmed, 1)
94+
assert.Equal(t, "lifecycle-1", confirmed[0].TxID)
95+
96+
// the sibling record is untouched
97+
status, _, err = store.GetStatus(ctx, "lifecycle-2")
98+
require.NoError(t, err)
99+
assert.Equal(t, endorserdb.Pending, status)
100+
}
101+
102+
func readValidationRecords(t *testing.T, store *endorserdb.StoreService, params endorserdb.QueryValidationRecordsParams) []*endorserdb.ValidationRecord {
103+
t.Helper()
104+
it, err := store.ValidationRecords(t.Context(), params)
105+
require.NoError(t, err)
106+
defer it.Close()
107+
108+
var records []*endorserdb.ValidationRecord
109+
for {
110+
next, err := it.Next()
111+
require.NoError(t, err)
112+
if next == nil {
113+
break
114+
}
115+
records = append(records, next)
116+
}
117+
118+
return records
119+
}
Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,24 @@
1+
fsc:
2+
persistences:
3+
token_persistence:
4+
type: sqlite
5+
opts:
6+
dataSource: file:tmp?_pragma=journal_mode(WAL)&_pragma=busy_timeout(20000)&mode=memory&cache=shared
7+
tablePrefix: tsdk
8+
maxOpenConns: 10
9+
10+
token:
11+
enabled: true
12+
tms:
13+
pineapple:
14+
network: pineapple
15+
channel:
16+
namespace: ns
17+
endorserdb:
18+
persistence: token_persistence
19+
grapes:
20+
network: grapes
21+
channel:
22+
namespace: ns
23+
endorserdb:
24+
persistence: token_persistence

token/services/storage/services/cleanup/manager.go

Lines changed: 15 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -47,7 +47,7 @@ type Leadership interface {
4747
Close() error
4848
}
4949

50-
//go:generate counterfeiter -o mock/identity_provider.go -fake-name IdentityProvider . IdentityProvider
50+
//go:generate counterfeiter -o mock/identity_provider.go -fake-name IdentityProvider . SKIProvider
5151

5252
// SKIProvider provides methods to derive SKIs from identities
5353
type SKIProvider interface {
@@ -326,7 +326,9 @@ func (m *Manager) cleanupToken(ctx context.Context, token DeletedToken) error {
326326

327327
if len(skis) == 0 {
328328
m.logger.Warnf("no SKIs derived for token [%s:%d], skipping", token.TxID, token.Index)
329-
// Still mark as cleaned to avoid retrying
329+
// No SKIs means this owner type has no per-token key material to remove (for example
330+
// X.509, see NoopSKIProvider). Mark the token as cleaned to avoid rescanning it on
331+
// every sweep: "cleaned" here records "nothing to delete", not "keys were deleted".
330332
if err := m.storage.MarkTokenCleaned(ctx, token.TxID, token.Index, m.config.InstanceID); err != nil {
331333
return errors.Wrapf(err, "failed to mark token [%s:%d] as cleaned", token.TxID, token.Index)
332334
}
@@ -347,12 +349,20 @@ func (m *Manager) cleanupToken(ctx context.Context, token DeletedToken) error {
347349
}
348350
}
349351

350-
// If all deletions failed, return error without marking as cleaned
352+
// All-or-nothing: if *any* deletion failed, return an error without marking the token as
353+
// cleaned, so the next sweep retries it. Marking a token cleaned while some of its key
354+
// material is still in the keystore would turn a transient error into a permanent,
355+
// un-retriable key-retention hole. Re-deleting the keys that did succeed is harmless,
356+
// because Keystore.Delete is idempotent.
351357
if len(deleteErrors) > 0 {
352-
return errors.Errorf("failed to delete keys for token [%s:%d]: %v", token.TxID, token.Index, deleteErrors)
358+
return errors.Wrapf(
359+
errors.Join(deleteErrors...),
360+
"failed to delete %d of %d key(s) for token [%s:%d]",
361+
len(deleteErrors), len(skis), token.TxID, token.Index,
362+
)
353363
}
354364

355-
// Mark token as cleaned (even if some keys failed to delete)
365+
// Every key was deleted: record the token as cleaned so it is not reprocessed.
356366
if err := m.storage.MarkTokenCleaned(ctx, token.TxID, token.Index, m.config.InstanceID); err != nil {
357367
return errors.Wrapf(err, "failed to mark token [%s:%d] as cleaned", token.TxID, token.Index)
358368
}

0 commit comments

Comments
 (0)