Skip to content

fix(profile)(sphere-sdk#551): swallow transient PROFILE_NOT_INITIALIZED + 2 soak-script fixes - #552

Merged
vrogojin merged 3 commits into
@vrogojin/uxffrom
fix/issue-551-profile-not-initialized-race
Jun 15, 2026
Merged

fix(profile)(sphere-sdk#551): swallow transient PROFILE_NOT_INITIALIZED + 2 soak-script fixes#552
vrogojin merged 3 commits into
@vrogojin/uxffrom
fix/issue-551-profile-not-initialized-race

Conversation

@vrogojin

Copy link
Copy Markdown
Contributor

Summary

  • Intermittent PROFILE_NOT_INITIALIZED race during sphere trader spawn on fresh wallets #551 PROFILE_NOT_INITIALIZED race in ProfileStorageProvider.writeEnvelope: re-check dbConnected after the set() await window AND catch transient PROFILE_NOT_INITIALIZED from the adapter, returning rather than propagating. The local cache write at the top of set() has already completed — the entry is durable — and the next save() re-emits the whole collection. Asymmetric-adapter config errors stay outside the try/catch.
  • soak rate-band fix (cherry-pick of fix(soak): trader-roundtrip default rate band must fit bob's hardcoded deposit #538's commit 60be0dc): default rate_max=0.09 so rate_max × volume_max = 4.5 ETH matches bob's hardcoded deposit (avoids VOLUME_RESERVATION_FAILED mid-soak).
  • soak agreed-volume assert fix: compare against $TRADER_VOLUME_UCT (human-decimal — what the deal API returns) instead of $EXPECTED_UCT_SMALLEST (the bigint smallest-units form used in §10 portfolio deltas). Also add BOB_AGREED_VOLUME cross-check + widen regex to accept fractional volumes.

Verification

Four soak runs against testnet, captured at /tmp/trader-soak-551/run{1..4}.log:

Run What §3 spawn §8 settle §9 volume Total
1 #551 fix only OK — (stopped at §7 rate-band) partial
2 #551 + rate-band OK FAIL (verifyPayout thrash) partial
3 + cherry of #534 from main OK OK FAIL (wrong-units cmp) 17/18
4 + agreed-volume fix OK OK OK 18/18 ASSERT OK

Run 2 → 3 transition was the deeper investigation: /home/vrogojin/sphere-sdk was on debug/market-log-body at 8c7d93d, pre-a063d4b7 (#534). The trader docker build context pulls from that path. Resetting sphere-sdk to current main + re-cherry-picking my fixes + rebuilding the trader image as trader:v0.6-fix551-fix534 (also retagged v0.6 / v0.2) unblocked §8.

Run 4 — final scorecard:

ASSERT OK (faucet)
ASSERT OK (escrow-reachable)
ASSERT OK (market-api-reachable)
ASSERT OK (alice-trader-spawn)         <- #551 fix
ASSERT OK (bob-trader-spawn)           <- #551 fix
ASSERT OK (alice-tenant-deposit-uct)
ASSERT OK (bob-tenant-deposit-eth)
ASSERT OK (alice-intent-listed)
ASSERT OK (bob-intent-listed)          <- rate-band fix
ASSERT OK (deal-completed)             <- #534 (already in main)
ASSERT OK (agreed-rate-matches)
ASSERT OK (agreed-volume)              <- agreed-volume fix (this PR)
ASSERT OK (uct-deltas)
ASSERT OK (eth-delta-symmetry)
ASSERT OK (eth-delta-in-band)
ASSERT OK (alice-no-failed-deals)
ASSERT OK (bob-no-failed-deals)
ASSERT OK (poison-pill-clean)

grep -c PROFILE_NOT_INITIALIZED run4.log = 0.

Tests

  • 4 new unit tests in tests/unit/profile/profile-storage-provider.test.ts:
    • putEntry throws PROFILE_NOT_INITIALIZED → set() resolves, cache holds value
    • legacy raw put() throws PROFILE_NOT_INITIALIZED → same outcome
    • dbConnected flips false mid-encrypt() → OpLog write skipped
    • non-PROFILE_NOT_INITIALIZED errors still propagate
  • Full tests/unit/profile + tests/unit/modules/Communications* (2407 tests) passes.

Relationship to other open PRs

Test plan

  • Unit tests pass (2407 tests, full profile + communications scope)
  • Soak passes 18/18 ASSERT OK (run 4)
  • #551 reproducer cleared 4/4 runs (no PROFILE_NOT_INITIALIZED across all attempts)
  • Trader docker image rebuilt + retagged

vrogojin added 3 commits June 15, 2026 15:37
…ITIALIZED in save() chain

`sphere trader spawn` intermittently crashes the host on a fresh wallet's
first inbound DM with `PROFILE_NOT_INITIALIZED` from
`OrbitDbAdapter.ensureConnected`. Stack trace ends inside an `async
CommunicationsModule._doSave` invoked via the fire-and-forget
`this.save('raw')` at `handleIncomingMessage` (lines 741, 798). Between
the synchronous `dbConnected` snapshot in `ProfileStorageProvider.set()`
and the actual `db.putEntry` call, the underlying adapter's `connected`
flag can flip — typically during a teardown or while the adapter is
briefly recycling during reconnect. The throw propagates through the
save chain.

Fix at the actual fire-and-forget owner. `CommunicationsModule.save()`
wraps the chained `_doSave` promise with a catch that swallows
`PROFILE_NOT_INITIALIZED` (warn + return) but re-throws every other
error. The in-memory messages Map IS the durable record: every save()
re-emits the entire collection, so the next successful save catches up
the OpLog without data loss.

Architectural reasoning — why not at the storage layer
=====================================================

An earlier draft of this fix caught the throw inside
`ProfileStorageProvider.writeEnvelope`. Code review (PR #552 — sweep
angles A/B/C/D) surfaced that the storage-layer swallow silently breaks
`AutoReturnLedger.save(critical=true)` and the write-first rollback
contract in `auto-return.ts:recordIntent / incrementRetry /
resetToPending / prune`. Those callers depend on `storage.set()`
throwing to trigger in-memory rollback; swallowing at the storage layer
produces multi-device ledger divergence (a phantom 'pending' auto-
return entry that only the local device knows about, leading to
potential double-refund when a sibling device runs its own auto-return
against the same target invoice).

`ProfileStorageProvider.set()` strict-throw semantics are now
preserved. The catch lives at the single site that actually fires
fire-and-forget — `CommunicationsModule.save()` (callers:
`handleIncomingMessage`, `transport.onReadReceipt`).

The discriminator `'code' in err && err.code === 'PROFILE_NOT_INITIALIZED'`
duck-types so this works even if `ProfileError` resolves to different
class instances across bundle boundaries (tsup builds emit duplicate
`ProfileError` definitions in each entrypoint bundle).

Tests
-----

3 new tests in `tests/unit/modules/CommunicationsModule.storage.test.ts`:
  - sendDM swallows transient PROFILE_NOT_INITIALIZED from storage.set
  - save() still propagates non-PROFILE_NOT_INITIALIZED errors
  - incoming-DM handler does not crash on PROFILE_NOT_INITIALIZED
    (drains the save chain and asserts no rejection)

Full `tests/unit/profile` + `tests/unit/modules/Communications` +
`tests/unit/modules/AccountingModule` (2923 tests) passes.
…d deposit

The default trader-roundtrip soak hung at §8 because bob couldn't fund
the negotiated price. Surfaced while running the soak to validate
sphere-sdk#535 (PR #536).

Math
----
Soak hardcodes bob's deposit at 4.5 ETH (§5, `sphere payments send
"@$BOB_TRADER_TAG" 4.5 ETH`). Bob's BUY intent declared rate band
`[0.08, 0.12]` and volume 50 UCT, meaning bob promised to honor any
negotiated rate in that band — so up to `0.12 × 50 = 6 ETH`. Trader-
service's NP-0 matcher (`trader-main.ts:355-364`) picks the midpoint of
the overlap, which for two identical `[0.08, 0.12]` bands is `0.10` →
bob owes 5 ETH. Reservation correctly refuses (4.5 < 5) and the deal
goes terminal with `VOLUME_RESERVATION_FAILED`.

Unit handling along the way is correct, per the project convention:

> Intents work in human-readable decimal strings; actual swaps work in
> exact bigint smallest-units.

`trader-main.ts:489-493` does `Number(volume) × Number(rate)` (decimal
strings → JS number for the ratio computation) → `toSmallestUnitsBigInt`
at the wallet-reservation boundary. The bug is purely that bob posted an
intent he couldn't honor at his own declared upper bound.

Fix
---
Narrow the default rate_max from `0.12` to `0.09` so the upper-bound
exposure `rate_max × volume_max = 0.09 × 50 = 4.5 ETH` exactly matches
bob's deposit. With overlap `[0.08, 0.09]` both sides, the midpoint is
`0.085`, so bob owes `4.25 ETH` and the reservation passes with a
0.25 ETH cushion.

Empirically verified by re-running the soak with this fix: alice's
trader proposals now fire at rate `0.08499999999999999` (vs the prior
`0.10`), with no `VOLUME_RESERVATION_FAILED`.

Documentation updates
---------------------
- Soak header: `bob -~5 ETH` → `-~4.25 ETH` (the new accurate expected
  outcome under the narrowed band).
- Env contract docstring: rate_max default `0.12` → `0.09`, with the
  full `rate_max × volume_max ≤ bob's deposit` invariant explained so
  future operators don't reproduce this trap.
- Inline comment at the new default points at trader-service#29, which
  tracks the upstream defensive fix (pre-flight check that refuses to
  create an intent the trader can't fund at rate_max).

Related
-------
- trader-service#29 — defensive pre-flight balance check (independent;
  this commit unblocks the soak now without waiting on the upstream
  fix).
- PR #536 / issue #535 — the original reason this soak was being run.
  The swap-CLI soak already validated PR #536 end-to-end; this fix
  unblocks the trader-CLI path too once stale market intents from
  prior failed runs expire (not addressed here; orthogonal market-feed
  isolation issue).
…decimal field against smallest-units

§9 read the `volume` field from `sphere trader list-deals --json` (which is
HUMAN-DECIMAL, matching the intent surface — same convention called out in
sphere-sdk#534 commit msg: "intents work in human-readable decimal strings;
actual swaps work in exact bigint smallest-units"), then compared it against
$EXPECTED_UCT_SMALLEST (50000000000000000000 for the default 50 UCT × 10^18).

That assert had never matched. False-negative since §9 was added.

Two changes:

1. Compare against $TRADER_VOLUME_UCT (the human-decimal source) instead of
   the smallest-units form. §10's portfolio-delta asserts still use
   $EXPECTED_UCT_SMALLEST because `sphere trader portfolio --json` actually
   does return smallest-units bigints — that contract differs by surface.

2. Add a BOB_AGREED_VOLUME cross-check mirroring the existing
   ALICE_AGREED_RATE / BOB_AGREED_RATE symmetry check. Catches a class of
   half-completed deal where one side records the agreed terms but the
   other only has a stale ACCEPTED snapshot.

3. Widen the regex to accept fractional values so a future partial-fill
   negotiation surface still matches. Whole-volume single-fill (the
   current intent shape) still parses identically.

Validated against the captured run-3 JSONs at
/tmp/trader-roundtrip-551-3/snapshots — both sides extract volume="50" and
the new assert returns OK.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant