Log NYM mixFetch request lifecycle

CHANGELOG.md

@@ -2,6 +2,10 @@
 
 ## Unreleased
 
+- added: Log the lifecycle of every NYM mixnet request (method, host, path, duration, HTTP status or error, and in-flight count), plus mixFetch setup timing. A request that logs a start with no terminal line identifies the host whose request never returned, which the previous logging could not attribute. These log at `warn` so they survive the default `warn` log level and appear in a log export without the user first enabling verbose logging.
+- changed: Bound NYM mixnet requests to 6 concurrent overall and 2 per host. A single Avalanche wallet was measured opening 12 concurrent mixnet requests during one sync, and a full wallet list multiplies that; mix-fetch v1 has a history of serving one request per host at a time.
+- fixed: Reduce the NYM per-request timeout from 300 seconds to 60. At five minutes, a request the mixnet never answered held the send screen on "Calculating Fee" long enough to read as a permanent hang rather than an error.
+
 ## 2.47.1 (2026-07-17)
 
 - fixed: Revert `@nymproject/mix-fetch` to v1 (1.4.4), restoring the pinned gateway and network requester. The v2 stack shipped in 2.47.0 fails to complete small HTTPS JSON-RPC requests through most exit nodes and its exit-node auto-discovery rarely converges, which left wallets with NYM privacy enabled unable to sync or send.

src/io/browser/browser-io.ts

@@ -3,7 +3,7 @@ import { makeLocalStorageDisklet } from 'disklet'
 import { LogBackend, makeLog } from '../../core/log/log'
 import { EdgeFetchOptions, EdgeFetchResponse, EdgeIo } from '../../types/types'
 import { scrypt } from '../../util/crypto/scrypt'
-import { initMixFetch, mixFetchOptions } from '../../util/nym'
+import { nymFetch } from '../../util/nym'
 import { fetchCorsProxy } from './fetch-cors-proxy'
 
 // Only try CORS proxy/bridge techniques up to 5 times
@@ -49,15 +49,7 @@ export function makeBrowserIo(logBackend: LogBackend): EdgeIo {
       const { corsBypass = 'auto', privacy = 'none' } = opts ?? {}
 
       if (privacy === 'nym') {
-        const nymFetch = await initMixFetch(log)
-        return await nymFetch(
-          uri,
-          {
-            ...opts,
-            mode: 'unsafe-ignore-cors' as RequestMode
-          },
-          mixFetchOptions
-        )
+        return await nymFetch(uri, opts ?? {}, log)
       }
       if (corsBypass === 'always') {
         return await fetchCorsProxy(uri, opts)

src/io/react-native/react-native-worker.ts

@@ -17,7 +17,7 @@ import {
   EdgeFetchResponse,
   EdgeIo
 } from '../../types/types'
-import { initMixFetch, mixFetchOptions } from '../../util/nym'
+import { nymFetch } from '../../util/nym'
 import { hideProperties } from '../hidden-properties'
 import { makeNativeBridge } from './native-bridge'
 import { WorkerApi, YAOB_THROTTLE_MS } from './react-native-types'
@@ -176,16 +176,7 @@ async function makeIo(logBackend: LogBackend): Promise<EdgeIo> {
       const { corsBypass = 'auto', privacy = 'none' } = opts ?? {}
 
       if (privacy === 'nym') {
-        const nymFetch = await initMixFetch(log)
-        const response = await nymFetch(
-          uri,
-          {
-            ...opts,
-            mode: 'unsafe-ignore-cors' as RequestMode
-          },
-          mixFetchOptions
-        )
-        return response
+        return await nymFetch(uri, opts ?? {}, log)
       }
       if (corsBypass === 'always') {
         return await nativeFetch(uri, opts)

src/util/nym.ts

@@ -6,7 +6,7 @@ import {
   SetupMixFetchOps
 } from '@nymproject/mix-fetch'
 
-import { EdgeLog } from '../types/types'
+import { EdgeFetchOptions, EdgeFetchResponse, EdgeLog } from '../types/types'
 
 /**
  * Configuration options for the NYM mixFetch client.
@@ -18,10 +18,40 @@ export const mixFetchOptions: SetupMixFetchOps = {
     '5x6q9UfVHs5AohKMUqeivj7a556kVVy7QwoKige8xHxh.6CFoB3kJaDbYz6oafPJxNxNjzahpT2NtgtytcSyN9EvF@5rXcNe2a44vXisK3uqLHCzpzvEwcnsijDMU7hg4fcYk8',
   forceTls: true, // force WSS
   mixFetchOverride: {
-    requestTimeoutMs: 300000
+    // A healthy mixnet request measures 2-4 seconds. The previous 300000 (5
+    // minutes) meant any request the mixnet never answered held its caller for
+    // five minutes, which on the send screen reads as a permanently stuck
+    // "Calculating Fee" spinner rather than an error.
+    requestTimeoutMs: 60000
   }
 }
 
+/**
+ * Ceilings on how many requests are in the mixnet at once.
+ *
+ * mix-fetch v1 historically served one request per host at a time, which this
+ * module used to work around with a per-host queue. That queue was removed in
+ * 5916d9d2 on the understanding that 1.4.2 had fixed the limitation. Measured
+ * on an Android emulator, a single Avalanche wallet still opens 12 concurrent
+ * requests during one sync, and a wallet list the size of a real user's
+ * multiplies that. Bounding it keeps the tunnel inside a regime we have
+ * actually observed working, at a negligible cost given each request already
+ * takes seconds.
+ */
+const MAX_IN_FLIGHT_TOTAL = 6
+const MAX_IN_FLIGHT_PER_HOST = 2
+
+/**
+ * How long a request will wait for a slot before going anyway.
+ *
+ * The ceilings above are smoothing, not an invariant worth stalling on. If
+ * every slot is held by a request that will not answer, an unbounded queue
+ * would add its own multi-minute delay on top of the per-request timeout and
+ * recreate exactly the stuck "Calculating Fee" this change exists to prevent.
+ * Past this deadline the request proceeds and the log says it did.
+ */
+const MAX_QUEUE_WAIT_MS = 10000
+
 /**
  * Budget for `createMixFetch` itself (client start + gateway handshake).
  *
@@ -35,13 +65,182 @@ const SETUP_TIMEOUT_MS = 60000
 // MixFetch initialization state
 let mixFetchInitPromise: Promise<IMixFetch> | null = null
 
+// Number of mixnet requests currently awaiting a response. Reported on every
+// request line, since a request that never settles is only visible as a count
+// that never comes back down.
+let inFlightCount = 0
+
+// Distinguishes concurrent requests to the same host in the log.
+let requestCounter = 0
+
+// Requests waiting on a concurrency slot, oldest first.
+const waiting: Array<() => void> = []
+
+// In-flight count per host key, for the per-host ceiling.
+const hostInFlight = new Map<string, number>()
+
+/**
+ * The `host:port` a request will actually open, used to key the per-host
+ * ceiling. Falls back to the raw uri so an unparsable one still gets queued
+ * rather than bypassing the limit.
+ */
+function getHostKey(uri: string): string {
+  try {
+    const url = new URL(uri)
+    const port =
+      url.port !== '' ? url.port : url.protocol === 'https:' ? '443' : '80'
+    return `${url.hostname}:${port}`
+  } catch (error: unknown) {
+    return uri
+  }
+}
+
+function hasSlot(hostKey: string): boolean {
+  return (
+    inFlightCount < MAX_IN_FLIGHT_TOTAL &&
+    (hostInFlight.get(hostKey) ?? 0) < MAX_IN_FLIGHT_PER_HOST
+  )
+}
+
+/**
+ * Wait until this request is allowed into the mixnet, then reserve its slot.
+ *
+ * Returns true when the slot was granted by the ceilings, false when the
+ * deadline elapsed first and the request is proceeding regardless. The slot is
+ * reserved either way, so the counters stay honest.
+ */
+async function acquireSlot(hostKey: string): Promise<boolean> {
+  const deadline = Date.now() + MAX_QUEUE_WAIT_MS
+  let granted = true
+
+  while (!hasSlot(hostKey)) {
+    const remaining = deadline - Date.now()
+    if (remaining <= 0) {
+      granted = false
+      break
+    }
+    let timer: ReturnType<typeof setTimeout> | undefined
+    let wake: () => void = () => {}
+    await new Promise<void>(resolve => {
+      wake = resolve
+      waiting.push(resolve)
+      timer = setTimeout(resolve, remaining)
+    })
+    clearTimeout(timer)
+    // Drop our own resolver. `releaseSlot` drains the whole array, so this
+    // only matters when the deadline fired instead: without it, a stretch
+    // where nothing settles (exactly the case being diagnosed) would grow
+    // `waiting` without bound, since nothing else ever clears it.
+    const index = waiting.indexOf(wake)
+    if (index !== -1) waiting.splice(index, 1)
+  }
+
+  inFlightCount += 1
+  hostInFlight.set(hostKey, (hostInFlight.get(hostKey) ?? 0) + 1)
+  return granted
+}
+
+/**
+ * Release this request's slot and wake everyone waiting.
+ *
+ * Every waiter re-checks its own host ceiling in `acquireSlot`, so waking all
+ * of them is correct: the ones still blocked simply queue again. Waking only
+ * the head would stall the queue whenever the head is blocked on a busy host
+ * while a slot for some other host just came free.
+ */
+function releaseSlot(hostKey: string): void {
+  inFlightCount -= 1
+  const remaining = (hostInFlight.get(hostKey) ?? 1) - 1
+  if (remaining <= 0) hostInFlight.delete(hostKey)
+  else hostInFlight.set(hostKey, remaining)
+
+  const woken = waiting.splice(0, waiting.length)
+  for (const wake of woken) wake()
+}
+
+/**
+ * A path segment long enough to be an identifier rather than a route: an
+ * address, a txid, a public key, or an API key.
+ *
+ * Length is what separates the two, not character set. Route segments in the
+ * endpoints we call are short (`ext`, `bc`, `C`, `rpc`, `v2`, `api`, the
+ * 16-character `get_address_info`), while identifiers run 26 characters and up.
+ * The separator classes matter: hyphens for UUIDs, a colon for cashaddr-style
+ * `prefix:address`, underscores and dots for the rest.
+ */
+const IDENTIFIER_SEGMENT = /^[0-9a-zA-Z][0-9a-zA-Z._:-]{19,}$/
+
+/**
+ * Reduce a request URI to the part that is safe to write to a user's log.
+ *
+ * Query strings are dropped entirely because RPC endpoints carry API keys
+ * there. The path is kept, because two endpoints on one host are often
+ * different routes and telling them apart is the point of this logging, but
+ * any segment that looks like an identifier is masked: several chains put a
+ * wallet address or txid directly in the path, and these lines end up in
+ * user-uploaded support logs.
+ */
+function describeUri(uri: string): string {
+  try {
+    const { host, pathname } = new URL(uri)
+    if (pathname === '/') return host
+    const safePath = pathname
+      .split('/')
+      .map(segment =>
+        IDENTIFIER_SEGMENT.test(segment) ? '<redacted>' : segment
+      )
+      .join('/')
+    return `${host}${safePath}`
+  } catch (error: unknown) {
+    return '<unparsable uri>'
+  }
+}
+
+/**
+ * Reduce any URL embedded in free text the same way `describeUri` reduces the
+ * request target.
+ *
+ * Error messages from the fetch and Go layers routinely quote the whole
+ * request URL (`Post "https://host/tx/<txid>?apikey=...": context deadline
+ * exceeded`). Running them through the same reducer keeps one rule for what
+ * may reach a support log, so an identifier masked in the request label cannot
+ * reappear intact in the error text on the very same line.
+ */
+function redactUrlsInText(text: string): string {
+  return text.replace(/https?:\/\/[^\s"'<>]+/g, url => {
+    // Trailing punctuation belongs to the sentence, not the URL.
+    const trimmed = url.replace(/[.,:;!?)\]}]+$/, '')
+    return describeUri(trimmed) + url.slice(trimmed.length)
+  })
+}
+
+/**
+ * Render an error for the log, preferring the raw message.
+ *
+ * The mix-fetch v1 Go layer surfaces failures as opaque strings such as
+ * `panic:todo: extract error message`, where the real reason is discarded
+ * inside the library. Keeping the message verbatim is what makes those
+ * reports attributable to a specific host, so the text is preserved apart
+ * from query strings, which are the part that carries credentials.
+ */
+function describeError(error: unknown): string {
+  const text =
+    error instanceof Error
+      ? error.name === 'Error'
+        ? error.message
+        : `${error.name}: ${error.message}`
+      : String(error)
+  return redactUrlsInText(text)
+}
+
 /**
  * Initialize the NYM mixFetch client. Must be called before using mixFetch.
  * Safe to call multiple times - subsequent calls return the same promise.
  */
 export async function initMixFetch(log: EdgeLog): Promise<IMixFetchFn> {
   if (mixFetchInitPromise == null) {
-    log('Initializing mixFetch...')
+    log.warn('Initializing mixFetch...')
+    const setupStart = Date.now()
     const pending = createMixFetch(mixFetchOptions)
     // The timeout below can abandon this setup while it is still in flight.
     // Deliberately do NOT tear it down on late completion: `createMixFetch`
@@ -60,7 +259,9 @@ export async function initMixFetch(log: EdgeLog): Promise<IMixFetchFn> {
     })
     mixFetchInitPromise = Promise.race([pending, timeout])
       .then(mixFetchModule => {
-        log('mixFetch initialized successfully')
+        log.warn(
+          `mixFetch initialized successfully in ${Date.now() - setupStart}ms`
+        )
         return mixFetchModule
       })
       .catch(async error => {
@@ -73,7 +274,11 @@ export async function initMixFetch(log: EdgeLog): Promise<IMixFetchFn> {
         // eslint-disable-next-line @typescript-eslint/no-dynamic-delete
         delete (window as any).__mixFetchGlobal
         mixFetchInitPromise = null
-        log.error('mixFetch initialization failed:', error)
+        log.error(
+          `mixFetch initialization failed after ${
+            Date.now() - setupStart
+          }ms: ${describeError(error)}`
+        )
         throw error
       })
       .finally(() => {
@@ -83,3 +288,76 @@ export async function initMixFetch(log: EdgeLog): Promise<IMixFetchFn> {
   const mixFetchModule = await mixFetchInitPromise
   return mixFetchModule.mixFetch
 }
+
+/**
+ * Perform a single request over the NYM mixnet, logging its lifecycle.
+ *
+ * Every request writes a `start` line before it goes out and exactly one
+ * terminal line when it settles. A request that produces a `start` with no
+ * terminal line is one that never came back, which is the shape we cannot
+ * currently attribute to a host, and the reason this instrumentation exists.
+ *
+ * These go out at `warn` rather than `info` deliberately. The app configures
+ * the core with `defaultLogLevel: 'warn'`, so `info` is dropped unless the
+ * user has turned on Verbose Logging, and a QA log export would arrive with
+ * none of this in it. NYM is opt-in and low volume, so the extra lines only
+ * appear for the users whose reports we are trying to diagnose.
+ */
+export async function nymFetch(
+  uri: string,
+  opts: EdgeFetchOptions,
+  log: EdgeLog
+): Promise<EdgeFetchResponse> {
+  const mixFetch = await initMixFetch(log)
+
+  const id = ++requestCounter
+  const target = describeUri(uri)
+  const method = opts.method ?? 'GET'
+  const label = `mixFetch #${id} ${method} ${target}`
+
+  const hostKey = getHostKey(uri)
+  const queuedAt = Date.now()
+  const granted = await acquireSlot(hostKey)
+  const queuedMs = Date.now() - queuedAt
+
+  const start = Date.now()
+  const queueNote =
+    queuedMs === 0
+      ? ''
+      : granted
+      ? `, queued ${queuedMs}ms`
+      : `, queued ${queuedMs}ms then went over the limit`
+  log.warn(`${label} start (${inFlightCount} in flight${queueNote})`)
+  let released = false
+  const release = (): void => {
+    if (released) return
+    released = true
+    releaseSlot(hostKey)
+  }
+
+  try {
+    const response = await mixFetch(
+      uri,
+      {
+        ...opts,
+        mode: 'unsafe-ignore-cors' as RequestMode
+      },
+      mixFetchOptions
+    )
+    release()
+    log.warn(
+      `${label} -> ${response.status} in ${
+        Date.now() - start
+      }ms (${inFlightCount} in flight)`
+    )
+    return response
+  } catch (error: unknown) {
+    release()
+    log.error(
+      `${label} failed after ${
+        Date.now() - start
+      }ms (${inFlightCount} in flight): ${describeError(error)}`
+    )
+    throw error
+  }
+}