Skip to content

Commit e81721e

Browse files
committed
Stop one refused flow from killing every flow beside it
Two Mux defects, both found by repairing a harness that had been reporting success while measuring nothing, and both invisible to any test that opens one flow at a time. The first is a poll interval used as a protocol deadline. `readStream` answers three things with three values, and 0 means "nothing arrived in the last 250 ms" — not a verdict. `open` read it as one, so a Portal that answered a SYN slower than a quarter of a second was reported as "the Portal did not answer on this stream — authentication most likely failed", which is both wrong and the most misleading sentence available. A dedicated lane gives the identical protocol step fifteen seconds. The carrier now gives it the same, because how long a Portal takes to dial a target is a property of the target rather than of the carrier the request arrived over. The second is worse and is a conformance matter. A rejected flow was reset. But the rejection *is* the teardown — the Portal answers and forgets the stream in the same breath — and section 3 says STREAM data for an unknown flow is a *carrier* error. So the RST did not tidy up one flow, it closed the connection and failed every other flow multiplexed onto it. The dedicated lane has always simply closed a rejected lane, so this is also the two carriers agreeing again. The trigger is ordinary and permanent: Android's Private DNS probes port 853 the moment a tunnel comes up, the Portal answers DIAL_FAILED, and whichever shard that probe landed on lost its other flows half a second later. Measured at one to four of sixteen concurrent fetches coming back empty, intermittently. After both fixes, fourteen further runs produced one short response rather than three in two runs of three — better, and not yet zero, which is recorded rather than rounded down. `reset` had no other caller and is gone. This client now sends no RST at all, which is a decision: every other way a flow ends here is a half-close, and FIN is what that is. Reading one stays implemented and tested, because the Portal may send one. The harness half is the reason any of this was visible. e2e-fakeip.sh drove three instrumentation classes that had been disabled two runs earlier for proving nothing — so it ran, skipped everything, and its shard arithmetic compared 0 connections against 0 flows and passed. It now drives the fetch from the shell, where the traffic actually enters the TUN, over both address families; the concurrency measurement opens sixteen `nc` processes at once and counts what the Portal saw; and zero flows now fails loudly instead of satisfying every comparison. e2e-tunnel-fetch.sh gained a family switch, which is what proves the v6 half of the fake-IP layer with nothing but the device: the name is resolved through the tunnel's own resolver into fc00::/96, the packet takes the ::/0 route, and the Portal still dials the name. Measured on the emulator: 20,971,762 bytes over a synthetic IPv6 address, the Portal's counters moving by the same amount, digest matching; and sixteen concurrent flows over four connections at mux=1, sixteen over sixteen at mux=0.
1 parent c05d9d1 commit e81721e

7 files changed

Lines changed: 314 additions & 42 deletions

File tree

‎app/src/main/kotlin/eu/nodepass/somewhere/protocol/mux/MuxCarrier.kt‎

Lines changed: 89 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -304,7 +304,7 @@ class MuxCarrier(
304304
// The Portal's answer is the first byte of this stream's payload, in
305305
// exactly the place a dedicated lane reads it from the socket.
306306
val setup = ByteArray(1)
307-
if (readStream(stream, setup, 0, 1) != 1) {
307+
if (!awaitSetupByte(stream, setup)) {
308308
releaseStream(stream)
309309
return invalid(stream.failure ?: MuxCarrierReason.NoSetupByte)
310310
}
@@ -319,7 +319,24 @@ class MuxCarrier(
319319
}
320320
stream.setupResult = result
321321
if (result.isRejection) {
322-
reset(stream)
322+
// Released, **not reset**. The rejection is the teardown: the
323+
// Portal answered and forgot the stream in the same breath, and
324+
// section 3 says "STREAM data for an unknown flow is a carrier
325+
// error" — so a RST for a flow it has already refused does not
326+
// tidy anything up, it closes the whole carrier and fails every
327+
// other flow on it.
328+
//
329+
// Measured, because it is invisible in any test that opens one
330+
// flow at a time. Android's Private DNS probes an address on port
331+
// 853 the moment a tunnel comes up; the Portal answers DIAL_FAILED;
332+
// this reset the stream; half a second later four unrelated fetches
333+
// on the same carrier reported "the Portal closed the Mux carrier".
334+
// One to four of sixteen concurrent fetches came back empty,
335+
// intermittently, depending on which shard the probe landed on.
336+
//
337+
// The dedicated lane has always done it this way — a rejected lane
338+
// is simply closed — so this is also the two carriers agreeing
339+
// again.
323340
releaseStream(stream)
324341
return invalid(MuxCarrierReason.Rejected(result))
325342
}
@@ -528,6 +545,45 @@ class MuxCarrier(
528545
}
529546
}
530547

548+
/**
549+
* Waits for the Portal's setup byte, for as long as a dedicated lane does.
550+
*
551+
* **A quiet stream is not a refused one**, and telling them apart is the
552+
* whole job here. [readStream] answers three things with three values: 1 is
553+
* the byte, -1 is a stream or carrier that has gone, and **0 is "nothing in
554+
* the last [READ_WAIT_MILLIS]"** — which is a poll interval, not a verdict.
555+
*
556+
* Treating that 0 as a verdict is what this used to do, and it produced the
557+
* worst failure this layer has had. Sixteen flows open at once, four land on
558+
* one carrier, the Portal dials four targets and answers each as it
559+
* finishes; any answer slower than a quarter of a second was read as *"the
560+
* Portal did not answer on this stream — authentication most likely
561+
* failed"*, which is both wrong and the most misleading sentence available.
562+
* The flow then reset a stream the Portal was still setting up, the Portal
563+
* closed the carrier, and **the other three flows on it died too** — three
564+
* short responses out of sixteen, intermittently, with nothing in the
565+
* Portal's log but a carrier that closed.
566+
*
567+
* The deadline is the dedicated lane's, deliberately. It is the same
568+
* protocol step over the same kind of connection to the same Portal, and a
569+
* carrier that gave it sixty times less patience than a lane was not making
570+
* a considered choice — it was reusing a queue-polling constant as a
571+
* protocol timeout.
572+
*/
573+
private fun awaitSetupByte(
574+
stream: Stream,
575+
into: ByteArray,
576+
): Boolean {
577+
val deadline = clock() + SETUP_DEADLINE_MILLIS
578+
while (true) {
579+
when (readStream(stream, into, 0, 1)) {
580+
1 -> return true
581+
0 -> if (clock() >= deadline) return false
582+
else -> return false
583+
}
584+
}
585+
}
586+
531587
// ── Stream reading, from the caller's thread ────────────────────────────
532588

533589
private fun readStream(
@@ -605,13 +661,18 @@ class MuxCarrier(
605661
if (stream.receiveClosed.get()) releaseStream(stream)
606662
}
607663

608-
/** RST is the only flag that may accompany it, and its value must be zero. */
609-
private fun reset(stream: Stream) {
610-
if (!stream.sendClosed.compareAndSet(false, true)) return
611-
runCatching {
612-
enqueue(MuxHeader(MuxKind.Stream, MuxHeader.FLAG_RST, 0, stream.id).encode())
613-
}
614-
}
664+
// This client sends no RST, and that is a decision rather than an omission.
665+
//
666+
// RST had exactly one caller: a flow the Portal had just rejected. That was
667+
// wrong for the reason written where the rejection is handled — the Portal
668+
// forgets a refused stream as it answers, and section 3 makes a frame for a
669+
// flow it does not know a *carrier* error, so the reset killed every other
670+
// flow sharing the connection. Every other way a flow ends here is a
671+
// half-close, which is what FIN is for.
672+
//
673+
// The frame itself stays implemented and tested in `MuxHeader`, because the
674+
// Portal may send one and this client has to read it. Writing one is what
675+
// no path needs.
615676

616677
/** Gives back the carrier slot, exactly once however the stream ended. */
617678
private fun releaseStream(stream: Stream) {
@@ -686,7 +747,14 @@ class MuxCarrier(
686747
}
687748
}
688749

689-
private companion object {
750+
/**
751+
* Internal rather than private so that the tests can assert the *relation*
752+
* between two of these numbers. `SETUP_DEADLINE_MILLIS` being sixty times
753+
* `READ_WAIT_MILLIS` is the whole content of a defect that cost three of
754+
* sixteen concurrent flows, and a test that can only observe it through
755+
* timing would be a slow test that fails on a loaded machine.
756+
*/
757+
internal companion object {
690758
/** The sentinel that means "no more data on this stream". */
691759
val EOF = ByteArray(0)
692760

@@ -702,6 +770,17 @@ class MuxCarrier(
702770

703771
/** The same, for a caller blocked on a stream that has gone quiet. */
704772
const val READ_WAIT_MILLIS = 250L
773+
774+
/**
775+
* How long a flow waits for the Portal to answer its SYN.
776+
*
777+
* The dedicated lane's read timeout, because it is the same protocol
778+
* step: the Portal dials the target and answers when it knows, and how
779+
* long that takes is a property of the target rather than of the
780+
* carrier the request arrived over. See [awaitSetupByte] for what a
781+
* shorter one did.
782+
*/
783+
const val SETUP_DEADLINE_MILLIS = 15_000L
705784
}
706785
}
707786

‎app/src/test/kotlin/eu/nodepass/somewhere/protocol/mux/FakeMuxPortal.kt‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -92,6 +92,15 @@ class FakeMuxPortal(
9292
private val onReady: (FakeMuxPortal) -> Unit = {},
9393
/** Called for each STREAM frame that carries payload after the opening one. */
9494
private val onPayload: (FakeMuxPortal, UInt, ByteArray) -> Unit = { portal, id, bytes -> portal.sendStream(id, bytes) },
95+
/**
96+
* How long to think before answering a SYN.
97+
*
98+
* A real Portal dials the target before it answers, and how long that takes
99+
* belongs to the target rather than to the carrier. Zero here would make
100+
* every setup instantaneous, which is exactly the condition under which a
101+
* carrier that mistook a poll interval for a refusal looked correct.
102+
*/
103+
private val setupDelayMillis: Long = 0,
95104
) {
96105
/** Every frame header the client sent, in order. */
97106
val received: MutableList<MuxHeader> = java.util.Collections.synchronizedList(mutableListOf())
@@ -307,6 +316,7 @@ class FakeMuxPortal(
307316
if (flowHeader is DecodeResult.Ok && target is DecodeResult.Ok) {
308317
opened[header.flowId] = target.value.target
309318
val result = setupResult(target.value.target)
319+
if (setupDelayMillis > 0) Thread.sleep(setupDelayMillis)
310320
sendStream(header.flowId, byteArrayOf(result.byte.toByte()))
311321
if (result.isRejection) return
312322
val consumed = FlowHeader.LENGTH + target.value.consumed

‎app/src/test/kotlin/eu/nodepass/somewhere/protocol/mux/MuxCarrierRefusalTest.kt‎

Lines changed: 36 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -123,6 +123,42 @@ class MuxCarrierRefusalTest {
123123
assertEquals(MuxCarrierReason.ClosedByCaller, reason)
124124
}
125125

126+
@Test
127+
fun aRejectedFlowIsReleasedRatherThanReset() {
128+
// The rejection is the teardown. The Portal answers and forgets the
129+
// stream in the same breath, and section 3 makes a frame for a flow it
130+
// does not know a *carrier* error — so a RST here does not tidy up one
131+
// flow, it closes the connection and fails every other flow sharing it.
132+
//
133+
// Found on a device and not by any test that opens one flow at a time.
134+
// Android's Private DNS probes port 853 the moment a tunnel comes up,
135+
// the Portal answered DIAL_FAILED, this client reset the stream, and
136+
// half a second later four unrelated fetches on the same carrier
137+
// reported "the Portal closed the Mux carrier". One to four of sixteen
138+
// concurrent fetches came back empty, intermittently, depending on
139+
// which shard the probe happened to land on.
140+
val (clientSide, portalSide) = LoopbackTransport.pair()
141+
val fake = FakeMuxPortal(portalSide, { SetupResult.DialFailed }).also { it.start() }
142+
val built = MuxCarrier(clientSide, key, SessionId.random())
143+
assertTrue(built.start() is DecodeResult.Ok)
144+
carrier = built
145+
portal = fake
146+
147+
val refused = built.open(target, FlowKind.Tcp, 1u)
148+
assertEquals(
149+
MuxCarrierReason.Rejected(SetupResult.DialFailed),
150+
(refused as DecodeResult.Invalid).reason,
151+
)
152+
153+
// Give the writer thread a chance to send anything it was going to.
154+
Thread.sleep(300)
155+
val reset = fake.frames().filter { it.isReset }
156+
assertTrue("a rejected flow must not be reset, but $reset went out", reset.isEmpty())
157+
158+
// And the carrier is still usable, which is the point of not resetting.
159+
assertTrue("the carrier died with the flow it refused", built.isOpen)
160+
}
161+
126162
@Test
127163
fun everyRefusalSaysSomethingDifferent() {
128164
// The seven rejections lesson, applied here: a caller that cannot tell

‎app/src/test/kotlin/eu/nodepass/somewhere/protocol/mux/MuxCarrierTest.kt‎

Lines changed: 40 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -45,9 +45,10 @@ class MuxCarrierTest {
4545
onReady: (FakeMuxPortal) -> Unit = {},
4646
onPayload: (FakeMuxPortal, UInt, ByteArray) -> Unit = { p, id, bytes -> p.sendStream(id, bytes) },
4747
clock: () -> Long = { System.nanoTime() / 1_000_000 },
48+
setupDelayMillis: Long = 0,
4849
): Pair<MuxCarrier, FakeMuxPortal> {
4950
val (clientSide, portalSide) = LoopbackTransport.pair()
50-
val fake = FakeMuxPortal(portalSide, setupResult, onReady, onPayload).also { it.start() }
51+
val fake = FakeMuxPortal(portalSide, setupResult, onReady, onPayload, setupDelayMillis).also { it.start() }
5152
val built = MuxCarrier(clientSide, key, SessionId.random(), clock)
5253
assertTrue("the carrier failed to start", built.start() is DecodeResult.Ok)
5354
carrier = built
@@ -291,4 +292,42 @@ class MuxCarrierTest {
291292
val reason = (openFlow(built, flowId = 0u) as DecodeResult.Invalid).reason
292293
assertEquals(MuxReason.StreamFlowIdZero, reason)
293294
}
295+
296+
@Test
297+
fun aPortalThatTakesItsTimeAnsweringIsNotAFailedAuthentication() {
298+
// The defect this pins cost three of sixteen concurrent fetches, on a
299+
// device, intermittently. `readStream` answers 0 for "nothing in the
300+
// last 250 ms", and `open` used to read that as the Portal having
301+
// refused — reporting "authentication most likely failed" for a flow
302+
// whose answer was merely in flight, then resetting a stream the Portal
303+
// was still setting up, at which point the Portal closed the carrier
304+
// and took every other flow on it down too.
305+
//
306+
// 600 ms is comfortably past the poll interval and nowhere near the
307+
// deadline, which is the window the old code could not represent.
308+
val (built, _) = connect(setupDelayMillis = 600)
309+
val opened = built.open(target, FlowKind.Tcp, flowId = 1u)
310+
assertTrue(
311+
"a Portal that answered after 600 ms was treated as a failure: " +
312+
(opened as? DecodeResult.Invalid)?.reason?.detail,
313+
opened is DecodeResult.Ok,
314+
)
315+
assertEquals(SetupResult.Ready, (opened as DecodeResult.Ok).value.setupResult)
316+
}
317+
318+
@Test
319+
fun theSetupDeadlineIsTheDedicatedLanesRatherThanAPollInterval() {
320+
// Stated as a relation rather than a number: the two are the same
321+
// protocol step over the same kind of connection, and the moment they
322+
// differ by two orders of magnitude somebody has reused a queue
323+
// constant as a protocol timeout.
324+
assertTrue(
325+
"a setup deadline of ${MuxCarrier.SETUP_DEADLINE_MILLIS} ms is not a protocol deadline",
326+
MuxCarrier.SETUP_DEADLINE_MILLIS >= 10_000L,
327+
)
328+
assertTrue(
329+
"the setup deadline must be far longer than a poll interval",
330+
MuxCarrier.SETUP_DEADLINE_MILLIS > MuxCarrier.READ_WAIT_MILLIS * 20,
331+
)
332+
}
294333
}

‎conformance/scripts/device-acceptance.sh‎

Lines changed: 29 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -145,17 +145,37 @@ else
145145
fi
146146
fi
147147

148-
head2 "3c. An IPv6 destination through the tunnel"
149-
# Needs an origin the Portal can reach over IPv6. The docker origin
150-
# e2e-fakeip.sh starts is v4-only, so this is supplied or it is a note --
151-
# never a silent pass.
152-
if [ -z "${NOWHERE_E2E_TARGET6:-}" ]; then
153-
note "no NOWHERE_E2E_TARGET6 given, so nothing checked that a v6 destination is carried. Set it to [addr]:port of an HTTP origin reachable over IPv6 from the Portal, serving /blob.bin with X-Content-Sha256."
154-
elif NOWHERE_E2E_CARRIER=tcp "$ROOT/e2e-tunnel-fetch.sh" "$NOWHERE_E2E_TARGET6" /blob.bin > /tmp/somewhere-fetch-v6.log 2>&1; then
148+
head2 "3c. A synthetic IPv6 address, end to end"
149+
# The v6 half of the fake-IP layer, proved with nothing but this device: the
150+
# name is resolved through the tunnel's own resolver, which answers AAAA with an
151+
# address out of fc00::/96; the packet takes the ::/0 route into the TUN;
152+
# lwIP's IPv6 side carries it; the address is resolved back to the name; and the
153+
# Portal dials that name over whichever family its own network prefers. No
154+
# IPv6 connectivity is needed anywhere outside this device.
155+
#
156+
# It needs a NAME rather than an address, because a synthetic address exists
157+
# only as the answer to a query. NOWHERE_E2E_ORIGIN is that name; without one
158+
# this says so rather than passing.
159+
if [ -z "${NOWHERE_E2E_ORIGIN:-}" ]; then
160+
note "no NOWHERE_E2E_ORIGIN given, so the v6 half of the fake-IP layer was not exercised. Set it to name:port of an origin only the Portal can resolve — e2e-fakeip.sh starts one at origin.somewhere.test:8080."
161+
elif NOWHERE_E2E_FAMILY=6 NOWHERE_E2E_CARRIER=tcp "$ROOT/e2e-tunnel-fetch.sh" "$NOWHERE_E2E_ORIGIN" /blob.bin > /tmp/somewhere-fetch-v6.log 2>&1; then
155162
RELAYED6="$(grep -o 'the Portal relayed [0-9]* bytes' /tmp/somewhere-fetch-v6.log | head -1)"
156-
pass "an IPv6 destination is carried — ${RELAYED6:-no counter}"
163+
SYNTH="$(grep -o 'resolved to [0-9a-fA-F:]*' /tmp/somewhere-fetch-v6.log | head -1)"
164+
pass "a synthetic IPv6 address carried 20 MB — $SYNTH, ${RELAYED6:-no counter}"
165+
else
166+
miss "synthetic IPv6: $(tail -3 /tmp/somewhere-fetch-v6.log | tr '\n' ' ')"
167+
fi
168+
169+
head2 "3d. A real IPv6 destination through the tunnel"
170+
# The other half, which this device cannot supply: an origin the Portal reaches
171+
# over IPv6. Supplied or a note, never a silent pass.
172+
if [ -z "${NOWHERE_E2E_TARGET6:-}" ]; then
173+
note "no NOWHERE_E2E_TARGET6 given, so nothing checked that a genuinely IPv6 destination is carried. Set it to [addr]:port of an HTTP origin reachable over IPv6 from the Portal, serving /blob.bin with X-Content-Sha256."
174+
elif NOWHERE_E2E_CARRIER=tcp "$ROOT/e2e-tunnel-fetch.sh" "$NOWHERE_E2E_TARGET6" /blob.bin > /tmp/somewhere-fetch-v6dst.log 2>&1; then
175+
RELAYED6D="$(grep -o 'the Portal relayed [0-9]* bytes' /tmp/somewhere-fetch-v6dst.log | head -1)"
176+
pass "an IPv6 destination is carried — ${RELAYED6D:-no counter}"
157177
else
158-
miss "IPv6 destination: $(tail -3 /tmp/somewhere-fetch-v6.log | tr '\n' ' ')"
178+
miss "IPv6 destination: $(tail -3 /tmp/somewhere-fetch-v6dst.log | tr '\n' ' ')"
159179
fi
160180

161181
# ── 4. The tunnel actually carries traffic ──────────────────────────────────

0 commit comments

Comments
 (0)