Skip to content

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

Description

@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>

Activity

  1. jvsena42 commented on Oct 6, 2026

    @jvsena42
    MemberAuthor

    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.

  2. ben-kaufman commented on Oct 6, 2026

    @ben-kaufman
    Contributor

    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.

  3. jvsena42 commented on Oct 6, 2026

    @jvsena42
    MemberAuthor

    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.

  4. jvsena42 commented on Oct 6, 2026

    @jvsena42
    MemberAuthor

    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)

  5. jvsena42 commented on Oct 6, 2026

    @jvsena42
    MemberAuthor

    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).

  6. jvsena42 commented on Oct 6, 2026

    @jvsena42
    MemberAuthor

    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)

  7. ben-kaufman commented on Oct 6, 2026

    @ben-kaufman
    Contributor

    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.

  8. jvsena42 commented on Oct 7, 2026

    @jvsena42
    MemberAuthor

    Relaunch at #1401 6ef9021 (rc68): slow in 7 of 12, and the split is explained by where the kill lands, not by idle time.

    Twelve single-device force-stop relaunches with 30–240 s idle on Home: seven took 64.7–68.3 s (one Deferred session restoration … concurrent_update at +35 s each), five took 12.4–16.0 s. Idle time does not separate them (30 s and 60 s slow on both devices, 100 s both outcomes, 240 s fast on both). What does: in all seven slow launches the old process had logged an SDK line within 0.15 s of the kill; in all five fast ones the SDK had been silent for 1–10 s. While idle the app does nothing at the app level; the SDK runs a poll round every 15–25 s (own-key Resolving homeserver at 3–4 lines/s) with 7–10 s quiet windows, so 74–100 % of idle seconds fall inside a round. Inferred: a process killed inside a poll round leaves a lock or lease on the homeserver, and the next launch waits about 30 s on it before concurrent_update.

    iOS at #856 5dd730b2 shows the same rate and shape (5 of 11 launches about 60 s, quiet ones included).

    Payments on rc68: swipe → broadcast 27.1 s when no poll was in flight, 41.2 s when the swipe landed during a link poll (proof upsert 11.1 s after the swipe instead of 1.8 s).

    Full tables and the log lines for a slow and a fast launch: #1401 (comment)

  9. piotr-iohk commented on Oct 7, 2026

    @piotr-iohk
    Collaborator

    Historical test results — earlier revisions (October 7, 2026). Tested iOS 5dd730b24930be3c7636b6e3b29f00f84f2a6f0e and Android 804e7547d3f0bf585d7dff36be8142ee5fa4afc0 (Paykit rc68). Both PRs have advanced since this run; these results have not been verified on the latest heads.

    Paired rc68 performance follow-up on Android 804e754, Stag8 with 63 contacts (original62 plus controlled Stag6). Different wallets and Pubky identities; staging/regtest.

    Session restoration timings:

    Repeated measurement Run 1 Run 2 Run 3
    Existing-profile relaunch 9.44s 9.50s 108.15s
    Post-sharing relaunch 6.40s 106.71s 6.15s

    Slow runs logged deferred restoration, concurrent_update, endpoint-refresh and wallet-backup warnings. All attempts eventually restored without reset. Measurements are launch-command start to session-restored log and include tooling overhead; background preparation remained active, so no verified quiet control was obtained.

    Important condition limit: early Android sharing timing sampled an optimistic checkbox while disabled, not completed update. Thus the first two post-toggle samples may overlap an unfinished update and are not controlled post-completion runs. The third ON tap was initially ignored while OFF was busy; that automation attempt was preserved and corrected. Native XML then proved checked=true/enabled=true by 24.65s, followed by a stop12s later and restoration in 6.15s. No app reset/reinstall was used. A verified quiet control was not obtained.

    Both 1,000-sat cross-platform request payments completed, with receiver credit, sender success and independent regtest confirmation. Android Send Request→Sent 9.60s, iOS reverse request 5.97s. Swipe→broadcast 8.01s Android payer /6.33s iOS payer. Incoming summaries appeared automatically, but exact preparation-to-ready time was not isolated. Some expected root IDs were omitted by the CLI; text/UI screenshots verified the flow.

    Contact deletion/re-addition completed by 13.79s /9.83s. Request/Pay after re-add was observed by 5m21.12s; warm Pay opened Amount by 7.10s. Earlier attempts used public fallback while private recovery continued. Re-link timings are sampled upper bounds.

    Sharing-OFF refusal worked in both directions: Android Pay to disabled iOS 3.15s, iOS Pay to disabled Android 2.82s. Early Android ON/OFF durations must be described only as checkbox-state changes, not completed withdrawal/publication; final ON validation used native enabled=true XML.

    Final Android Home: 99,859 sats Savings /0 Spending, Stag8 retained, counterparty saved, sharing ON. Contact-attributed activity and expected transaction fees verified. Full report and evidence are attached below. This does not approve #1401 or resolve hardware deadline recovery and other code-review findings. Quiet control, broader fault/payment cases and remote cleanup guarantees remain unverified.

    Full paired report and evidence ZIP

  10. ben-kaufman commented on Oct 9, 2026

    @ben-kaufman
    Contributor

    Reviewer measurements on #1451 at 04b0b0ec89a877d398d36f3cfa8f1d14b76abb22, using published Paykit rc72: review and recordings, with subsequent timing clarification.

    • Save-to-SDK-private-link-restoration took 47.1, 72.9 and 73.8 seconds. Request worked after background/resume, but there was no persistent linking-progress indicator. These were not measured Save-to-Request/Pay UI durations as initially described here.
    • In the last run, Save was at 02:07:58.245 UTC, public fallback while linking at 02:08:27.656, and private-link restoration at 02:09:12.017. Logs do not separate queue, SDK, intake or eligibility-discovery costs.
    • A separate debug-only 20-second hold confirmed admitted SDK work finished in background, later admissions paused, and the retained retry resumed without overlap. The first observation ended before the five-minute cooldown elapsed; the second passed.

    These are reviewer-reported Android-to-Android runs, not new author measurements or Bitkit-to-Server results. They are not isolated Noise handshake timings, and there is no matched base/head control proving the cause or a speedup.

    Both apps limit the extra targeted readiness refresh to the foreground-priority window, then rely on normal polling/contact lookup. Measuring that handoff separately from SDK queue, lock and network time remains useful. Persistent progress is also a separate UX follow-up.

    The reviewer withdrew the blocking objection to the scheduling PR because the recorded functional journey steps passed and the journey has no fixed latency assertion. This performance issue remains open; no safety wait was shortened and no performance target is claimed met.

  11. ben-kaufman commented on Oct 9, 2026

    @ben-kaufman
    Contributor

    Latest reviewer device evidence from #1451 remains a performance concern: the rolling report on 57a370e, updated October 9 at 10:15 UTC, records 53.070 seconds from Save to SDK private-link restoration without persistent progress; Request worked after resume, but J1 remains marked failed. Source: #1451 (comment) .

    A separate review run ended one Pay attempt at 74 seconds after Save; the next tap at 229 seconds opened Request or Pay within 11 seconds, with no checks in between. That does not establish a 229-second linking duration.

    New Android head 1c8f938 stops empty retries for confirmed missing peers and removes the scheduling-time SDK identity read from Contact Saved, while preserving queued delivery and fresh execution-time identity checks. These fixes passed 3,657 unit tests and baseline-compared lint, but have no new device latency measurement. They do not explain or resolve the reported end-to-end delay. Queue/SDK/intake/discovery attribution and persistent progress remain open; the 20-second window is a priority window, not a linking deadline.

  12. ben-kaufman commented on Oct 9, 2026

    @ben-kaufman
    Contributor

    New reviewer evidence from Android #1455 at 25f206a: Save returned immediately, background/resume completed, Request/Pay was first observed 192 seconds after Save, Request opened the amount screen, and the contact remained listed once.

    Pay was checked about every 20 seconds, using a fresh tablet counterpart. This is Save-to-first-observed Request/Pay, not an exact handshake-completion measurement. There is no matched control or queue/SDK/network breakdown. The paired iOS report used an older restored counterpart and a different polling interval, so the two times are not a platform benchmark.

    The controlled missing-to-linked recovery case was not reached. A separate no-homeserver fixture returned Transport, not NotFound. This functional pass and code approval do not resolve the latency/progress concern. Keeping this issue open.

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions