Contact payment latency on staging with the shared Paykit runtime: pin paykit-rs#171 and re-measure

[jvsena42]

Follow-up from #1401, Android twin of synonymdev/bitkit-ios#868. With the shared Paykit runtime on paykit rc62, contact-payment actions complete but are slow against the staging homeserver. The author's trace points at the SDK queue and the per-transaction homeserver lock (background private-list preparation holding the queue 33–36 s, a full refresh holding the repository mutex 79 s); pubky/paykit-rs#171 targets the lock cost. This issue tracks pinning a paykit release that contains #171, re-measuring, and adding progress feedback to the bell Pay tap.

Measured on staging at #1401 head 0eaae43 (two emulators, fresh linked pair). Nothing failed: no crash, lease expired, RequestUnavailable or timeout lines.

Action	0eaae43
First link after both sides save the contact	3 min 36 s – 4 min 10 s; Request or Pay within 5 min 39 s
Send Request → "Payment requested"	≤ 62 s one way, 152–177 s the other
Bell Pay tap → confirm screen	121 s, Home shows no spinner or progress
Swipe → broadcast	82.7 s
Contact payments off	278–341 s
Contact payments on	≤ 54 s
Cold launch, nothing pending → session restored	35–40 s
Relaunch right after a sharing change → session restored	137 s and 436 s, four Failed to initialize paykit (concurrent_update / shared_state_busy) each
Relaunch → Request or Pay offered	2 min 39 s and 9 min 13 s
Delete a linked contact	45 s
Own-key Resolving homeserver log lines at idle, pair linked	154–163/min (cache hits included; master logs 0)

Done when, on staging, Send Request reaches "Payment requested" within ~10 s, the bell Pay tap shows the confirm screen within 3 s or shows progress while it prepares, contact payments off completes within ~30 s, and Request or Pay is offered within one maintenance round (~60 s) of a cold launch.

Journey to reproduce

<journey name="Contact Payment Latency">
  <description>
    Measures how long contact-payment actions take against the staging homeserver. Requires two Bitkit instances saved as each other's contacts and linked as identities, with contact payments on, both on the staging homeserver. Same journey as bitkit-ios issue 868, with the bell Pay and relaunch steps added.
  </description>
  <actions>
    <action>Force-quit Bitkit on device A, launch it, and note the launch time</action>
    <action>Every 2 minutes, open the contact for device B from Contacts and tap Pay (id "ContactPay"); record the first time the Request or Pay sheet (id "RequestOrPaySheet") appears instead of the amount screen, and verify it is within 60 seconds of launch</action>
    <action>Tap Request, enter 1,000 sats, tap Send Request and record the time until "Payment requested" (id "PaymentRequestSent") appears; verify it is within 10 seconds</action>
    <action>On device B, idle on Home, record when the payment requests bell (id "PaymentRequestsBell") appears; tap it, tap Pay on the request row, and record the time until the Payment Request confirmation screen (id "PaymentRequestConfirm") appears; verify it is within 3 seconds or that progress is shown while it prepares</action>
    <action>On device A, open Settings, General, turn off Enable payments with contacts (id "ContactPaymentsToggle") and record the time until the switch is enabled again showing off; verify it is within 30 seconds and no error toast appears</action>
    <action>Turn Enable payments with contacts back on and record the time until it settles on</action>
    <action>Force-quit Bitkit on device A as soon as the switch settles, launch it, and record the time until the contact for device B offers the Request or Pay sheet; verify it is within 60 seconds and that no "Failed to initialize paykit" line is logged</action>
  </actions>
</journey>

[jvsena42]

Numbers at #1401 5310b75 (rc62), two emulators on staging, linked pair:

Action	5310b75	0eaae43
Send Request → "Payment requested"	29–41 s, 57–70 s, 71–85 s	≤ 62 s, 152–177 s
Request reaches the receiver (automatic sheet)	32–40 s and 114–134 s after "Sent"	n/a
Automatic sheet preparing → ready	150–158 s, spinner shown	n/a
Bell Pay tap → sheet / → ready	< 3 s / 42 s (already resolved once in the background)	121 s, no progress
Swipe → broadcast	74.2 s, 73.4 s	82.7 s
Contact payments off / on	119–145 s / 36–52 s	278–341 s / ≤ 54 s
Force-stop relaunch → session restored	140 s on both, four Failed to initialize paykit (concurrent_update) each	137 s, 436 s
Relaunch → Request or Pay offered	≤ 3 min 9 s, ≤ 4 min 44 s	2 min 39 s, 9 min 13 s

The missing progress on the Pay tap is fixed by b101e89: the sheet opens at once with a spinner. The waits themselves are still far from the targets above.

New detail on the relaunch window: while the session is restoring, a bitkit://contact deeplink for an already saved contact opens Add Contact with a placeholder name and a Save button (Falling back to placeholder contact), and Home activity rows lose the contact name.

[ben-kaufman]

The PR now uses published rc63. The latest measurements are here: #1406 (comment). With the rc63 SDK source, incoming preparation took 3.502s, request sending 15.553s, and sharing OFF 41.247s including 6.527s waiting in the app queue. These were individual traced runs, not matched controls or a funded end-to-end payment. The send/withdrawal targets, cold-start eligibility and contact/deeplink behavior still need the comparable rc63 device check, so this stays open.

[jvsena42]

Numbers at #1401 bde1523 with paykit rc63, two emulators on staging, fresh identities:

Action	rc63	rc62	Target
Send Request → "Payment requested"	13–40 s	29–107 s	~10 s
Request reaches the receiver (sheet opens)	2–30 s after "Sent"	32–134 s	n/a
Automatic sheet preparing → ready	≤ 12 s, 5–17 s	108–158 s	3 s
Bell Pay tap → ready	4.8 s	42 s, 189 s	3 s
Swipe → broadcast	39–47 s	70–87 s	n/a
Contact payments off / on	32–50 s / 16–30 s	119–145 s / 36–52 s	~30 s
Relaunch → session restored	14.6 s without a lock conflict; 73–82 s with one concurrent_update	35–43 s quiet, 140 s after a force-stop	n/a
Relaunch → Request or Pay offered	≤ 1 min 44 s, ≤ 2 min 52 s	3–5 min	~60 s
First link, fresh pair	≤ 2 min 46 s	≤ 5 min 39 s	n/a
Delete a linked contact	16.7 s	45 s	n/a
Idle own-key Resolving homeserver, pair linked	112–147/min	~155–160/min	n/a

Close to target now: bell Pay → ready and contact payments off. Still above: Send Request, swipe → broadcast, and the time until Request is offered after a launch or a new link.

New on rc63: a relaunch that hits one concurrent_update (Deferred session restoration, PubkyRepo.kt:464) takes 73–82 s to restore, which is slower than a quiet relaunch was on rc62. In this run both devices were relaunched within 1.3 s of each other; a single-device relaunch still needs measuring. Until the session restores, contact deeplinks are dropped and a contact Pay tap can spin and return with no sheet.

[jvsena42]

Single-device relaunch measured at #1401 bde1523 (rc63): force-stopping and relaunching one device alone takes 82 s to restore the session, on both emulators, with Deferred session restoration … concurrent_update (PubkyRepo.kt:464) at +63 s and 142 own-key Resolving homeserver lines in the minute before it. So the slow relaunch is not two devices contending; it looks like the new process waiting on the shared-state lock left by the killed one. Timestamps: #1401 (comment)

[jvsena42]

Relaunch at #1401 d56c3f7: all eight launches restored in 10.7–13.1 s, against 82 s at bde1523.

Edited: I first wrote "fixed" here. On the next head, 51e26b0, 4 of 8 launches were slow again: Deferred session restoration … concurrent_update (PubkyRepo.kt:481) at about +35 s, restored after 52–65 s; the other four took 11–13 s. So the Android-only extra initialization removed in d56c3f7 cut one wait (82 s → about 60 s) but the lock conflict at launch is intermittent and still open. Table: #1401 (review)

Still above target on rc63: Send Request (13–40 s), swipe → broadcast (39–47 s), and the time until Request is offered after a launch or a new link (up to 2 min 52 s).

[jvsena42]

Numbers at #1401 9083227 with paykit rc65 (two emulators, staging, identities carried over from rc63): payments and sharing are unchanged from rc63 within sample spread (Send Request 15–26 s, bell Pay → ready 5–7 s, swipe → broadcast 41–44 s, sharing off 33–69 s, idle lookups 111–145/min).

Relaunch is slow in 5 of 10 on rc65. Ten single-device force-stop relaunches, each after about 90 s idle: five restored in 11.1–12.4 s, five in 64.2–64.8 s. Every slow one has Deferred session restoration … concurrent_update (PubkyRepo.kt:481) 34–36 s after process start, then Backup failed for: WALLET [concurrent_update], and the retry restores about 30 s later. Fast and slow launches run the same sequence up to the second grant exchange (+5 s); the slow one then logs nothing from the SDK except Resolving homeserver for about 29 s. The slow launches followed a predecessor process that had lived 100–102 s, the fast ones 110–158 s (pattern only).

iOS at #856 f79cfcbc shows the same when relaunched 12–38 s after a write: 62–69 s, and 6 min 2 s once with shared_state_busy (the five-minute uncertain-write wait). So on both platforms the slow launch follows killing the app shortly after it wrote shared state.

Full tables: #1401 (review) and synonymdev/bitkit-ios#856 (review)

[ben-kaufman]

Thanks for the repeated rc65 measurements. This is now confirmed on both platforms, so the earlier Android-only explanation was incomplete. I am keeping this issue open: the logs distinguish ordinary ConcurrentUpdate retries from the longer pending-write safety wait, but do not identify the exact interrupted operation that left the state busy. We should not shorten those waits or clear markers based only on elapsed time.

The atomic contact restore in rc65 removes the per-contact import/rollback writes. It does not claim to fix this cold-launch delay. The separate re-import retest and these cold-launch targets still need verification.