Skip to content

Commit aba9b43

Browse files
RozerxshashankAKRAM@il.ibm.com
authored andcommitted
Fix #1635: Add Comprehensive Tests for Auditor Lock Management
Signed-off-by: AKRAM@il.ibm.com <akram@akramb.vpc.cloud9.ibm.com>
1 parent b1d9869 commit aba9b43

3 files changed

Lines changed: 326 additions & 2 deletions

File tree

token/services/auditor/auditor.go

Lines changed: 16 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -111,8 +111,22 @@ func (a *Service) Validate(ctx context.Context, request *token.Request) error {
111111
}
112112

113113
// Audit extracts the list of inputs and outputs from the passed transaction.
114-
// In addition, the Audit locks the enrollment named ids.
115-
// Release must be invoked in case
114+
// In addition, Audit acquires locks on the enrollment IDs involved in the transaction.
115+
// The caller MUST call Release() to unlock these enrollment IDs after processing.
116+
//
117+
// IMPORTANT: The defer Release() statement MUST be placed immediately after checking
118+
// the error returned by Audit(). This ensures locks are released even if subsequent
119+
// operations fail. Example:
120+
//
121+
// inputs, outputs, err := auditor.Audit(ctx, tx)
122+
// if err != nil {
123+
// return errors.Wrap(err, "audit failed")
124+
// }
125+
// defer auditor.Release(ctx, tx)
126+
//
127+
// Note: The semaphore-based locking mechanism handles context cancellation during
128+
// lock acquisition (see PR #1616), ensuring proper cleanup in case of timeouts or
129+
// cancellations.
116130
func (a *Service) Audit(ctx context.Context, tx Transaction) (*token.InputStream, *token.OutputStream, error) {
117131
start := time.Now()
118132
logger.DebugfContext(ctx, "audit transaction [%s]....", tx.ID())

token/services/auditor/auditor_test.go

Lines changed: 294 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -309,6 +309,63 @@ func TestService_Audit_Success(t *testing.T) {
309309
assert.NotNil(t, outputs)
310310
}
311311

312+
// TestService_Audit_LockAcquisitionFailure verifies that when AcquireLocks() fails
313+
// due to context cancellation, the error is properly returned and no locks are held.
314+
func TestService_Audit_LockAcquisitionFailure(t *testing.T) {
315+
// Create a StoreService with real lock mechanism
316+
storeService := newTestStoreService(t, newFakeStore())
317+
318+
// First, acquire locks directly on enrollment IDs to simulate lock contention
319+
ctx := context.Background()
320+
err := storeService.AcquireLocks(ctx, "blocking-anchor", "test-eid-1", "test-eid-2")
321+
require.NoError(t, err)
322+
defer storeService.ReleaseLocks(ctx, "blocking-anchor")
323+
324+
// Now try to acquire the same locks with a cancelled context
325+
cancelledCtx, cancel := context.WithCancel(context.Background())
326+
cancel() // Cancel immediately to simulate timeout/cancellation
327+
328+
err = storeService.AcquireLocks(cancelledCtx, "tx-lock-fail", "test-eid-1", "test-eid-2")
329+
require.Error(t, err)
330+
assert.Contains(t, err.Error(), "context canceled")
331+
332+
// Verify no locks are held for the failed transaction by checking the anchor is not stored
333+
storeService.ReleaseLocks(ctx, "tx-lock-fail") // Should be a no-op since locks weren't acquired
334+
}
335+
336+
// TestService_Audit_ContextCancellationDuringAcquisition verifies that when context
337+
// is cancelled or times out during lock acquisition, the semaphore automatically rolls
338+
// back acquired locks and returns an error, allowing subsequent acquisitions to succeed.
339+
func TestService_Audit_ContextCancellationDuringAcquisition(t *testing.T) {
340+
// Create a StoreService with real lock mechanism
341+
storeService := newTestStoreService(t, newFakeStore())
342+
343+
// Acquire locks to create contention
344+
ctx := context.Background()
345+
err := storeService.AcquireLocks(ctx, "blocking-anchor", "test-eid-1", "test-eid-2")
346+
require.NoError(t, err)
347+
348+
// Create a context with a very short timeout
349+
timeoutCtx, cancel := context.WithTimeout(context.Background(), 1)
350+
defer cancel()
351+
352+
// This should fail due to context timeout while waiting for locks
353+
err = storeService.AcquireLocks(timeoutCtx, "tx-ctx-cancel", "test-eid-1", "test-eid-2")
354+
require.Error(t, err)
355+
assert.True(t, errors.Is(err, context.DeadlineExceeded) || errors.Is(err, context.Canceled),
356+
"expected context cancellation error, got: %v", err)
357+
358+
// Release the blocking locks
359+
storeService.ReleaseLocks(ctx, "blocking-anchor")
360+
361+
// Verify the semaphore automatically rolled back by attempting acquisition with fresh context
362+
err = storeService.AcquireLocks(context.Background(), "tx-after-cancel", "test-eid-1", "test-eid-2")
363+
require.NoError(t, err)
364+
365+
// Clean up
366+
storeService.ReleaseLocks(ctx, "tx-after-cancel")
367+
}
368+
312369
func TestService_Audit_DBCleanSuccess(t *testing.T) {
313370
fakeStore := newFakeStore()
314371
fakeStore.GetStatusReturns(0, "", errors.New("db status err"))
@@ -662,3 +719,240 @@ func TestManager_GetByTMSID(t *testing.T) {
662719
auditor.Get(sp, w)
663720
})
664721
}
722+
723+
// ---------------------------------------------------------------------------
724+
// Service.Audit Lock Management Tests
725+
// ---------------------------------------------------------------------------
726+
727+
// TestService_Audit_LocksReleasedOnAuditRecordError verifies that when Audit() fails
728+
// before lock acquisition (during AuditRecord()), no locks are held and Release() is safe.
729+
// Audit() acquires locks ONLY after successful AuditRecord(), so early failures don't leak locks.
730+
func TestService_Audit_LocksReleasedOnAuditRecordError(t *testing.T) {
731+
// Create a TMS that will fail on AuditRecord by returning nil public parameters
732+
mockTMS := &drivermock.TokenManagerService{}
733+
mockPPM := &drivermock.PublicParamsManager{}
734+
mockPPM.PublicParametersReturns(nil) // This will cause AuditRecord to fail
735+
mockTMS.PublicParamsManagerReturns(mockPPM)
736+
mockTMS.ValidatorReturns(&drivermock.Validator{}, nil)
737+
mockTMS.TokensServiceReturns(&drivermock.TokensService{})
738+
mockTMS.WalletServiceReturns(&drivermock.WalletService{})
739+
740+
mockVP := &tokenmock.VaultProvider{}
741+
mockV := &drivermock.Vault{}
742+
mockV.QueryEngineReturns(&drivermock.QueryEngine{})
743+
mockVP.VaultReturns(mockV, nil)
744+
745+
badTMS, err := token.NewManagementService(
746+
token.TMSID{}, mockTMS, logging.MustGetLogger("test"), mockVP, nil, nil,
747+
)
748+
require.NoError(t, err)
749+
750+
storeService := newTestStoreService(t, newFakeStore())
751+
svc := newTestService(storeService, nil)
752+
753+
tx := &auditmock.Transaction{}
754+
tx.IDReturns("tx-audit-record-err")
755+
tx.RequestReturns(token.NewRequest(badTMS, token.RequestAnchor("tx-audit-record-err")))
756+
757+
// Audit should fail
758+
_, _, err = svc.Audit(context.Background(), tx)
759+
require.Error(t, err)
760+
assert.Contains(t, err.Error(), "failed getting transaction audit record")
761+
762+
// Release should be safe to call even though Audit failed
763+
assert.NotPanics(t, func() {
764+
svc.Release(context.Background(), tx)
765+
})
766+
767+
// Verify no locks are held by trying to acquire the same anchor
768+
ctx := context.Background()
769+
err = storeService.AcquireLocks(ctx, "tx-audit-record-err")
770+
require.NoError(t, err, "should be able to acquire locks since Audit failed")
771+
storeService.ReleaseLocks(ctx, "tx-audit-record-err")
772+
}
773+
774+
// TestService_Audit_LocksAcquiredOnSuccess verifies successful Audit() acquires locks,
775+
// Release() frees them, and Release() is idempotent (safe to call multiple times).
776+
func TestService_Audit_LocksAcquiredOnSuccess(t *testing.T) {
777+
storeService := newTestStoreService(t, newFakeStore())
778+
svc := newTestService(storeService, nil)
779+
780+
tx := &auditmock.Transaction{}
781+
tx.IDReturns("tx-audit-success")
782+
tx.RequestReturns(token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-audit-success")))
783+
784+
ctx := context.Background()
785+
786+
// Audit should succeed
787+
inputs, outputs, err := svc.Audit(ctx, tx)
788+
require.NoError(t, err)
789+
assert.NotNil(t, inputs)
790+
assert.NotNil(t, outputs)
791+
792+
// Verify Release is safe to call
793+
assert.NotPanics(t, func() {
794+
svc.Release(ctx, tx)
795+
})
796+
797+
// Verify Release is idempotent
798+
assert.NotPanics(t, func() {
799+
svc.Release(ctx, tx)
800+
})
801+
}
802+
803+
// TestService_Audit_ContextCancellationBeforeLockAcquisition verifies context cancellation
804+
// doesn't leak locks. Semaphore auto-rolls back partially acquired locks (PR #1616).
805+
// Release() is always safe regardless of Audit() outcome.
806+
func TestService_Audit_ContextCancellationBeforeLockAcquisition(t *testing.T) {
807+
storeService := newTestStoreService(t, newFakeStore())
808+
svc := newTestService(storeService, nil)
809+
810+
tx := &auditmock.Transaction{}
811+
tx.IDReturns("tx-ctx-cancel")
812+
tx.RequestReturns(token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-ctx-cancel")))
813+
814+
// Use a cancelled context
815+
cancelledCtx, cancel := context.WithCancel(context.Background())
816+
cancel()
817+
818+
// Audit may fail due to context cancellation (depending on timing)
819+
// or succeed if AuditRecord completes before cancellation check
820+
_, _, _ = svc.Audit(cancelledCtx, tx)
821+
// We don't assert error here as it depends on timing
822+
823+
// Release should always be safe to call
824+
assert.NotPanics(t, func() {
825+
svc.Release(context.Background(), tx)
826+
})
827+
828+
// Verify we can acquire locks after (no locks were leaked)
829+
ctx := context.Background()
830+
err := storeService.AcquireLocks(ctx, "tx-ctx-cancel")
831+
require.NoError(t, err, "should be able to acquire locks")
832+
storeService.ReleaseLocks(ctx, "tx-ctx-cancel")
833+
}
834+
835+
// TestService_Audit_MultipleAuditsSequential verifies sequential audits work correctly:
836+
// first Audit() acquires locks, Release() frees them, second Audit() succeeds.
837+
func TestService_Audit_MultipleAuditsSequential(t *testing.T) {
838+
storeService := newTestStoreService(t, newFakeStore())
839+
svc := newTestService(storeService, nil)
840+
841+
ctx := context.Background()
842+
843+
// First audit
844+
tx1 := &auditmock.Transaction{}
845+
tx1.IDReturns("tx-audit-1")
846+
tx1.RequestReturns(token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-audit-1")))
847+
848+
inputs1, outputs1, err := svc.Audit(ctx, tx1)
849+
require.NoError(t, err)
850+
assert.NotNil(t, inputs1)
851+
assert.NotNil(t, outputs1)
852+
853+
// Release first audit's locks
854+
svc.Release(ctx, tx1)
855+
856+
// Second audit should succeed
857+
tx2 := &auditmock.Transaction{}
858+
tx2.IDReturns("tx-audit-2")
859+
tx2.RequestReturns(token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-audit-2")))
860+
861+
inputs2, outputs2, err := svc.Audit(ctx, tx2)
862+
require.NoError(t, err)
863+
assert.NotNil(t, inputs2)
864+
assert.NotNil(t, outputs2)
865+
866+
// Clean up
867+
svc.Release(ctx, tx2)
868+
}
869+
870+
// TestService_Audit_ReleaseIdempotency verifies Release() is idempotent - can be called
871+
// multiple times safely without panics (handles error paths, defer, retry logic).
872+
func TestService_Audit_ReleaseIdempotency(t *testing.T) {
873+
storeService := newTestStoreService(t, newFakeStore())
874+
svc := newTestService(storeService, nil)
875+
876+
tx := &auditmock.Transaction{}
877+
tx.IDReturns("tx-release-idempotent")
878+
tx.RequestReturns(token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-release-idempotent")))
879+
880+
// Audit to acquire locks
881+
_, _, err := svc.Audit(context.Background(), tx)
882+
require.NoError(t, err)
883+
884+
ctx := context.Background()
885+
886+
// First release should work
887+
assert.NotPanics(t, func() {
888+
svc.Release(ctx, tx)
889+
})
890+
891+
// Second release should also be safe (no-op)
892+
assert.NotPanics(t, func() {
893+
svc.Release(ctx, tx)
894+
})
895+
896+
// Third release should still be safe
897+
assert.NotPanics(t, func() {
898+
svc.Release(ctx, tx)
899+
})
900+
}
901+
902+
// TestService_Audit_ReleaseWithoutAudit verifies Release() is safe to call without
903+
// prior Audit() (handles defer in error paths where Audit() never ran or failed early).
904+
func TestService_Audit_ReleaseWithoutAudit(t *testing.T) {
905+
storeService := newTestStoreService(t, newFakeStore())
906+
svc := newTestService(storeService, nil)
907+
908+
tx := &auditmock.Transaction{}
909+
tx.IDReturns("tx-no-audit")
910+
tx.RequestReturns(token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-no-audit")))
911+
912+
// Release without Audit should be safe
913+
assert.NotPanics(t, func() {
914+
svc.Release(context.Background(), tx)
915+
})
916+
}
917+
918+
// TestService_Audit_PanicRecoveryReleasesLocks verifies defer Release() executes even
919+
// when code panics, preventing lock leaks. Demonstrates correct pattern:
920+
//
921+
// defer auditor.Release(ctx, tx) // MUST be after error check
922+
func TestService_Audit_PanicRecoveryReleasesLocks(t *testing.T) {
923+
storeService := newTestStoreService(t, newFakeStore())
924+
svc := newTestService(storeService, nil)
925+
926+
tx := &auditmock.Transaction{}
927+
tx.IDReturns("tx-panic-recovery")
928+
tx.RequestReturns(token.NewRequest(newTestManagementService(t), token.RequestAnchor("tx-panic-recovery")))
929+
930+
ctx := context.Background()
931+
932+
// Simulate code that panics after Audit but has defer Release
933+
func() {
934+
defer func() {
935+
if r := recover(); r != nil {
936+
// Panic recovered as expected
937+
assert.Equal(t, "simulated panic", r)
938+
}
939+
}()
940+
941+
// Audit succeeds and acquires locks
942+
inputs, outputs, err := svc.Audit(ctx, tx)
943+
require.NoError(t, err)
944+
assert.NotNil(t, inputs)
945+
assert.NotNil(t, outputs)
946+
947+
// Defer Release - this should execute even if panic occurs
948+
defer svc.Release(ctx, tx)
949+
950+
// Simulate panic in subsequent processing
951+
panic("simulated panic")
952+
}()
953+
954+
// Verify locks were released by attempting to acquire them
955+
err := storeService.AcquireLocks(ctx, "tx-panic-recovery")
956+
require.NoError(t, err, "locks should have been released despite panic")
957+
storeService.ReleaseLocks(ctx, "tx-panic-recovery")
958+
}

token/services/ttx/auditor.go

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -59,6 +59,22 @@ func (a *Auditor) Validate(tx *Transaction) error {
5959
return a.Service.Validate(tx.Context, tx.TokenRequest)
6060
}
6161

62+
// Audit extracts the list of inputs and outputs from the passed transaction.
63+
// In addition, Audit acquires locks on the enrollment IDs involved in the transaction.
64+
// The caller MUST call Release() to unlock these enrollment IDs after processing.
65+
//
66+
// IMPORTANT: The defer Release() statement MUST be placed immediately after checking
67+
// the error returned by Audit(). This ensures locks are released even if subsequent
68+
// operations fail. Example:
69+
//
70+
// inputs, outputs, err := auditor.Audit(ctx, tx)
71+
// if err != nil {
72+
// return errors.Wrap(err, "audit failed")
73+
// }
74+
// defer auditor.Release(ctx, tx)
75+
//
76+
// Note: The semaphore-based locking mechanism handles context cancellation during
77+
// lock acquisition, ensuring proper cleanup in case of timeouts or cancellations.
6278
func (a *Auditor) Audit(ctx context.Context, tx *Transaction) (*token.InputStream, *token.OutputStream, error) {
6379
return a.Service.Audit(ctx, tx)
6480
}

0 commit comments

Comments
 (0)