Closed bug report

Bridge-bound loopback request gives up at ~45s regardless of the bridge's declared per-verb timeout (pup_open_window declares 150s)

John Lauer · 2mo ago ·closed by John Lauer

Measured on winvm (ab 2.0.97, pup 2.0.390, 4 vCPU Azure VM) during pup's release sweep, 2026-09-04. pup's bridge.json declares timeouts.verbs.open_window = 150 and the CLI envelope even prints timeoutSeconds 150, but every slow open came back at a consistent 45-47s wall clock with: 'Browser bridge request failed: error sending request for url (http://127.0.0.1:8851/command...)' - a client-side send failure, not a verb timeout, with no timeout wording. Six occurrences: rt05-rt08 at 45-46s each, then rt06 and rt10 retried one at a time on an idle VM at 45s and 47s. In every case pup went on to create the window (it appears in pup_list_windows with its final title moments later), so the caller is told the open failed while the bridge succeeded - the worst possible split, since a retry with the same sessionId is then refused as owned, and a retry with a new one duplicates the window. Asks: (1) honor the bridge's declared per-verb timeout for the loopback HTTP call itself (or say which cap applies: it looks like a fixed 45s reqwest timeout on the bridge-bound request); (2) when the loopback call does time out, return errorCode bridge_request_timeout with the elapsed seconds and the declared budget, instead of a transport error string; (3) document the effective cap in the SDK so bridges can shape long verbs to it (pup is now returning early from slow navigations with a progress frame, per the measured-progress rule, so the verb stays under any sane cap - but the cap should still be honest).

2 Replies

John Lauer · 2mo ago

Retracting: the ~45s cap is pup's, not ab's. pup's own HTTP server had server.timeout = 45000, so Node closed the socket under any verb slower than 45s while the handler kept running; ab correctly reported the transport failure it saw ('error sending request'). Fixed in pup 2.0.391 (socket budget now 260s, above the longest declared verb). Ask (2) still stands on its own as a nicety - a bridge socket closing mid-verb would be clearer as errorCode bridge_connection_closed with the elapsed time - but nothing in ab caused this. Closing.

John Lauer closed this · 2mo ago
John Lauer · 2mo ago

Initial read from the ab code path (also true on 2.0.97): ab DOES apply the declared per-verb budget to the loopback HTTP call itself - browser_bridge_request resolves timeouts via bridge.json and sets reqwest .timeout(150s) for open_window, and a genuine timeout returns the structured timed_out/stillRunning envelope, never a transport string. 'error sending request' is reqwest's NON-timeout arm: the CONNECTION died mid-flight at ~45s - and your evidence agrees (the request reached pup, the window was created; it is the RESPONSE path that was lost). So the 45s cap is not an ab timeout constant; prime suspects are a socket/server timeout on the pup side (node http server socket timeout - node's server.timeout/requestTimeout/keepAlive settings on the bridge's listener) or something VM-level killing the idle-looking connection while pup works.

Plan, next release: (1) reproduce with a sleep-verb harness against a node bridge on winvm and pin who closes the socket (netstat + pup-side socket event logging will name the closer); (2) regardless of who closes it, ab will stop surfacing the bare transport string: a non-timeout send failure on a bridge call will return a structured errorCode bridge_transport_error with elapsedSeconds, the declared budget, and the 'the bridge may have COMPLETED the operation - check its state verb before retrying with a new sessionId' warning, since the succeed-but-report-failure split you hit is the real damage; (3) the SDK timeouts section will document the effective cap once measured. pup-side: worth checking whether your http server sets a socket timeout near 45s - if it does, raising it to your longest declared verb budget fixes the root cause today.

Log in to reply.