Skip to content

test: replace sleeps and fixed-window negative assertions with deterministic synchronization - #1592

Merged
IAmJSD merged 6 commits into
LeanerCloud:mainfrom
IAmJSD:fix/issue-36-archera-gate
Oct 29, 2026
Merged

IAmJSD merged 6 commits into
LeanerCloud:mainfrom
IAmJSD:fix/issue-36-archera-gate

Conversation

@IAmJSD

@IAmJSD IAmJSD commented Oct 29, 2026 •

Copy link
Copy Markdown
Collaborator

Summary

Finishes #36. #1298, #1568 and #1569 removed most of the wall-clock sleeps. This PR handles what was left:

  1. The 100ms sleep in internal/archera/provider_cancel_test.go (named in the issue's last status update) is replaced by a gate channel.
  2. A 10ms frontend unit-test wait that the test(frontend): wait for async handlers instead of sleeping in unit tests #1569 guard missed is removed, and the guard now catches that form.
  3. Every fixed-window negative assertion in the Go tests is converted. This is the issue's main Go concern: a test that proves "X did not happen" by waiting N ms and seeing nothing passes falsely when a loaded runner has not scheduled X yet. 12 sites: the scheduler refresh check, the auth no-booking check, the server usage-booking helper (3 tests), a server assert.Never, and 8 real-Postgres integration windows/barriers of 300ms to 1.5s.
  4. Every remaining sleep, time.After and timer wait in the Go tests is listed below with the reason it stays.

Root cause (archera)

TestClient_ConcurrentCallersShareOneBuild used a slowResolver that slept 100ms so the 20 racing callers would overlap the in-flight build. The test got its overlap from timing: on a slow runner a late caller could arrive after the build finished, take the cached-client fast path, and never test the serialization. It also spent 100ms on every run.

Fix (archera and frontend)

  • internal/archera/provider_cancel_test.go: the resolver is now a gatedResolver that parks on a release channel. The test runs in a testing/synctest bubble. synctest.Wait() returns only when every caller is durably blocked: one inside the resolver and 19 on the build semaphore, both on channels created inside the bubble. The test then:
    1. asserts exactly one resolver call and nothing cached while the gate is closed (this catches a missing semaphore),
    2. opens the gate and asserts there is still exactly one call and all 20 callers got the same client with no error (this catches a missing re-check after acquire).
      A deferred openGate(); wg.Wait() drains the callers when an assertion fails, so a failure shows up as a test failure and not as a synctest "blocked goroutines remain" panic that would kill the whole package binary.
  • frontend/src/__tests__/index.test.ts: calls init on DOMContentLoaded waited 10ms (new Promise(resolve => setTimeout(() => { expect(...); resolve(); }, 10))) for an init() that the listener calls synchronously (document.addEventListener('DOMContentLoaded', () => void init())). It now asserts directly, like the next test in the file.
  • frontend/src/__tests__/no-wallclock-sleeps.test.ts: the test(frontend): wait for async handlers instead of sleeping in unit tests #1569 guard only matched setTimeout(r, N) and setTimeout(() => r(), N), so it missed the form above, where the assertions sit inside a timer block. A second pattern (SLEEP_BLOCK) now flags that form with a non-zero delay. Two matcher samples cover it: the 10ms form is flagged and the 0ms flush is allowed.

No production code changed. No frontend source changed (only files under frontend/src/__tests__/). The only non-test Go change is the shared test helper internal/database/postgres/testhelpers/lockwait.go.

Fixed-window negative assertions (the issue's main Go concern)

The pattern was select { case <-done: t.Fatal(...); case <-time.After(N): }, an assert.Never, or a race barrier that gave up after N ms. Each one cannot tell "the event will never happen" from "the event has not happened yet", so a slow runner turns a real regression into a pass. Each site now waits on an observed state that proves the event can no longer happen, and keeps a timeout only as a failure deadline.

New helpers in internal/database/postgres/testhelpers/lockwait.go, next to the existing WaitForLockWait/Await:

  • BackendPID(ctx, t, tx) returns the holder transaction's backend PID.
  • AwaitBlockedBy(ctx, t, db, holderPID, done) polls pg_locks until some backend waits on a lock the holder holds (holderPID = ANY(pg_blocking_pids(pid))). It returns (v, true) at once if the contender returns first, and fails after 30s if neither happens. Once the contender is observed blocked by the holder, it provably cannot finish before the holder ends.
  • LockWaiters and AwaitArrivalsOrLockWaits(ctx, db, parties, arrived, queryLike) form a race-test barrier. It opens once every party has either arrived or is observed waiting on a lock in a matching statement, never on a timeout. It reads arrived() before the lock query, so a party that moves between the two reads is missed for a round rather than counted twice.
Site (on origin/main) Window Change Mutation evidence (applied locally, reverted)
internal/scheduler/scheduler_test.go:1006 StaleHoursZeroDisablesBackgroundRefresh 200ms Runs in a synctest bubble. synctest.Wait() returns only once any refresh goroutine the call started has finished or is durably blocked, so a non-blocking receive afterwards is exact. Ignoring the stale-hours-0 sentinel in finishCacheRead: 50/50 FAIL
internal/auth/service_apikeys_test.go:719 ValidateUserAPIKey/successfully validate 2s Same synctest pattern; the case body moved into validateBooksNoUsage so it runs inside the bubble. s.RecordUsageAsync(key.ID) added to ValidateUserAPIKey: 50/50 FAIL
internal/server/apikey_usage_booking_test.go:176 (3 tests via requireExactlyOneBooking) 2s quiet + 10s positive All 3 tests run in a bubble. After synctest.Wait(), every flush has reached the store, so the test drains the channel and requires exactly [1]. Same mutation: 50/50 FAIL for each of the 3 tests (flushes wrote [3])
internal/server/app_rl_cleanup_test.go:104 CleanupWorkerOutlivesRequestCtx assert.Never 300ms Checks the positive half instead: Close must stop the worker while the request ctx is still live (then asserts reqCtx.Err() == nil). The #1137 call-site bug (dbRL.StartCleanupWorker(ctx) instead of app.startRateLimiterCleanup(dbRL)): 10/10 FAIL
internal/config/store_postgres_db_test.go:1499 claim races an uncommitted claim 300ms AwaitBlockedBy on the holder transaction. Slow-runner probe: a claim that sleeps 400ms and then answers from a read passes the old test and fails the new one
internal/config/store_postgres_ri_exchange_direct_db_test.go:160 finalize races an uncommitted finalize 300ms AwaitBlockedBy Same slow-runner probe (sleep 400ms, answer from a status read): old passes, new fails
internal/config/store_postgres_history_dedupe_integration_test.go:111 save races an uncommitted twin 500ms AwaitBlockedBy Slow-runner probe (sleep 600ms, skip the write): old passes, new fails
internal/api/handler_purchases_retry_ladder_integration_test.go:137 TrancheLockBlocksReconciler 1.5s The paused store records the Retry transaction's PID; then AwaitBlockedBy. FOR UPDATE dropped from LockLadderTrancheForRetryTx: FAIL (reconciler finished while Retry held the tranche row)
internal/api/handler_ladder_reconcile_retry_integration_test.go:139 TailLockBlocksRealRetryLink 1.5s Same, with the reconciler's chain-lock transaction as the holder. FOR UPDATE dropped from the chain locks: FAIL (retry linked while the reconciler held the tail row)
internal/api/handler_purchases_submit_dedupe_integration_test.go:36-41 insertBarrierStore (used by ConcurrentIdenticalSubmitsCreateOneRow and RetrySuccessorRacesFreshSubmit/forced) barrier gave up after 1s / 300ms AwaitArrivalsOrLockWaits on the per-creator pg_advisory_xact_lock; the wait field is removed. Per-creator lock in ListRecentSubmitsTx replaced by SELECT 1: both tests FAIL (2 rows / 2 pending rows)
internal/purchase/plan_provider_lock_integration_test.go:56 AttachedNeverExceedsShown barrier gave up after 500ms AwaitArrivalsOrLockWaits on the provider advisory lock (runProviderTicks now takes the pool). The test's own lock-free control still over-commits on every run (20/20 under -race)
internal/purchase/plan_step_attach_integration_test.go:193 PlansOnOneAccountNeverOverAttach barrier gave up after 500ms Same barrier. LockPlanProvidersTx made a no-op: FAIL (12 attached against 10 shown)

The slow-runner probes are the direct demonstration of the old false pass: each makes the contender non-contending and slower than the old window, the old test passes, and the new test fails. A side benefit: the locked runs no longer spend the full window on every waiting party (the attach race went from about 1.5s of barrier waits to 0.3s total), and the usage-booking and validate tests went from about 2s each to near zero.

The synctest conversions need testing/synctest (Go 1.25+; go.mod is 1.26.10), the same package the archera change uses.

Closes #36

Remaining sleeps, and why each stays

Re-grepped on this branch after merging origin/main (d71af683):

  • grep -rn --include=*_test.go 'time\.Sleep': 23 code hits, plus comments saying "no time.Sleep".
  • Every time.After(, time.NewTimer( and time.Tick( in *_test.go (about 80). An awk pass flagged each timeout case whose body does not fail the test; after this PR it flags only the two sites justified under "Remaining time.After and timer waits".
  • assert.Never/Consistently: none left.
  • lock_timeout/statement_timeout and short context.WithTimeout deadlines in tests.

For the frontend I grepped every setTimeout/waitForTimeout under frontend/src and frontend/tests-e2e, leaving out the zero-delay flushes.

Go: deadline-bounded poll loops (poll for a condition, fail at a deadline)

Location What it polls
tests/e2e/e2e_test.go:60 /health reports healthy (2s poll interval against a deployed app)
internal/server/http_shutdown_test.go:84 TCP dial until the test server is listening
internal/server/http_scheduled_context_test.go:173 same listen check
internal/server/scheduledauth/kidguard_test.go:216 retries until a JWKS fetch actually happens (hit counter changes)
internal/purchase/plan_step_fail_atomic_integration_test.go:151 pg_stat_activity shows the approval waiting on the row lock
internal/auth/store_postgres_admin_lock_db_test.go:94 pg_locks shows a backend queued on the advisory lock
internal/config/store_postgres_token_pin_cancel_db_test.go:131 pg_stat_activity shows a backend waiting on a row lock
internal/config/store_postgres_ri_exchange_approved_reservation_integration_test.go:158 two backends waiting on the advisory xact lock
internal/testutil/testutil.go:149 (WaitFor, non-test file) generic condition poll with a deadline

Each loop exits as soon as the observed state appears. The sleep is only the poll interval, so a slow runner makes the loop take longer instead of making the test fail.

Go: deliberate race staggers (the stagger is the input that varies interleavings)

Location Purpose
internal/api/ladder_resolve_race_integration_test.go:113,117 Rounds cycle through three schedules (all at once, finishers first, retries first) so both race orders happen. The test asserts the invariant on every round and asserts that each side won at least once.
internal/api/handler_purchases_retry_submit_race_integration_test.go:55,61 Lag on one side, alternating which side leads, so both orderings are covered
internal/purchase/plan_step_fail_atomic_integration_test.go:247 0-2ms stagger so the single-statement approval does not always land first (documented in place)
internal/purchase/token_rotation_pin_integration_test.go:152,158 alternating cancel/rotate lag
internal/config/store_postgres_token_pin_cancel_db_test.go:215,221 0-1.9ms alternating stagger (documented in place)
internal/database/postgres/migrations/000139_..._test.go:350 Paces a background insert stream that runs while the migration runs. The test checks the outcome (every streamed row is consistent, and the stream inserted more than zero rows), not a timing.

None of these sleeps waits for work to finish. Each start is coordinated by a start gate channel or a WaitGroup, and the sleep only spreads out the start times.

Go: database-clock aging (the DB's NOW() must move forward; a Go fake clock cannot do this)

Location Why
internal/database/advisory_lock_holder_integration_test.go:94 (1.2s) asserts the advisory lock's age read from Postgres is at least 1s
internal/config/store_postgres_no_submission_integration_test.go:72 (1.1s) updated_at is set by a trigger, so the row has to age past ListStuckExecutions's 1s floor
internal/config/store_postgres_service_config_stamps_integration_test.go:52 (5ms) NOW() is the transaction start, so the second save needs a later transaction to get a later stamp
internal/config/store_postgres_revocation_return_integration_test.go:107 (5ms) same, to prove the first return_posted_at stamp is kept

Go: simulated slow work against a real net/http timeout

  • internal/server/http_scheduled_context_test.go:96: the mock handler takes 400ms, longer than the server's WriteTimeout, which the test shortens to 100ms. The test checks that the per-route write deadline lets the response through. net/http enforces WriteTimeout against the real clock, so the handler really has to take longer than the timeout.

Go: remaining time.After and timer waits

  • Failure-only deadlines (the timeout branch calls t.Fatal, and a passing run returns as soon as the event arrives): every other case <-time.After(...) in the Go tests, for example internal/execution/fanout_test.go:157, internal/api/handler_history_test.go:467 and the 2-5s waits throughout the suites.
  • internal/purchase/execution_test.go:1276: a parallelism barrier whose timeout sets barrierTimedOut, which the test then asserts is false. The timeout only bounds the failure path.
  • internal/api/handler_purchases_revoke_claim_integration_test.go:79: inside the fake Azure Return client, waiting up to 10s for the other request to finish so the two interleave. If the timeout path is taken, the final assertions fail (one revoked, one in flight, exactly one Return), so it cannot hide a regression.
  • internal/config/store_postgres_ri_exchange_reservation_integration_test.go:143: the 10ms poll interval of a deadline-bounded pg_stat_activity poll that also fails at once if the reservation returns early. This is the same shape as AwaitBlockedBy.
  • internal/purchase/execute_detached_test.go:109 (callTime 1.2s): simulated provider-call duration measured against the real save budget. The time is the input.
  • Context deadlines that are the input, not a quiet window: internal/email/smtp_server_test.go:714 (a real stalled SMTP socket), internal/database/postgres/migrations/migrate_cancel_test.go:68 (a server that never finishes the handshake), internal/archera/provider_cancel_test.go:45, and internal/api/handler_insurance_comparison_test.go:356,415 (the resolver or vendor call blocks until the ctx ends, so ordering is guaranteed). Each asserts the code returns because of the deadline, with a failure-only outer timeout.
  • lock_timeout in internal/auth/store_postgres_admin_lock_db_test.go:272 and internal/config/store_postgres_ladder_lock_integration_test.go:197: production lock timeouts under test (the expected 55P03, or a hang fails fast). These are not quiet windows.

Frontend

  • Jest unit tests: after this PR the guard test finds no non-zero sleeps. The remaining setTimeout lines are zero-delay flushes (flushPromises and local flush helpers), jest.spyOn(global, 'setTimeout') assertions (archera-comparison, auth-mfa-login, history-deeplink), fake-timer tests, or comments.
  • frontend/tests-e2e/fixtures/recs.ts:304: a one-shot response delay that a spec can set to simulate a slow backend (the loading state under test). It is the input, not a wait.
  • frontend/tests-e2e/ri-exchange-confirmation.spec.ts:224,309 (page.waitForTimeout(2200/2500)): these are negative assertions. Before fix(frontend): announce RI exchange results and keep the exchange ID #1375 the exchange modal closed itself after 2s. These waits prove it now stays open past that window, so the test has to let the time pass. Playwright's page.clock could fast-forward instead; I did not change it because these specs cannot be run on this VM (see below), and TEST-04: Wall-clock sleeps for async synchronization (~90 frontend setTimeout waits, several Go sleeps) #36 covers unit tests.

Verification

Unit-level evidence (Go unit tests, jest with jsdom) for the archera and frontend changes. Real-Postgres integration evidence (testcontainers, Docker on this VM) for the converted race tests, run narrowly by name.

export PATH=$HOME/.local/go/bin:$HOME/go/bin:$HOME/.local/bin:$PATH
export AWS_CONFIG_FILE=/dev/null AWS_SHARED_CREDENTIALS_FILE=/dev/null AWS_EC2_METADATA_DISABLED=true
go build ./...                                   # ok
go vet ./... ; go vet -tags integration ./...    # ok
go test ./internal/archera/ -count=1             # ok
go test ./internal/mocks/ -count=1               # ok
go test ./internal/archera/ -run 'TestClient_ConcurrentCallersShareOneBuild$' -race -count=20 -v   # 20/20 PASS
go test ./internal/archera/ -race -count=20      # ok
golangci-lint run --allow-parallel-runners ./internal/archera/...   # 0 issues (v2.10.1)

Runtime of the test itself: 0.10s before (the sleep), 0.00s after.

Mutation probes. Each was applied to internal/archera/provider.go locally, run, and reverted; none is committed:

Mutation Result (-count=50) Failing assertion
A: drop the semaphore (release := func() {} instead of p.acquire(ctx)) 50/50 FAIL, no panics only one caller may build while the others wait (expected 1, actual 20)
B: drop the p.client.Load() re-check after acquire 50/50 FAIL, no panics waiters reuse the built client instead of rebuilding (expected 1, actual 20)

Mutation A first panicked with deadlock: main bubble goroutine has exited but blocked goroutines remain and took the package binary down (1 of 50 reported). The deferred drain fixes that, so both mutations now fail cleanly on every run.

Fixed-window conversions (after merging origin/main d71af683; final head is this PR's head):

go build ./... ; go vet ./... ; go vet -tags integration ./...      # ok
go test ./internal/{archera,scheduler,auth,server,mocks,database/postgres/testhelpers}/ -count=1   # ok, one package at a time
go test ./internal/scheduler/ ./internal/auth/ ./internal/server/ -race -count=20 \
  -run 'TestScheduler_ListRecommendations_StaleHoursZeroDisablesBackgroundRefresh$|TestService_ValidateUserAPIKey$|TestHandleRequest_UserAPIKey.*Book|TestReinitializeAfterConnect_CleanupWorkerOutlivesRequestCtx$'   # ok (each 20/20 before the merge too)
go test -tags integration -race -count=20 -run 'TestPostgresStoreDB_ClaimRIExchangeIdempotencyKey$|TestPostgresStoreDB_RIExchangeDirectExecution$|TestSavePurchaseHistory_ConcurrentSaveWaitsForUncommittedTwin$' ./internal/config/   # 20/20 each
go test -tags integration -race -count=20 -run 'TestPlanProviderLock_AttachedNeverExceedsShown$|TestAttachIntegration_PlansOnOneAccountNeverOverAttach$' ./internal/purchase/   # 20/20 each
go test -tags integration -race -count=20 -run 'TestRetry_TrancheLockBlocksReconciler$|TestLadderReconcile_TailLockBlocksRealRetryLink$|TestRetrySuccessorRacesFreshSubmit$|TestPersistExecution_ConcurrentIdenticalSubmitsCreateOneRow$' ./internal/api/   # 20/20 each
golangci-lint run --allow-parallel-runners ./internal/{scheduler,auth,server,archera}/...                         # 0 issues
golangci-lint run --allow-parallel-runners --build-tags integration ./internal/{config,api,purchase}/... ./internal/database/postgres/testhelpers/...   # 0 issues
gocyclo -over 10 internal/database/postgres/testhelpers/lockwait.go   # silent

The integration -race -count=20 runs were made on the pre-merge head b655a563. The merge touched none of these files, and the merged tree builds and vets with -tags integration. Mutation and slow-runner evidence is in the table above. All probes were applied locally, run, and reverted; none is committed.

Frontend (jest, with npm ci in frontend/):

npx jest src/__tests__/index.test.ts src/__tests__/no-wallclock-sleeps.test.ts --coverage=false   # 13/13 pass
npx eslint src/__tests__/index.test.ts src/__tests__/no-wallclock-sleeps.test.ts                   # clean
npx tsc --noEmit                                                                                   # clean
  • Guard fails before the fix: with index.test.ts restored from origin/main, the guard fails with "index.test.ts:121 sleeps 10ms". It passes on this branch.
  • Index test still guards its behavior: with the DOMContentLoaded -> init() listener in src/index.ts commented out locally (reverted, not committed), calls init on DOMContentLoaded fails.

Combined-tree verification (earlier head 2d229863, the archera and frontend commit only). Tested on a local, never-pushed tree: queue/platform @ 594ac3ec = origin/main ae6854b3 plus:

Branch Tested head
fix/issue-357-delete-cleanup-lambda 56989d8
fix/issue-36-archera-gate 2d22986
fix/issue-35-assert-api-a f793689
fix/issue-35-assert-api-b fac72f3
fix/issue-120-stale-rec-sweep 07c2e9c
fix/issue-981-summary-sql 7056746

Linux, Go 1.26.9, AWS_CONFIG_FILE=/dev/null AWS_SHARED_CREDENTIALS_FILE=/dev/null AWS_EC2_METADATA_DISABLED=true; Docker Postgres via testcontainers.

  • Passed: go build ./..., go vet ./..., go vet -tags integration ./... and the full go test -race -short -count=1 ./....
  • Static checks: golangci-lint v2.10.1 found 0 issues on every changed package, with and without --build-tags integration. gocyclo -over 10 is silent on the changed non-test files.
  • Integration tests (-tags integration -count=1, one package at a time): internal/api, internal/auth, internal/config, internal/scheduler, internal/server and internal/testutil pass.
  • Secrets: git-secrets on the changed files found nothing, and a planted fake key was flagged; scripts/test-git-secrets-allowlist.sh passes.

Combined-tree verification (head 7fc2b00). Tested on a local, never-pushed tree: queue/platform @ e0b2dcd0 = origin/main fd45080f plus fix/issue-36-archera-gate @ 7fc2b006.

Linux, Go 1.26.9, AWS_CONFIG_FILE=/dev/null AWS_SHARED_CREDENTIALS_FILE=/dev/null AWS_EC2_METADATA_DISABLED=true; Docker Postgres via testcontainers.

  • Passed: go build ./..., go vet ./..., go vet -tags integration ./... and the full go test -race -short -count=1 ./....
  • Static checks: golangci-lint v2.10.1 found 0 issues on every changed package, with and without --build-tags integration. gocyclo -over 10 is silent on the changed non-test files.
  • Integration tests (-tags integration -count=1, one package at a time): internal/api, internal/auth, internal/config, internal/database/postgres/testhelpers, internal/purchase, internal/scheduler and internal/server pass.
  • Secrets: git-secrets on the changed files found nothing, and a planted fake key was flagged; scripts/test-git-secrets-allowlist.sh passes.

Out of scope / not done

  • Playwright e2e specs were not run (no browsers on this VM). The two waitForTimeout negative assertions in ri-exchange-confirmation.spec.ts could move to page.clock in a follow-up if wanted.
  • internal/testutil.WaitFor polls every 100ms, which is coarse. It is a correct deadline-bounded poll, so I left it alone.
  • No production or frontend source changes.
  • internal/server/app_rl_cleanup_test.go no longer checks behaviorally that canceling the request ctx leaves the worker running; no deterministic signal exists for "a goroutine would have exited". The two failure modes are covered instead: the call-site regression is caught by the Close ordering, and startRateLimiterCleanup takes no ctx (pinned by TestStartRateLimiterCleanup_SurvivesRequestCtxAndStopsOnClose).

Maintainers: please mirror the issue's triage labels onto this PR: impact/internal, type/chore, triaged, priority/p3, severity/low, urgency/eventually, effort/m.

🤖 Generated with Claude Code

…00ms sleep

TestClient_ConcurrentCallersShareOneBuild relied on a resolver that slept
100ms so the 20 racing callers would overlap the build. It now parks the
resolver on a gate channel inside a synctest bubble: synctest.Wait proves
every caller is blocked (one in the resolver, the rest on the build slot)
before the test checks that only one build started, then opens the gate and
checks the waiters reused the cached client. Removing the semaphore or the
re-check after acquire fails it 50 out of 50 runs.

The frontend index test waited 10ms for an init call the DOMContentLoaded
listener makes synchronously; it now asserts directly. The no-wallclock-
sleeps guard missed that form (assertions inside a setTimeout block that
then resolves), so it now flags it too.

Closes LeanerCloud#36

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@IAmJSD IAmJSD added impact/internal Team-internal only type/chore Maintenance / non-user-visible triaged Item has been triaged priority/p3 Polish / idea / may never ship severity/low Minor harm urgency/eventually No deadline effort/m Days labels Oct 29, 2026
@coderabbitai

coderabbitai Bot commented Oct 29, 2026 •

Copy link
Copy Markdown
Contributor

Review in Change Stack →

Caution

Review failed

The pull request is closed.

Finishing Touches
🧪 Generate unit tests (beta)
  • Create a new PR
  • Autofix · Keep fixing CodeRabbit findings and required CI, and resolving merge conflicts

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

@IAmJSD

IAmJSD commented Oct 29, 2026

Copy link
Copy Markdown
Collaborator Author

Independent review (IAmJSD's agent, fresh context, given only the diff, the issue and the PR text): VERDICT: APPROVE 2d22986395172c2720c86d7623e2de4bc3420b1f

Blocking:

  • none

Non-blocking:

  • Closes #36 overclaims; it should say Refs #36, or the PR should finish the job. Issue TEST-04: Wall-clock sleeps for async synchronization (~90 frontend setTimeout waits, several Go sleeps) #36 names a Go negative assertion with a wall-clock window as its main risk ("the 20ms negative-assertion window can miss a slow wrongly-spawned goroutine (false green)") and recommends "inject a hook/channel for the negative assertion". That test lives on at internal/scheduler/scheduler_test.go:1006 (TestScheduler_ListRecommendations_StaleHoursZeroDisablesBackgroundRefresh). It is still select { case <-refreshed: t.Fatal(...); case <-time.After(200 * time.Millisecond): }, a fixed window that goes falsely green when a wrongly spawned refresh is slower than 200ms. It is a good candidate for the same synctest treatment: run staleListRecommendations inside a bubble, call synctest.Wait(), then make a non-blocking receive.

  • The "Remaining sleeps" inventory leaves out every select/time.After fixed window. It says it covered bare <-time.After waits ("none"), but these are not bare:

    • scheduler_test.go:1006 (200ms, the negative assertion above)
    • store_postgres_history_dedupe_integration_test.go:111 (500ms)
    • store_postgres_db_test.go:1499 (300ms)
    • store_postgres_ri_exchange_direct_db_test.go:160 (300ms)
    • plan_step_attach_integration_test.go:193 and plan_provider_lock_integration_test.go:56 (500ms "with the lock the others never arrive" waits)

    The three DB "must still be waiting" windows could poll pg_stat_activity/pg_locks, like the poll loops the body lists. If these stay as they are, list them with the reason, or keep TEST-04: Wall-clock sleeps for async synchronization (~90 frontend setTimeout waits, several Go sleeps) #36 open for them.

  • The Go grep count is slightly off: 29 hits, of which 6 are comment lines, not 4. This does not matter in practice.

Attacked:

  • Synctest correctness:
    • p.sem and release are created inside the bubble (NewProvider runs in it), and the select in acquire with context.Background() (nil Done) is durably blocking. So synctest.Wait() can't return before all 20 callers park.
    • wg.Go and synctest.Test both need Go 1.25 or later, and go.mod says 1.26.10.
    • The deferred openGate(); wg.Wait() drains the callers when a require fails.
  • Mutations, applied to provider.go in the scratch tree and reverted:
    • Mutation A (no semaphore: release, err := func() {}, error(nil)): -count=20 gives 20/20 FAIL on "only one caller may build", with no deadlock panic.
    • Mutation B (drop the p.client.Load() re-check after acquire): 10/10 FAIL on "waiters reuse the built client".
  • Ran go vet with and without -tags integration on internal/archera, go test -race -short -count=1 ./internal/archera/, and -race -count=30 on the new test: all pass. golangci-lint v2.10.1 on ./internal/archera/ found 0 issues.
  • Frontend:
    • Ran npm ci, then jest on index.test.ts and no-wallclock-sleeps.test.ts: 13/13 pass. eslint on both files is clean.
    • Fail-before: with index.test.ts restored from main, the guard fails with index.test.ts:121 sleeps 10ms.
    • SLEEP_BLOCK does not overlap SLEEP (one needs () => {, the other a bare resolver or () => r()), so nothing is double-counted.
    • index.ts:86 calls init synchronously from the listener, so the direct assertion is sound.

Body-stale:

  • "lists every remaining sleep with the reason it stays" and "bare <-time.After(... waits in Go tests (none)" are both incomplete. The select-with-time.After fixed windows listed above are not in the inventory.

Reviewer: rQ1. Bar while the maintainers are away (set by IAmJSD as acting owner): one approving independent review on the head, two for money, auth and security paths.

IAmJSD and others added 5 commits October 29, 2026 03:29
…ree race tests

The claim, direct-finalize and purchase-history race tests proved "the
contender waits on the uncommitted holder" by checking that it had not
returned after 300-500ms. A contender that never contends but is slow to
run (a loaded runner) passed that window and then answered after the holder
committed. Verified: a claim that sleeps 400ms and answers from a read passes
the old test and fails the new one; the same holds for the finalize and the
history save.

testhelpers.AwaitBlockedBy now polls pg_locks until a backend waits on a lock
the holder's session holds (pg_blocking_pids), and fails at once if the
contender returns first. testhelpers.AwaitArrivalsOrLockWaits and
LockWaiters back the race barriers converted next.

Refs LeanerCloud#36

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…and submit race tests

TestRetry_TrancheLockBlocksReconciler and
TestLadderReconcile_TailLockBlocksRealRetryLink proved "the other side
waits on the held row" by checking it had not returned after 1.5s. They now
record the paused transaction's backend and wait until a backend is blocked
by it (testhelpers.AwaitBlockedBy), failing at once if the other side returns
first. Dropping FOR UPDATE from LockLadderTrancheForRetryTx or from the chain
lock fails the matching test.

insertBarrierStore opened its barrier after a fixed 300ms/1s wait, so on a
slow runner an unguarded second submit could miss it and see the first one's
committed row. It now opens once both submits arrived or the missing one is
observed parked on the per-creator advisory lock. Dropping that lock fails
both tests that use the barrier.

Refs LeanerCloud#36

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
… waits

TestPlanProviderLock_AttachedNeverExceedsShown and
TestAttachIntegration_PlansOnOneAccountNeverOverAttach held each tick at a
barrier that gave up after 500ms. On a slow runner an unlocked tick could
miss the barrier and see the first tick's committed suppression, hiding the
over-commit the tests (and the lock-free control) depend on. The barrier now
opens once every tick has resolved or is observed waiting on the
per-provider advisory lock. A no-op LockPlanProvidersTx fails the attach test
(12 attached against 10 shown). The locked runs no longer spend 500ms per
waiting tick.

Refs LeanerCloud#36

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…t windows

Four unit tests asserted that something did NOT happen by waiting a fixed
time (200ms to 2s) and seeing nothing. A goroutine a loaded runner had not
yet scheduled passed that window.

- scheduler: the stale-hours-0 refresh check, the auth no-booking check on
  ValidateUserAPIKey and the server exactly-once usage booking checks now run
  in a synctest bubble. synctest.Wait returns only once every goroutine the
  call started has finished or is durably blocked, so a non-blocking receive
  afterwards is exact. Ignoring the disable sentinel, or booking usage on
  the validation path, fails every run (50/50).
- server: the reinit cleanup-worker test replaced assert.Never(300ms) after
  canceling the request ctx with the positive half: Close must stop the
  worker while the request ctx is still live. Starting the worker with the
  request ctx (the LeanerCloud#1137 call-site bug) fails it 10/10.

The three usage-booking tests and the no-booking check drop from about 2s
each to near zero.

Closes LeanerCloud#36

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@IAmJSD IAmJSD changed the title test: gate the Archera shared-build test with synctest instead of a 100ms sleep test: replace sleeps and fixed-window negative assertions with deterministic synchronization Oct 29, 2026
@IAmJSD

IAmJSD commented Oct 29, 2026

Copy link
Copy Markdown
Collaborator Author

Independent review (IAmJSD's agent, fresh context, given only the diff, the issue and the PR text): VERDICT: APPROVE 7fc2b006f4abdcf53021bb94b07f3981bd4bd815

Blocking:

  • none

Non-blocking:

  • internal/auth/service_apikeys_test.go (validateBooksNoUsage), internal/scheduler/scheduler_test.go (StaleHoursZeroDisablesBackgroundRefresh), internal/server/apikey_usage_booking_test.go (requireExactlyOneBooking): after synctest.Wait() the fake clock has not moved. If a regression put the surplus flush or refresh behind a timer (a debounce such as time.AfterFunc(d, flush)), that goroutine would be durably blocked on the timer, Wait would return, and the non-blocking receive would pass. This is no weaker than the old 2s/200ms windows, which would also miss a timer longer than the window. Adding time.Sleep(time.Hour); synctest.Wait() inside the bubble before the receive or drain would close that gap at no real-time cost.
  • internal/server/app_rl_cleanup_test.go:104: the "cancelling the request ctx leaves the worker running" half is now only covered structurally (startRateLimiterCleanup takes no ctx). A worker started on a ctx that ends when either the request ctx or the app ctx ends would pass the new test, but the old assert.Never would usually have caught it. The PR body's "no deterministic signal exists for a goroutine would have exited" is not quite right: the same synctest pattern used elsewhere in this PR would give one (cancel reqCtx, synctest.Wait(), then count workers), if newReinitTestApp can run in a bubble. This is a follow-up, not a regression risk on main today.
  • testhelpers.AwaitBlockedBy returns once any backend is blocked by holderPID, not specifically the contender. That is sound in every current caller, because the contender is the only other session that touches the holder's rows or locks. The doc comment could say that callers must ensure this.
  • Playwright ri-exchange-confirmation.spec.ts:224,309 still uses waitForTimeout negative windows. The body discloses this, and TEST-04: Wall-clock sleeps for async synchronization (~90 frontend setTimeout waits, several Go sleeps) #36 is about unit tests, so Closes #36 is fine.

Attacked:

  • Checked the head was still 7fc2b006 and reviewed the three-dot diff. The only non-test file is testhelpers/lockwait.go. I checked how AwaitBlockedBy uses pg_blocking_pids. In AwaitArrivalsOrLockWaits I checked the read order (no double count), the scoping to current_database, the LIKE pattern against ListRecentSubmitsTx/LockPlanProvidersTx, and pool headroom (4 ticks + 4 pollers ≤ 10 conns). I also checked that the pid is published before close(locked) (happens-before), that the done channels are buffered, and that t.Error (not Fatal) is used from goroutines.
  • Fail-before, all applied in the scratch tree and reverted:
    • s.RecordUsageAsync(key.ID) in ValidateUserAPIKey: auth test FAIL 10/10, and all 3 server booking tests FAIL 10/10.
    • finishCacheRead ignores disabled: scheduler test FAIL 10/10.
    • The re-check after acquire removed in archera/provider.go: FAIL 10/10 ("waiters reuse the built client").
    • Slow-runner probe (SavePurchaseHistory sleeps 600ms and skips the write): the origin/main test passes, the new test FAILs ("save returned while a twin was uncommitted").
    • Per-creator advisory lock replaced by SELECT 1: ConcurrentIdenticalSubmitsCreateOneRow and RetrySuccessorRacesFreshSubmit (both subtests) FAIL.
    • FOR UPDATE dropped from the tranche retry lock: TrancheLockBlocksReconciler FAILs.
    • Frontend: with index.test.ts restored from origin/main, the guard fails with index.test.ts:121 sleeps 10ms.
  • Ran on Go 1.26.10:
    • go build ./..., go vet ./..., go vet -tags integration ./...: ok.
    • go test -race -short -count=1 on archera, scheduler, auth, server, testhelpers: ok.
    • -race -count=20 on the converted unit tests: ok.
    • -tags integration -race -count=5 on the 9 converted integration tests: ok.
    • -tags integration -race -count=1 on all changed packages: all 8 ok (archera, scheduler, auth, server, testhelpers, config, purchase, api).
    • golangci-lint v2.10.1, with and without --build-tags integration: 0 issues. gocyclo -over 10 lockwait.go: silent.
    • jest on index.test.ts and no-wallclock-sleeps.test.ts: 13/13.

Body-stale:

  • none. I re-checked the claims: 23 time.Sleep code hits, no assert.Never or Consistently left, and no production code changed. The integration -count=20 runs on pre-merge head b655a563 are disclosed as such.

Reviewer: rR1. Bar while the maintainers are away (set by IAmJSD as acting owner): one approving independent review on the head, two for money, auth and security paths.

@IAmJSD

IAmJSD commented Oct 29, 2026

Copy link
Copy Markdown
Collaborator Author

Independent review (IAmJSD's agent, fresh context, given only the diff, the issue and the PR text): VERDICT: APPROVE 7fc2b006f4abdcf53021bb94b07f3981bd4bd815

Blocking:

  • none

Non-blocking:

  • internal/scheduler/scheduler_test.go:1028, internal/auth/service_apikeys_test.go:722, internal/server/apikey_usage_booking_test.go:162: synctest.Wait() also returns when a goroutine is durably blocked on a bubble timer. So these negative checks are exact against "the runner has not scheduled it yet", which is the TEST-04: Wall-clock sleeps for async synchronization (~90 frontend setTimeout waits, several Go sleeps) #36 concern, but not against a regression that refreshes or books after a delay (for example a debounced flush or a jittered refresh). No such delay exists today, so this does not block. Adding time.Sleep(10 * time.Minute) before synctest.Wait() would cover it at no wall-clock cost, because fake time advances instantly once everything is blocked.
  • internal/server/app_rl_cleanup_test.go:104: the PR body says the "cancel the request ctx and the worker keeps running" half is no longer checked directly. A worker started on a ctx that ends when either the request or the app ends would pass. It is acceptable because startRateLimiterCleanup takes no ctx.
  • internal/database/postgres/testhelpers/lockwait.go:134 and :173: the 30s deadline only bounds the poll loop. The pg queries use the caller's ctx (context.Background() at every call site), so if the pool is exhausted or a query hangs, the test hangs until go test -timeout instead of failing in 30s. The pools are big enough for the 2 to 4 parties here, so this is cosmetic.
  • internal/api/handler_purchases_retry_ladder_integration_test.go:110 and handler_ladder_reconcile_retry_integration_test.go:43: if the wrapped lock call errors, pid stays 0 and the failure reads "finished while ... held the row" when the real cause was a lock error. The test still fails, only with a misleading message.

Attacked:

  • Head confirmed at 7fc2b006, diffed three-dot against origin/main (fd45080f; the 3 main commits since the PR's merge base d71af683 touch none of these files; GitHub reports MERGEABLE/CLEAN). In the scratch worktree: go build ./..., go vet ./... with and without -tags integration, tests/e2e go vet -tags e2e all ok. golangci-lint v2.10.1 found 0 issues on all 8 changed packages, with and without --build-tags integration. gocyclo -over 10 lockwait.go silent. secrets-scan printed "clean; planted key flagged". The allowlist test gave 183 PASS. go test -race -short -count=1 passed on archera, scheduler, auth, server, testhelpers, api, config and purchase. -race -tags integration -count=5 on the 12 converted tests passed, plus a full -tags integration -race -count=1 run of each changed package: testhelpers, scheduler, auth, server, config, purchase and api all ok.
  • Mutation probes. Each was applied in my worktree, run, and reverted. Unit tests:
    • Stale-hours-0 sentinel ignored in finishCacheRead: 10/10 FAIL.
    • s.RecordUsageAsync(key.ID) added to ValidateUserAPIKey: auth 10/10 FAIL, and all 3 server booking tests 10/10 FAIL.
    • dbRL.StartCleanupWorker(ctx) at the test(server): pin the rate-limiter cleanup start in reinitializeAfterConnect #1137 call site: 10/10 FAIL.
    • archera with the semaphore dropped: 20/20 FAIL, no synctest panics. With the post-acquire re-check dropped: 20/20 FAIL.
  • Integration mutations:
    • FOR UPDATE dropped from LockLadderTrancheForRetryTx: 3/3 FAIL.
    • Per-creator submit lock replaced by SELECT 1: both dedupe tests FAIL.
    • LockPlanProvidersTx made a no-op: both attach tests 3/3 FAIL.
  • Fail-before for the false-pass claim: I made ClaimRIExchangeIdempotencyKey sleep 400ms and then answer from a plain read (a slow, non-contending claim). The old test from origin/main passes against it. The new test fails ("the claim answered true while a conflicting claim was still uncommitted").
  • AwaitArrivalsOrLockWaits: checked the read order (arrivals are read before lock waiters, so a party is never counted twice). Its pg_stat_activity filter is per-database, and the databases are per-test (requireSharedDatabase), so other tests cannot open the barrier early. The %pg_advisory_xact_lock% pattern matches ListRecentSubmitsTx and LockPlanProvidersTx.
  • Frontend: after npm ci, jest passed 13/13 on both files and eslint is clean. With index.test.ts restored from main, the guard fails with index.test.ts:121 sleeps 10ms. The index.ts:86 listener calls init() synchronously, so the direct assertion is right.
  • PR body inventory: the re-grep matches the body. There are 23 time.Sleep code hits at exactly the listed sites. Every remaining case <-time.After without an inline fail either bounds a failure path or is a poll interval. No assert.Never or Consistently remains.

Body-stale:

Reviewer: rR2. Bar while the maintainers are away (set by IAmJSD as acting owner): one approving independent review on the head, two for money, auth and security paths.

@IAmJSD

IAmJSD commented Oct 29, 2026

Copy link
Copy Markdown
Collaborator Author

Local verification at 7fc2b006f4abdcf53021bb94b07f3981bd4bd815 merged onto main (fd45080f), together with #1592 in that order (combined tree 6e67d09f, Linux, Go 1.26.10): go build ./..., go vet with and without -tags integration, the full go test -race -short -count=1 ./..., and go test -race -tags integration -count=1 on every changed package, against Docker Postgres. All pass. CI Success and pre-commit are green on this head, with 2 approving independent review(s) on it. Nothing was run against any cloud.

@IAmJSD
IAmJSD marked this pull request as ready for review October 29, 2026 04:40
@IAmJSD
IAmJSD requested a review from cristim as a code owner October 29, 2026 04:40
@IAmJSD
IAmJSD merged commit 43dd618 into LeanerCloud:main Oct 29, 2026
42 checks passed
@IAmJSD

IAmJSD commented Oct 29, 2026

Copy link
Copy Markdown
Collaborator Author

Merged by IAmJSD's agent at IAmJSD's request (IAmJSD is acting owner while the maintainers are away), under the bar IAmJSD set: 2 approving independent review(s) on 7fc2b006 (two required: money, auth or security path), green CI, and the combined-tree verification above. Squash-merged at exactly 7fc2b006f4abdcf53021bb94b07f3981bd4bd815.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

effort/m Days impact/internal Team-internal only priority/p3 Polish / idea / may never ship severity/low Minor harm triaged Item has been triaged type/chore Maintenance / non-user-visible urgency/eventually No deadline

Projects

None yet

Development

Successfully merging this pull request may close these issues.

TEST-04: Wall-clock sleeps for async synchronization (~90 frontend setTimeout waits, several Go sleeps)

1 participant