Skip to content
C.W.K.
Lesson 06 of 06 · published

A False Alarm, and One Measurement per Cause

~16 min · latency, connection-pool, diagnostics, measurement

Level 0Muted
0 XP0/64 lessons0/14 achievements
0/100 XP to next level100 XP to go0% complete
"이게 지금 잘못된 경보라고." ("This one, right now, is a false alarm.") — Dad, Málaga, 2026-10-19, 20:11 CEST

One Word, Several Causes

The night paragraph reading came apart (Track 4's "Whole Again: Zero Breaks Before a Fast Start" tells the reading's side), build 156 on hotel Wi-Fi with AirPods gave Dad a whole evening of symptoms. Replies broke up. The microphone took long seconds to open. One reply spoke a single sentence and stopped. And the phone said "Reconnecting — The engine did not answer in time" while the engine, on the Mac that was then the Pippa machine, answered every call it received. Only a reboot, or killing the app, helped. Out loud, all of it has one name: 끊긴다, "it breaks up".

At 19:59 CEST Dad refused to treat that word as a diagnosis. His frame, as the design doc records it: what he hears as "끊긴다" is one symptom over several causes (the network, synthesis, the pipeline, accumulated state, Bluetooth), and each is to be measured on its own, against the stable home baseline from before the Málaga changes (todo #536). At 20:06 he closed one door on purpose: iOS and the AirPods are stable and used the way Apple advertises them, the AirPods microphone included, so every fix would be in our code. At 20:11 he pointed at the one symptom that described nothing he could hear, the "Reconnecting" line itself, in the words at the top of this page.

Six Connections and a Burst

Since todo #376 every call from the phone had ridden one kept-alive pool, the shared kit's HTTPConnectionPool, because from Seville a fresh TCP connection per request had cost a 285 ms round trip before a byte was sent. The pool opens at most six connections to a host. Under paragraph reading one reply could fill all six: at 20:07, when a reply's tool ended, the phone fired four take prepares, four take streams and the 1.96 MB microphone-rate copy of Dad's recording in the same second, beside the turn's own stream. The turn progress check, which asks again 3 seconds after each answer with the kit's quick policy (a 5 second request timeout), queued behind the audio, timed out, and one miss was enough to print "Reconnecting". The engine was healthy all day, on Wi-Fi and LTE alike.

Then it got worse. Once that line appeared, nothing recovered: the pool's connections stayed wedged until Dad killed the app at 20:16, and only a relaunch made new ones. A status line built to tell him the phone had lost Pippa was reading the phone's own congestion as Pippa's absence.

Traffic by Kind

The first fix stopped audio and control from sharing a line. Build 157 (cbe99bd0) gave bulk transfers a pool of their own: her takes, speech, uploads, downloads and video. Reads, polls and the turn no longer wait behind a byte of audio. Build 157 then showed the next shape: six minutes after launch the remaining pool's kept-alive connection went stale, and a dictated turn sat 49 seconds on the phone before its POST while the line said only "not sent for 37s". So build 158 (e9fbe699) gives the turn's stream a connection of its own on every turn (HTTPTransports.lineStream): one handshake, well under a second from Málaga, the price of never waiting on a dead connection.

The voice-mode review of 2026-10-22 (f58e7fea) finished the split from the other side. The listening grant and a take's ticket (/api/tts/prepare) had ridden the bulk pool with 120 to 180 second timeouts, so a stale bulk connection held her first unit 29 seconds while the stall check, asking the healthy control pool, said her voice was still being made. Short control calls ride the control pool now, with 20 and 30 second limits (/api/tts/ensure, which may make a whole take before it answers, gets a minute). Only byte streams and uploads stay on bulk, and a quiet "Getting her voice ready" probes the bulk pool itself, because the control pool answering says nothing about a stale bulk connection. The excerpt below is where each kind of call is assigned its pool.

A Pool That Heals, and a Heal That Fed Itself

A split pool still meets stale connections, so the pool learned to heal (cwkSiblingKit f655776). After buffered replies time out in a row, it opens a fresh session for every later call, lets the calls in flight finish on the old one, logs the reset and counts it as pool_reset. It began at three timeouts in a row, at most once every 30 seconds. Build 158 made it two in a row, at most once every 20 seconds (21507b4), because three had cost Dad that 49 second wait: the healing was slower than the connection it healed.

The review then found the heal feeding itself. The pool's router matched each callback to its caller by taskIdentifier, a number unique only within one session. After a reset the old session's calls were still in flight on the same router, so the first call on the new session shared its number with the first on the old one. The newer route replaced the older, the old reply's body went to nobody, its caller timed out, and that timeout counted toward the next heal. Live, one app run logged up to five pool_reset. The router is keyed by the task object now (cwkSiblingKit e50efa6), and byte and line streams report their timeouts and lost connections, so the bulk pool heals too. A self-healing mechanism deserves the same suspicion as the fault it heals: when the heal can produce the symptom it counts, it is a loop, not a cure.

"Reconnecting" Is a Verdict

Dad's complaint was about the words too: "리커넥팅이라고만 돼 있으니까" ("all it says is Reconnecting"). A line that fires on one missed check and names nothing gives him nothing to act on. Since build 157 "Reconnecting" is a verdict (AppModel.reconnecting, excerpted below): two checks in a row failing, failing for at least 6 seconds, with nothing heard from the engine for 15. Her streamed words count as hearing from it, and since the review so do the stage board's answers. When the verdict does fall, the line names the failing check and how long it has failed.

The waits around it say what they wait on, too. A turn still on the phone counts the other calls open on the shared connection, from the kit's pool_reply counter: "not sent for 20s (4 other calls open)". The microphone opens on the phone first, at the 16 kHz every grant carries, and only then asks Pippa for the listening grant; what Dad says meanwhile is kept and goes in first, and "Opening the microphone…" names what it is waiting for (the audio session, Pippa with its seconds, the listening socket). The web caught up in the same review: words said while a listen connects are kept, and the grant is asked beside opening the microphone.

On 2026-10-23 the web's lost-link banner learned the same honesty (46d86006). A restart's cut had read as the same error a dropped tailnet throws, so the banner told Dad to check Tailscale while the engine was only restarting. Now it says "Connection lost. Checking why…" first, then "Pippa is restarting, back in a few seconds." when the engine's twin answers 502, 503 or 504 for an engine that is down, or "This device is offline.", or "Pippa cannot be reached from this device." Only the last carries the Tailscale advice. Dad's words for what it fixed: "멍 때리거나 엉터리 안내하는 UI가 죄악인 거야." ("A UI that zones out or gives bogus guidance is the real sin.")

One Measurement per Cause

Dad's frame became instrumentation. Every voice turn's report (the timeline from this track's "The Voice Lane: Measured From Málaga") now carries one reading for each cause he named, so a break can be attributed instead of argued about:

causewhat is measuredwhere it shows
the networkunderruns= per unit (count, silent seconds, longest, the cushion, the player) beside link=the [voice-turn] line
synthesisfirst_byte, total, rate against real time, need= (the cushion this take alone needed), beside= (takes made at the same time)one [tts-take] line per take on the Pippa machine
the pipeline and accumulated statehealth: device and app uptime, turns, audio-session activations, memory, and live= counts of players, microphone engines, audio queues, takes, open byte streams, replies in flight, and the pool resets since launchthe [voice-turn] line
Bluetoothroute= with inputs, rate, category and mode, and route_change@<s>=<reason>:<outputs> for every change while she readsthe [voice-turn] line
the wait itselfeach gap before a unit with its lead (0.56a(-0.30): queued 0.3 s after the last unit ended, so her words were late), and listen_open:grant=…,session=…,total=…the [voice-turn] line

Each reading comes with the rule that reads it. A stutter on a turn with underruns=0 and +bluetooth is the radio between the phone and the AirPods, not the stream. A take whose need= sits above the phone's cushion broke on synthesis; one under it broke on the network. A live= count of objects that grows from turn to turn is our process holding something it should have let go. One entry is not a live count: pool_reset is never counted down, so it is a tally of heals since launch, and its reading is whether it moved since the last turn. And the next device check costs one swipe: when it degrades again, force-quit Pippa before rebooting. Clean after that means our process held it, and health: shows what grew; still broken means the phone's own audio state, which only the reboot resets.

The doc wrote down what "done" means for this work before anyone could claim it: a day of dictated turns on Wi-Fi and LTE with speech_end_to_post within the end-of-speech window plus the upload, pool_reset at 0, and no "not sent" line. The breaks themselves are Track 4's story: after the Pippa machine moved, 103 phone voice turns, 90 of them over cellular, each logged underruns=0.

Code

verbatim, clients/apple/PippaMobile/Sources/PippaClient.swift (cwkPippa), lines 694-714, as of 2026-10-27: which pool each kind of call rides, and the turn's stream on a connection of its own·swift
        quick = readTransport ?? pool.transport(policy: .quick)
        media = bulkPool.transport(policy: Self.mediaPolicy)
        download = readTransport ?? bulkPool.transport(policy: Self.downloadPolicy)
        transcript = readTransport ?? pool.transport(policy: Self.transcriptPolicy)
        video = bulkPool.transport(policy: Self.videoPolicy)
        speech = bulkPool.transport(policy: Self.speechPolicy)
        control = pool.transport(policy: Self.controlPolicy)
        ensuring = pool.transport(policy: Self.ensurePolicy)
        bulkProbe = bulkPool.transport(policy: .quick)
        // A turn's stream opens a connection of its own (todo #556): on build 157 the
        // pool's kept-alive connection went stale within six minutes of launch, every
        // call on it hung until the pool healed, and a dictated turn sat 49 s on the
        // phone before its POST ("not sent for 37s; office answers"). One handshake
        // per turn, well under a second from Malaga, is the price of never waiting on
        // a dead connection.
        streamer = { request, policy in
            var request = request
            request.timeoutInterval = policy.requestTimeout
            return try await HTTPTransports.lineStream(request, policy: policy)
        }
        speechStreamer = bulkPool.byteStreamer(policy: Self.speechPolicy)
verbatim, clients/apple/PippaMobile/Sources/AppModel.swift (cwkPippa), lines 152-164, as of 2026-10-27: "Reconnecting" as a verdict·swift
    /// "Reconnecting" is a verdict, never one missed check (todo #556): two checks
    /// in a row failing over at least this long, with nothing heard from the engine in
    /// `reconnectQuietSeconds`. One 5 s timeout behind a reply's audio said
    /// "The engine did not answer in time" against a healthy engine all day.
    nonisolated static let reconnectAfterSeconds = 6.0
    nonisolated static let reconnectQuietSeconds = 15.0

    /// Whether the progress check's failures add up to "Reconnecting".
    nonisolated static func reconnecting(failures: Int, failingFor: TimeInterval, sinceContact: TimeInterval?) -> Bool {
        guard failures >= 2, failingFor >= reconnectAfterSeconds else { return false }
        if let sinceContact, sinceContact < reconnectQuietSeconds { return false }
        return true
    }
A runnable sketch: one pool of six for everything, or bulk on a pool of its own, and when one miss and the verdict each say "Reconnecting"·python
# One pool of six for everything, or traffic by kind: when does the progress
# check get an answer, and when does the screen say "Reconnecting"?
# The rules follow cwkSiblingKit's HTTPConnectionPool and cwkPippa's
# AppModel.reconnecting; the call durations are illustrative, shaped after
# the Malaga access log of 2026-10-19, not measured per call.
import heapq

CONNECTIONS = 6        # httpMaximumConnectionsPerHost, per pool
CHECK_REST = 3.0       # the progress check sleeps this long between asks
CHECK_TIMEOUT = 5.0    # the quick policy's request timeout
CHECK_SECONDS = 0.2    # a healthy engine answers the check this fast
AFTER_SECONDS = 6.0    # AppModel.reconnectAfterSeconds
QUIET_SECONDS = 15.0   # AppModel.reconnectQuietSeconds

# (arrival, seconds held, kind). The turn's stream runs for the whole reply;
# when the tool ends at 20 s, four takes are prepared and streamed at once,
# and the 1.96 MB microphone-rate copy goes up in the same second.
REPLY = [(0.0, 40.4, "stream")]
REPLY += [(20.0, 0.4, "prepare")] * 4
REPLY += [(20.4, seconds, "take") for seconds in (14.0, 19.0, 24.0, 30.0)]
REPLY += [(20.0, 26.0, "upload")]
BULK = {"take", "upload"}


def run(calls, split: bool, engine_up: bool = True, until: float = 45.0):
    """Every call takes the connection that frees first in its pool, in arrival
    order. The check asks, waits for an answer or its timeout, rests, asks again."""
    pools = {"control": [0.0] * CONNECTIONS, "bulk": [0.0] * CONNECTIONS}
    queue = [(arrival, kind != "stream", seconds, kind) for arrival, seconds, kind in calls]
    queue.append((0.0, True, CHECK_SECONDS, "check"))
    heapq.heapify(queue)
    checks = []                                          # (asked at, answered at or None)
    while queue:
        arrival, _, seconds, kind = heapq.heappop(queue)
        pool = pools["bulk" if split and kind in BULK else "control"]
        slot = min(range(CONNECTIONS), key=lambda i: pool[i])
        start = max(arrival, pool[slot])
        if kind != "check":
            pool[slot] = start + seconds
            continue
        if engine_up and start + seconds - arrival < CHECK_TIMEOUT:
            pool[slot] = start + seconds
            checks.append((arrival, start + seconds))
            end = start + seconds
        else:
            checks.append((arrival, None))               # timed out
            end = arrival + CHECK_TIMEOUT
        if end + CHECK_REST < until:
            heapq.heappush(queue, (end + CHECK_REST, True, CHECK_SECONDS, "check"))
    return checks


def first_alarm(checks, words_until: float):
    """When one miss would say "Reconnecting", and when the verdict would:
    two failures in a row, failing for at least 6 s, nothing heard for 15 s.
    Her streamed words count as hearing from the engine."""
    one_miss = verdict = None
    failures, since, heard = 0, None, 0.0
    for asked, answered in checks:
        now = answered if answered is not None else asked + CHECK_TIMEOUT
        heard = max(heard, min(now, words_until))
        if answered is not None:
            failures, since, heard = 0, None, answered
            continue
        failures += 1
        since = now if since is None else since
        one_miss = now if one_miss is None else one_miss
        if verdict is None and failures >= 2 and now - since >= AFTER_SECONDS and now - heard >= QUIET_SECONDS:
            verdict = now
    return one_miss, verdict


for label, split, up, words in (("one pool, a healthy engine", False, True, 40.4),
                                ("two pools, a healthy engine", True, True, 40.4),
                                ("two pools, the engine gone", True, False, 0.0)):
    checks = run(REPLY, split, engine_up=up)
    missed = sum(1 for _, answered in checks if answered is None)
    one_miss, verdict = first_alarm(checks, words_until=words)
    show = lambda t: "never" if t is None else f"{t:4.1f} s"
    print(f"{label:28s} checks {len(checks):2d}, missed {missed:2d} | one miss: {show(one_miss):7s} verdict: {show(verdict)}")

# Output:
# one pool, a healthy engine   checks 12, missed  1 | one miss: 27.4 s  verdict: never
# two pools, a healthy engine  checks 15, missed  0 | one miss: never   verdict: never
# two pools, the engine gone   checks  6, missed  6 | one miss:  5.0 s  verdict: 21.0 s

External links

Exercise

Run the sketch and read its three lines: where the single shared pool misses a check against a healthy engine, why the verdict stays quiet there, and why it does speak when the engine is really gone. Then make the burst bigger the way paragraph reading did, with six takes instead of four (add 34.0 and 38.0 to the take lengths), and add a fourth row to the loop: one pool, a healthy engine, and her words ending at 20 seconds (False, True, 20.0). Finally, take a status line from an app of your own that says something like "connecting" or "offline", list every cause that can make it appear, and write the one measurement that would tell each cause apart.
Hint
With six takes the shared pool holds more long transfers than it has connections, so two checks miss in a row. While her words are still streaming, the verdict stays quiet, because hearing from the engine is evidence it is up. Once her words stop at 20 seconds, the verdict fires at about 35 seconds against an engine that never went down. That is the point of the order of the fixes: the verdict keeps one slow call from becoming an alarm, but only giving control traffic its own line stops a full pool from failing the check at all. For your own line, the usual causes are no network on the device, a server that is down, a server that is restarting, a slow call queued behind others, and a stale connection; each has its own probe.

Progress

Progress is local-only — sign in to sync across devices.
Spotted a bug or have feedback on this page?Report an Issue

Comments 0

🔔 Reply notifications (sign in)
Sign in — Please sign in to comment.

No comments yet — be the first.