Skip to content

Music picks failing and running long: 3 dead probes, one 'nothing suitable', 82-192s picks in one session [spec 04 §3.3] #164

Description

@wine-fall

What it is

In one real session on 2026-08-31 (~13:57-14:29, .dev/dev.log), music
discovery failed far more often and ran far longer than the recorded baseline.

Dead stream probes — three in half an hour, each costing a full pick-again
round (music.probe is logged by src/music-programmer.ts:86, the probe
itself is probeStream wired through musicTools):

14:08:51 INFO director: music.probe 943ms dead
14:09:08 INFO director: music.probe 873ms dead
14:26:08 INFO director: music.probe 925ms dead

One pick gave up entirely and the segment fell back to talk
(src/director.ts:711):

14:26:39 INFO host: music: nothing suitable found; back to talk.

Pick wall-clock across the session (music.pick done): 93.7 s, 89.1 s,
192.1 s, 81.7 s, 111.7 s — all five picks succeeded but every one of them ran
long. The recorded baseline for this stage, re-measured after issue #76 under
controlled conditions, is 40.2 s cold / 54.7 s hot (specs/spec04/04-no-dead-air.md
§3.3). Today's session is 1.5-3.5x that. Per-stage timings in the same log are
not the outlier: searches 1.7-2.9 s, resolves 2.5-4.1 s, probes 0.7-1.0 s —
in line with the spec's ~2.3-2.6 s / ~2.4-2.9 s / ~1-1.3 s. The excess is in
model turns and in the retry rounds the dead probes force.

Suspected, NOT verified: degraded yt-dlp source health (stale or
region-blocked stream URLs surviving search + resolve and only dying at
probe) is the leading hypothesis, since the failure is concentrated at the
probe stage while search and resolve stay fast. Nothing has been done to
confirm it. This session was not run under the spec-04 measurement
conditions (no isolated MURMUR_HOME, a long-lived real session with a grown
memory), so the latency numbers above are an observation, not a re-measurement,
and must not be read into spec 04's table.

Not yet investigated

  • Whether the dead probes are a yt-dlp / source-health problem at all, versus a
    probe-side false negative (timeout, ffmpeg behavior on a slow first byte).
  • Why 14:26:39's "nothing suitable found" has no preceding
    music.pick done … picked=no line, although src/music-programmer.ts:114
    logs every completed pick. The pick that fed that boundary appears to have
    been discarded or superseded rather than to have returned null — either the
    failure path is unlogged or the pick was dropped upstream. Worth resolving
    first: it decides whether the "no suitable track" event is even the same
    failure as the dead probes.
  • Whether the long picks are caused by the retry rounds alone, or by model-turn
    growth on top.

Spec

specs/spec04/04-no-dead-air.md §3.3 (the discovery-latency measurement and
the per-stage split it records); specs/spec03/03-01-brain-harness.md §155
(next_track returns null when nothing suitable resolves).

Done when — either exit closes this:

  • It recurs. A second session shows the same pattern (multiple dead probes
    and/or picks well past the §3.3 baseline). Then this becomes an eng issue
    with a named cause: run a controlled re-measure under the spec-04 conditions,
    land the number in §3.3, and fix or bound the source-health path.
  • It did not recur. Later sessions show probes overwhelmingly ok and picks
    back near the 40-55 s baseline — close with that stated, naming the sessions
    checked.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingwatchObserved once, not reproduced; may close on did-not-recur

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions