negotiate on a large repository takes ~7 s per request; one client polling it keeps the hub busy issue #228 closed: completed andymccall opened this · 3 comments
andymccall set labels performance ·
referenced by 6 changes on 17 Oct 2026
ed3a36b6414c fb8aafc64f9c a268d4df52bf 2bae995eb2f1 dbcb0b813caa f157bcea0e32
Fixed. Three causes, found with /health cloud_stores (now counted by kind): (1) a new cloud store client for every request, with serialised calls (oxygen a23729f0: one shared client per URL and credentials); (2) large packs read by range uncached (oxygen 24f95a3e: ranges and sizes kept on disk); (3) every read of a packed object first asked the bucket for a loose copy, a miss each time and never cached (oxygen b2952b8d: packs first). Negotiate on metalgear2 went from 7-8 s every 8 s to under the slow-request threshold; bucket requests from ~540 to ~30 a minute; no slow metalgear2 request in the hour after 05:07 on 2026-10-17. The proposals call's remaining stalls were the nightly gc rerunning on each restart (fixed in faf9b557).
andymccall closed ·
andymccall referenced by change 7e51c8a2d23c on main ·
Came back at 07:23 after a push to metalgear2: its client's negotiate then asked about ~190 objects the hub lacked, every 8 s, each a bucket miss (4 270 in three minutes, 9 s a negotiate). Fixed in oxygen bc32f9c5 (a shared cloud client remembers a missing key for 30 s, forgotten when this process writes it), deployed 08:10 (817c4aa5): 298 misses in three minutes, negotiate off the slow list after the cold start. Still visible: each request lists the bucket's packs when it opens the repository (~430 lists in three minutes); a candidate for the next round, not a stall today.
Still slow on metalgear2 (GCS) at 08:30, around a push by its client: GET …/oxy/v1/refs 9-10 s (three times), the push 12 s, the proposals list ~2 s. Negotiate itself stays fast (4.8 s once, after the push). Next candidates: refs and push reads (likely ref reads and pack listings per repository open, ~430 lists in three minutes), not started.
Seen on 2026-10-16 from 01:55: POST /doomsdayone/metalgear2/oxy/v1/negotiate took 6-8 s on every call (547 slow-request warnings in an hour, one about every 7 s), after a 52 s push; GET /api/v1/repos/doomsdayone/metalgear2/proposals and .../checks took 9-11 s; some unrelated pages (file views in andymccall/oxygenhub) were slow at the same time while Earth CPU was idle (load 0.6), and the hub process held about 7 GB RSS. Other pages stayed fast (health 0.1 s, overview 1.6 s).
To look at: what negotiate does per call on a repository with many heads/changes (cache the advertisement per state?), whether the proposals list and checks endpoints walk every proposal state, and whether a per-repository lock serialises readers. Also whether a client loop (an agent waiting on checks?) should back off: the hub could answer 429 with Retry-After.
Found during the overnight loop; not caused by that night’s changes (it predates them).