Skip to content

6.30.1 - An idle redirect pin, and three lines that were misread

Choose a tag to compare

@superuser404notfound superuser404notfound released this 17 Aug 18:12
· 714 commits to main since this release

Drop-in from 6.30.0. No public API change, which is why this is a patch: one reader behaviour fix on the redirect-pin path, and three diagnostic lines that a field trace had been misread through.

An idle pin is dropped by its first refusal

6.29.0 bounded the keep-pin grace: three paced rate-limited attempts against a pinned redirect target, then one re-resolve through the source (#380, #381). The 6.30.0 field retest of that change was clean, and it also priced what the grace still costs. After a 332 s pause the ladder walked 509, 509, 509, dropped the pin, and had first data 417 ms later, which is 12.5 s of media time between the first refusal and the byte that ended it. The player never saw it, but only because 16 MB of read-ahead absorbed it. The same pause taken right after a seek is visible.

Those three attempts were spent on an explanation that a long idle rules out. The grace exists for one shape, #307's lingering slot: a connection-capped panel answers 509 while the slot of the connection this reader has just replaced is still occupied server-side, and it clears in seconds. That requires a byte of ours to have been in flight moments ago. The pump ends its connection at the window high water (#310), so a reader that has delivered nothing for a minute holds nothing at the origin for a slot to linger on, and what refuses there is the other shape, the lease that died during the pause.

So past the idle gap the first rate-limited refusal drops the pin, and the attempt that follows is not paced behind a backoff charged to an address it is no longer using. A server-sent Retry-After still applies, since the source belongs to the same origin.

The shape a resume after a long pause leaves in the log on this release, where 6.30.0 spent three refusals and two backoffs first:

[AVIOReader] pump gen=5 rejected response status=509 at offset 84909512 from the pinned target <edge>
[AVIOReader] Dropped resolved URL cache (rate-limited after 337s idle through pinned URL)
[AVIOReader] pump conn start gen=6 offset=84909512 len=32MB re-resolving through the source
[AVIOReader] Cached resolved URL host=<edge>

A pin that is still alive pays nothing. Only what happens after a refusal changes; how a healthy request is issued does not. That is the reason this shape shipped rather than the stronger one the report suggested, which would spend an idle pin through the source preemptively and pay a portal round trip on every resume, including the common one where the pin is fine (717 ms at open against 38 to 134 ms through the pin, in the same trace).

Two things fell out of building it:

  • The idle needs its own clock. The reader already had a last-delivery timestamp, but startPersistentConnection rebases it, so at the moment a refusal is judged it always reads as fresh. The new one is stamped wherever bytes cross the network and nowhere that serves from memory. Wall time, not uptime: a lease expires in wall time, and a device that slept through the gap has let it expire too.
  • The detour cache's rate-limit arm had no pin rung at all. It fetches through the same pinned target, so a dead lease discovered there could only be given up on, which fails the read, and never re-resolved. It is also the arm a backward read after a long pause lands on. It now takes the same decision as both reconnect ladders, which are themselves one method now instead of two copies of one policy.

Reported by @tschuegy (#392, following #380). That retest also answered the question the earlier thread left open, and not the way it was posed: the re-resolved target is the same edge host. What dies across an idle is not the address but the authorization behind it, and walking the chain again re-blesses it.

Three lines that were being read as something else

All log-only, all from round 3 of #377.

  • A refused response now names the host that refused it. A pin is only ever recorded from a 2xx, deliberately, so a re-resolve that lands on a refusing target was written down nowhere. Three shapes that need three different fixes collapsed into one silence: the source refused the re-resolve itself, the source handed back the target just dropped, or a genuinely fresh target refused. Only the last one means the origin is metering us. The rejection line says which, compared on the origin key rather than on the whole URL, because a re-minted link carries a fresh signature for the same edge host, and reading that as a fresh target is exactly the misreading the line exists to prevent. For a target that never answers at all there is the other half, on the request side: a connection opened while a dropped pin is outstanding says it is re-resolving through the source. The refusal is also charged and stamped against the host that answered rather than the one asked; post-#388 chain folding lands both in one bucket, so no budget moves differently, the books just name the right host.
  • refusals= on a slow read says it is cumulative. Every other number on that line belongs to the one read, so a bare count read as this read's. Three windows reporting 7, 14 and 28 look like a meter tightening its grip; the same numbers as increments of 7, 7 and 14 are three whole reconnect ladders each hitting their give-up cap of 7. Same trace, opposite diagnosis, and the second one is a dead pin rather than a meter. It now prints refusals=28total.
  • Connection reuse is reported from a sample, not from a first connection. isReusedConnection was taken from the first metrics callback for an origin, where a connection is nearly always new, so every http/1.1 origin reported "connection new" whether the session went on to reuse that socket a hundred times or none. A reader taking that at face value concludes a fresh handshake per range, which is a different and expensive finding. Reuse is a property of a session, so it is tallied across an origin's reader connections and reported once there is a sample behind it. It says "reader connections" rather than "requests" on purpose: detour blocks, probes and the tail prefetch run on completion-handler tasks with no delegate and are outside the tally.

Upgrading

.package(url: "https://github.com/superuser404notfound/AetherEngine", from: "6.30.1")

Nothing to change at the call site.