From 27cd64a66841d0072d34d325300d93ea18d5cb81 Mon Sep 17 00:00:00 2001 From: ekklesia Date: Sun, 20 Sep 2026 14:46:46 -0500 Subject: [PATCH] fix: the room asks for its output again, not only once at boot River Kids came up silent on stable 0.2.2. The decision this policy makes was right and was never asked for. classroom-audio applied its policy once at startup and then only when a PipeWire event arrived. pactl talks to PipeWire's PulseAudio server, and the unit was ordered after pipewire and wireplumber but not after that. At boot it therefore raced the server and lost: the single startup apply failed with "Connection refused", the subscription attached cleanly a few seconds later, and from that moment the daemon waited for an event that had already happened. systemd said active, the subscription was live, and the policy had never run at all. That is why the card was found on output:analog-stereo+input:analog-stereo with its HDMI port available. That profile is WirePlumber's own pick, not one this policy would ever produce, which is the evidence it never ran. Reproduced in the lab against real PipeWire 1.4.2 and WirePlumber 0.5.8 by starting the daemon with pipewire-pulse stopped and then starting it: the old daemon sits idle forever, the new one converges. The shape is now: wait for the server, apply, subscribe, apply again the moment the subscription attaches, and coalesce each burst of events into one decision. Applying on attach is the fix for the race. While the room has not got the output it would prefer it also looks again on a backing off timer capped at a minute, so a television switched on hours later is picked up whether or not ALSA's jack change ever reaches us as an event. Once the room has what it wants it stops looking entirely, and a machine with no digital output never looks at all. Also here, all of it found by measuring the real server rather than reading the code: * sink lookup matched on fields a sink does not have. Two of its three conditions could never be true; the one that worked returned whichever sink of the card came first rather than the one for the chosen port. * volume and mute are no longer touched. The old code unmuted and forced 70% on every output change, so every television power cycle reset a volume the teacher had set and could unmute an output muted on purpose. WirePlumber already remembers volume per device. A machine this policy has never configured still gets 70% once. * the profile chosen keeps the card's input, which is the difference between output:hdmi-stereo and the output:hdmi-stereo+input:analog-stereo an administrator reaches for by hand. * a card profile is only set when it is not already in place, and only so many times, so a sink that never appears cannot become a switching loop. * a machine with no sound server at all says so once and backs off, rather than filling the journal. pactl subscribe's own stderr is dropped because saying it is this daemon's job, and a subscription is only treated as healthy once it has lasted, since pactl starts successfully and then fails to connect. * the fixtures described a machine nobody has. Real pactl puts no "direction" on a port at all and says "availability unknown" rather than nothing, so a test could not have caught this. Existing streams are moved explicitly. Measured both ways on the real stack: changing the default sink does move a stream that never asked for a particular sink, but a stream pinned to a device stays where it is with no policy running, and this moves it back without the application being restarted. tests/test-classroom-audio-daemon.sh drives the real daemon through the boot race, a television switched on with and without an event announcing it, a power cycle, a set that never comes on, and a room already correct. It uses a pactl mock because no loopback or dummy sound driver has an HDMI port, so the one thing a lab cannot prove is that the real jack change arrives; docs/testing.md carries the physical procedure for that and says not to take a passing build as evidence of it. Co-Authored-By: Claude Opus 5 --- docs/testing.md | 56 ++ lib/classroom_audio.py | 64 ++- scripts/classroom-audio | 474 +++++++++++++--- systemd/user/ekklesia-classroom-audio.service | 10 +- tests/mock-pactl | 319 +++++++++++ tests/test-classroom-audio-daemon.sh | 516 ++++++++++++++++++ tests/test-classroom-audio.sh | 115 +++- tools/build-release.sh | 2 +- tools/validate-trixie-release.sh | 17 + 9 files changed, 1464 insertions(+), 109 deletions(-) create mode 100755 tests/mock-pactl create mode 100755 tests/test-classroom-audio-daemon.sh diff --git a/docs/testing.md b/docs/testing.md index ec9bbaa..050b6ae 100644 --- a/docs/testing.md +++ b/docs/testing.md @@ -174,6 +174,62 @@ session instead. It never starts mako. - [ ] Running it as an unprivileged admin account explains it needs sudo - [ ] `tests/test-classroom-notify-test.sh` passes (also run by the build) +## Audio + +The room prefers the television. `AUDIO_OUTPUT` in device.conf decides: +`auto` (prefer a connected HDMI or DisplayPort set, fall back to the +jack), `hdmi`, or `analog`. A machine with no digital output at all — a +laptop, when one arrives — is correct on `auto` without any change here. + +Two test suites cover this, and both run in the build: + +- [ ] `tests/test-classroom-audio.sh` — the decision itself, against the + shapes real pactl emits +- [ ] `tests/test-classroom-audio-daemon.sh` — the real daemon driven + through every situation a room gets into, against a pactl that + answers the way PipeWire does + +On a machine: + +- [ ] `classroom-audio show` lists the outputs, what it chose, the + profile it would set and whether it is `settled` +- [ ] `journalctl --user -u ekklesia-classroom-audio` shows one + `output is ...` line per real change and nothing in between +- [ ] Leaving the room alone for an hour adds no further lines and no + measurable CPU time + +### The television switched on after the computer + +This is the scenario that silenced River Kids on 0.2.2 and the one no lab +can produce: ALSA reports a television through the HDMI port's +availability, and no loopback or dummy sound driver has such a port. The +suites above play it through a mock, and the mock is faithful to the real +server as far as it was measured — but a mock cannot prove the real +ALSA jack change arrives. **Do not take a passing build as evidence that +this works.** It has to be done at a machine, once, per release: + +1. Switch the television **off** at the set, not the remote. +2. Reboot the computer and let it reach the classroom desktop. +3. Leave it at least two minutes, so any startup settling is over. +4. `journalctl --user -u ekklesia-classroom-audio` — expect one + `output is ...` line. In a room with nothing in the analog jack it + names the HDMI port even now, which is right: there is nowhere + better for the sound to go, and the set is then already correct + when it comes on. +5. Open Wonder Ink and Chrome and start something playing. +6. Switch the television **on**. +7. Sound should arrive within about a minute, in both applications, + **without closing or reopening either one**. +8. `wpctl status` should show the HDMI sink as default, and + `classroom-audio show` should say `settled=True`. +9. Switch the television off and on again. Sound should come back. +10. Check the volume is where the teacher left it, and that an output + muted on purpose is still muted. + +If step 7 fails, the jack change is not reaching PipeWire at all; capture +`pactl subscribe` and `classroom-audio show` with the set off and then on, +which is what distinguishes that from a policy fault. + ## Messaging - [ ] With `MQTT_ENABLED=false`, `journalctl -u ekklesia-classroom-mqtt` diff --git a/lib/classroom_audio.py b/lib/classroom_audio.py index a614cdb..2b54e44 100644 --- a/lib/classroom_audio.py +++ b/lib/classroom_audio.py @@ -10,13 +10,27 @@ PCM audio, nothing at all plugged into the onboard analog jack, and WirePlumber had chosen analog anyway. A teacher who fixed it by hand then had to restart the browser before any sound came out. -Two rules come out of that: +Two rules came out of that: * a port that reports itself unavailable is not a candidate, and "analog exists" is not evidence that a cable is in it; and * the decision has to be re-made whenever the hardware situation changes, not once at boot, because a television that is switched on after the computer is the normal case in a classroom. + +A third came out of the Sunday the rooms were silent on 0.2.2. The +decision was right and was never asked for: the part that applies it had +made it once, at startup, before PipeWire's PulseAudio server was +listening, and then waited for an event to tell it to try again. So this +module also answers whether the answer it just gave is the best one the +hardware could ever give, which is what lets the caller know whether it +still has something to wait for. + +The shapes here are the ones real pactl emits, which are not the ones the +first set of fixtures assumed. `ports` is an object keyed by port name, +and a port carries no `direction` at all; availability is the phrase +"availability unknown" rather than an empty string. Measured against +PipeWire 1.4.2 and WirePlumber 0.5.8, which is what the rooms run. """ # Port name prefixes PipeWire uses for the digital display outputs. @@ -148,9 +162,17 @@ def choose(cards, preference=AUTO): def profile_for(port): """The card profile to switch to so that a port is usable. - A port lists the profiles it appears in; the classroom wants the one - that turns the output on without also claiming inputs it does not need, - which in practice is the shortest name among the stereo output ones. + A port lists the profiles it appears in. The classroom wants the + plainest output the card offers — stereo rather than one of the + surround arrangements a television will not use — and, among equals, + one that leaves an input in place. + + Dropping the input is what the narrower rule here used to do, and it + is the difference between output:hdmi-stereo and the + output:hdmi-stereo+input:analog-stereo an administrator reaches for by + hand. Nothing in the room records sound today, but taking the + microphone away is not this policy's business, and choosing the same + profile a person would choose keeps the two from undoing each other. """ profiles = [name for name in port.get("profiles") or [] if name != "off"] @@ -159,4 +181,36 @@ def profile_for(port): outputs = [name for name in profiles if "output" in name] or profiles - return sorted(outputs, key=lambda name: (len(name), name))[0] + def rank(name): + # The output half decides first, so stereo beats surround however + # long the rest of the name is. + output = name.split("+", 1)[0] + + return (len(output), 0 if "+input:" in name else 1, len(name), name) + + return sorted(outputs, key=rank)[0] + + +def preferred_kind(preference): + """The kind of output this preference is holding out for.""" + return ANALOG_ONLY if preference == ANALOG_ONLY else HDMI + + +def settled(cards, preference, chosen): + """Whether waiting any longer could produce a better output. + + False means the room is playing through something, but the output it + would rather have exists on this machine and is not usable yet — a + television that is switched off, in practice. The caller uses this to + decide whether it still has a reason to look again, so that a room + which has what it wants is driven by events alone and never polls. + """ + wanted = preferred_kind(preference) + + if chosen is not None and chosen["kind"] == wanted: + return True + + # Nothing of the preferred kind is wired into this machine at all, so + # there is nothing to wait for. A laptop with only a headphone jack is + # settled the moment it picks that jack. + return not any(item["kind"] == wanted for item in candidates(cards)) diff --git a/scripts/classroom-audio b/scripts/classroom-audio index e243bcd..f2867fd 100755 --- a/scripts/classroom-audio +++ b/scripts/classroom-audio @@ -7,8 +7,7 @@ It applies the decision, and then re-applies it whenever the sound hardware changes, which is what makes a television switched on after the computer work without anybody touching anything. -Three things happen on every change, and the third is the one that fixes -the complaint from the room: +Three things happen when the output changes: set the card profile so the output exists at all set the default sink so new sound goes there @@ -16,15 +15,67 @@ the complaint from the room: Without the last step a browser that was started before the change keeps playing into the old sink, and the only fix a teacher can find is to close -and reopen it. That is exactly what happened in the room this was written -for. +and reopen it. -Volume and mute are set once, when the output actually changes. After that -the room's own volume is left alone. +WHY THIS WAS REWRITTEN +---------------------- + +On 0.2.2 the rooms came up silent, and the reason was not the decision — +which was right — but when it was asked for. The old shape was: + + apply once at startup + then apply only when an event arrives + +`pactl` talks to PipeWire's PulseAudio server, and this service was +ordered after pipewire and wireplumber but not after that. At boot it +therefore raced the server and lost: the one startup apply failed with +"Connection refused", the subscription then attached successfully a few +seconds later, and from that moment the daemon sat waiting for an event +that had already happened. It looked perfectly healthy — systemd said +active, the subscription was live — and it had never applied its policy at +all. The room was left on whatever WirePlumber had chosen, which is how an +administrator came to find output:analog-stereo+input:analog-stereo on a +card whose HDMI port was available: that profile is WirePlumber's own +pick, and not one this policy would ever produce. + +Reproduced in the lab by starting this daemon with pipewire-pulse stopped +and then starting it, which leaves exactly the state the room was found +in. + +So the shape is now: + + wait for the server, within reason + apply + subscribe, and apply again the moment the subscription attaches + apply on events, coalescing each burst into one decision + while the room does NOT have the output it would prefer, look again + on a backing-off timer; once it does, stop looking and wait + +The re-apply on attach is the fix for the race. The timer is the fix for +the larger version of the same problem: this policy no longer depends on +an event arriving at the one moment it happens to be listening. A +television switched on hours later is picked up whether or not ALSA's jack +change reaches us as an event. + +Nothing polls once the room has the output it wants. A machine with no +digital output at all never polls either, because there is nothing it +could be waiting for. + +VOLUME AND MUTE +--------------- + +This no longer touches either, except once on a machine it has never +configured before. The old code unmuted the sink and forced it to 70% on +every output change, which meant every television power cycle reset a +volume the teacher had set, and could unmute an output that was muted on +purpose. WirePlumber already remembers volume per device, so leaving it +alone is both less code and the behaviour the room wants. """ +import errno import json import os +import select import subprocess import sys import time @@ -45,15 +96,64 @@ except ImportError: # pragma: no cover - the daemon must not need it # Loud enough to be heard at the back of a classroom, quiet enough that the -# first thing a teacher plays is not a shock. Only ever applied when the -# output changes, never on top of a volume somebody has chosen. +# first thing a teacher plays is not a shock. Applied once in the life of a +# machine, when this policy has never configured it before; after that the +# room's own volume is never touched again. DEFAULT_VOLUME = "70%" -# Several udev events arrive for one cable being plugged in. Settle first. +# Several events arrive for one television being switched on. The burst is +# drained to quiet before deciding, so one change is one decision rather +# than one decision per event — which is what the old sleep-per-line did, +# and it turned a single change into some forty seconds of churn. SETTLE_SECONDS = 1.5 +# However chatty the server is, service it eventually. +SETTLE_LIMIT_SECONDS = 6.0 -def pactl(*args, parse=False): +# How long to wait for PipeWire's PulseAudio server at startup before +# carrying on regardless. Bounded: a room with no sound server must still +# reach the watch loop rather than spin here. +SERVER_WAIT_SECONDS = 60 + +# While the room has not got the output it would prefer — a television +# that is off, in practice — look again on a backing-off timer. Read-only +# unless the answer actually changes, and capped, so a set that is never +# switched on costs one `pactl list cards` a minute forever and changes +# nothing. +RECHECK_START_SECONDS = 5 +RECHECK_LIMIT_SECONDS = 60 + +# A subscription that will not stay up is retried, but at a rate that +# cannot become a spin on a machine with no sound server at all. +RESUBSCRIBE_SECONDS = 3 +RESUBSCRIBE_LIMIT_SECONDS = 60 + +# A subscription that lasted this long was a real one, so the next time it +# drops it is worth reconnecting quickly again. Anything shorter is a +# server that is not answering, and is backed off from. +SUBSCRIPTION_HEALTHY_SECONDS = 10 + +# A card profile is only re-asserted so many times before the daemon stops +# trying, so that a sink which never appears cannot become a profile +# switching loop. +PROFILE_ATTEMPTS = 3 + +# Remembers that this machine has been configured once, so the default +# volume is a first-run courtesy rather than something applied at every +# boot on top of a volume somebody chose. +STATE_DIRECTORY = os.path.join( + os.environ.get("XDG_STATE_HOME") + or os.path.expanduser("~/.local/state"), + "ekklesia-classroom", +) +STATE_FILE = os.path.join(STATE_DIRECTORY, "audio-configured") + + +def log(message): + print(f"classroom-audio: {message}", flush=True) + + +def pactl(*args, parse=False, quiet=False): command = ["pactl"] if parse: @@ -66,11 +166,13 @@ def pactl(*args, parse=False): command, capture_output=True, text=True, timeout=15, check=False ) except (OSError, subprocess.SubprocessError) as error: - log(f"pactl {' '.join(args)}: {error}") + if not quiet: + log(f"pactl {' '.join(args)}: {error}") return None if result.returncode != 0: - log(f"pactl {' '.join(args)}: {result.stderr.strip()}") + if not quiet: + log(f"pactl {' '.join(args)}: {result.stderr.strip()}") return None if not parse: @@ -83,10 +185,6 @@ def pactl(*args, parse=False): return None -def log(message): - print(f"classroom-audio: {message}", flush=True) - - def preference(): value = (read_device_config() or {}).get("AUDIO_OUTPUT", policy.AUTO) value = (value or "").strip().lower() @@ -95,104 +193,314 @@ def preference(): else policy.AUTO -def sink_for_card(card_name): - for sink in pactl("list", "sinks", parse=True) or []: - properties = sink.get("properties") or {} +def configured_before(): + return os.path.exists(STATE_FILE) - if properties.get("alsa.card_name") and card_name and \ - properties.get("device.string"): - pass - if (sink.get("card") == card_name - or properties.get("device.name") == card_name - or (card_name or "") in (sink.get("name") or "")): +def remember_configured(): + try: + os.makedirs(STATE_DIRECTORY, exist_ok=True) + with open(STATE_FILE, "w") as handle: + handle.write("This machine's audio output has been set up once.\n") + except OSError as error: + # Losing this only means the first-run volume is offered again + # later. It is never worth failing the policy for. + log(f"could not record first run: {error}") + + +def sink_for(sinks, chosen): + """The sink that carries the chosen port. + + A sink is tied to its card by properties["device.name"], which is the + card's name — there is no top-level card field on a sink, whatever the + older code here believed. Two of its three conditions could never + match; the one that did returned whichever sink of that card came + first, which is not necessarily the one for the port just chosen. + """ + card = chosen["card"] + port = chosen["port"] + + on_card = [ + sink for sink in sinks or [] + if (sink.get("properties") or {}).get("device.name") == card + ] + + if not on_card: + return None + + for sink in on_card: + if sink.get("active_port") == port: return sink + for sink in on_card: + names = { + entry.get("name") for entry in sink.get("ports") or [] + if isinstance(entry, dict) + } + + if port in names: + return sink + + return on_card[0] + + +def active_profile_of(cards, card_name): + for card in cards or []: + if card.get("name") == card_name: + return card.get("active_profile") + return None -def apply(state): - cards = pactl("list", "cards", parse=True) +def move_streams(name, index): + """Send sound that is already playing to the new output. - if cards is None: - return - - chosen = policy.choose(cards, preference()) - - if chosen is None: - if state.get("port") is not None: - log("no usable output") - state["port"] = None - return - - profile = policy.profile_for(chosen) - changed = state.get("port") != (chosen["card"], chosen["port"]) - - if changed and profile: - pactl("set-card-profile", str(chosen["card"]), profile) - # The sink appears only after the profile is in place. - time.sleep(0.4) - - sink = sink_for_card(chosen["card"]) - - if sink is None: - log(f"no sink for {chosen['card']} after {profile}") - return - - name = sink.get("name") - pactl("set-default-sink", name) - - if changed: - pactl("set-sink-mute", name, "0") - pactl("set-sink-volume", name, DEFAULT_VOLUME) - log(f"output is {chosen['port']} on {chosen['card']} ({name})") - - # Anything already making sound follows, so a browser that was open - # before the television was switched on does not have to be restarted. + Changing the default sink does move streams that never asked for a + particular one — measured on PipeWire 1.4.2, WirePlumber does it — but + a stream WirePlumber has pinned to a device stays where it is, so the + move is still made explicitly. + """ moved = 0 for stream in pactl("list", "sink-inputs", parse=True) or []: - if stream.get("sink") == sink.get("index"): + if stream.get("sink") == index: continue if pactl("move-sink-input", str(stream.get("index")), name) is not None: moved += 1 - if moved: - log(f"moved {moved} playing stream(s) to {name}") + return moved - state["port"] = (chosen["card"], chosen["port"]) + +def apply(state): + """Make the room match the decision. Returns True once it is settled.""" + cards = pactl("list", "cards", parse=True, quiet=state.get("offline", False)) + + if cards is None: + # Said once, not every few seconds for as long as the machine has + # no sound server. + if not state.get("offline"): + log("cannot reach the sound server") + state["offline"] = True + + return False + + if state.get("offline"): + log("the sound server is back") + state["offline"] = False + + want = preference() + chosen = policy.choose(cards, want) + + if chosen is None: + if state.get("port") is not None: + log("no usable output") + + state["port"] = None + + return policy.settled(cards, want, None) + + key = (chosen["card"], chosen["port"]) + changed = state.get("port") != key + + if changed: + profile = policy.profile_for(chosen) + active = active_profile_of(cards, chosen["card"]) + + # Only ever asked for when it is not already in place, so a room + # that is working is never disturbed and the card is not switched + # in a circle. + if profile and profile != active: + attempts = state.get("attempts", {}) + tried = attempts.get(key, 0) + + if tried >= PROFILE_ATTEMPTS: + log(f"giving up on {profile} for {chosen['card']}") + + return True + + attempts[key] = tried + 1 + state["attempts"] = attempts + + pactl("set-card-profile", str(chosen["card"]), profile) + # The sink only exists once the profile is in place. + time.sleep(0.6) + + sinks = pactl("list", "sinks", parse=True) + sink = sink_for(sinks, chosen) + + if sink is None: + # Deliberately leaves state["port"] alone so the next look tries + # again, and deliberately counted, so it cannot try forever. + log(f"no sink yet for {chosen['port']} on {chosen['card']}") + + return False + + name = sink.get("name") + + if sink.get("name") != (pactl("get-default-sink") or "").strip(): + pactl("set-default-sink", name) + + if changed: + if not configured_before(): + # The one time this machine's volume is set for it. + pactl("set-sink-volume", name, DEFAULT_VOLUME) + log(f"first run: {name} set to {DEFAULT_VOLUME}") + remember_configured() + + moved = move_streams(name, sink.get("index")) + + log(f"output is {chosen['port']} on {chosen['card']} ({name})" + + (f", moved {moved} playing stream(s)" if moved else "")) + + state["attempts"] = {} + else: + # A television coming back can leave a stream stranded on a sink + # that has gone; nothing is logged when there is nothing to do. + move_streams(name, sink.get("index")) + + state["port"] = key + + return policy.settled(cards, want, chosen) + + +def wait_for_server(): + """Let PipeWire's PulseAudio server finish starting. + + The race this avoids is the whole reason the rooms were silent, and + ordering the unit after pipewire-pulse is not by itself enough: the + socket can be there before the server will answer. + """ + deadline = time.monotonic() + SERVER_WAIT_SECONDS + complained = False + + while time.monotonic() < deadline: + if pactl("info", quiet=True) is not None: + return True + + if not complained: + log("waiting for the sound server") + complained = True + + time.sleep(1) + + log("carrying on without having reached the sound server") + + return False + + +def _interesting(line): + return any(word in line for word in ("card", "server", "sink", "source")) def watch(): - """Follow PipeWire's own event stream rather than polling it.""" state = {} - apply(state) + + wait_for_server() + settled = apply(state) + delay = RECHECK_START_SECONDS + backoff = RESUBSCRIBE_SECONDS + complained = False while True: - process = subprocess.Popen( - ["pactl", "subscribe"], - stdout=subprocess.PIPE, - text=True, - ) + try: + started = time.monotonic() + process = subprocess.Popen( + ["pactl", "subscribe"], + stdout=subprocess.PIPE, + # pactl says "Connection refused" on its own stderr every + # time it cannot reach the server. Saying so once is this + # daemon's job; letting pactl say it into the journal + # every few seconds is not. + stderr=subprocess.DEVNULL, + ) + except OSError as error: + log(f"could not subscribe: {error}") + time.sleep(backoff) + backoff = min(backoff * 2, RESUBSCRIBE_LIMIT_SECONDS) + continue + + stream = process.stdout + pending = b"" + + # Everything that happened before this attached is invisible to it, + # including everything that happened at boot. This is the line the + # silent rooms were missing. + settled = apply(state) try: - for line in process.stdout: + while process.poll() is None: + timeout = None if settled else delay + ready, _, _ = select.select([stream], [], [], timeout) + + if not ready: + # The room has not got the output it would prefer, so + # look again without waiting to be told. + settled = apply(state) + delay = (RECHECK_START_SECONDS if settled + else min(delay * 2, RECHECK_LIMIT_SECONDS)) + continue + + try: + chunk = os.read(stream.fileno(), 65536) + except OSError as error: + if error.errno == errno.EINTR: + continue + raise + + if not chunk: + break + + pending += chunk + lines = pending.split(b"\n") + pending = lines.pop() + if not any( - word in line for word in ("card", "server", "sink", "source") + _interesting(line.decode("utf-8", "replace")) + for line in lines ): continue - # Drain the rest of the burst before acting once. - time.sleep(SETTLE_SECONDS) - apply(state) + # Drain to quiet before deciding, so one television being + # switched on is one decision and not a dozen. + limit = time.monotonic() + SETTLE_LIMIT_SECONDS + + while time.monotonic() < limit: + quiet = select.select([stream], [], [], SETTLE_SECONDS)[0] + + if not quiet: + break + + if not os.read(stream.fileno(), 65536): + break + + pending = b"" + settled = apply(state) + # Whatever it was waiting for, it starts looking eagerly + # again rather than at whatever rate it had backed off to. + delay = RECHECK_START_SECONDS except OSError as error: log(f"subscription ended: {error}") finally: process.terminate() - log("re-subscribing") - time.sleep(3) + try: + process.wait(timeout=5) + except subprocess.SubprocessError: + process.kill() + + if time.monotonic() - started >= SUBSCRIPTION_HEALTHY_SECONDS: + # It ran for a while, so this is an ordinary reconnect rather + # than a server that is not there. + backoff = RESUBSCRIBE_SECONDS + complained = False + + if not complained: + log("re-subscribing") + complained = True + + time.sleep(backoff) + backoff = min(backoff * 2, RESUBSCRIBE_LIMIT_SECONDS) def main(): @@ -202,12 +510,16 @@ def main(): if len(sys.argv) > 1 and sys.argv[1] == "show": cards = pactl("list", "cards", parse=True) or [] + for item in policy.candidates(cards): print(f"{item['kind']:6} {item['availability']:13} " f"prio={item['priority']:<6} {item['card']} {item['port']}") + chosen = policy.choose(cards, preference()) print(f"\npreference={preference()} chosen=" - f"{chosen['port'] if chosen else 'none'}") + f"{chosen['port'] if chosen else 'none'} " + f"profile={policy.profile_for(chosen) if chosen else 'none'} " + f"settled={policy.settled(cards, preference(), chosen)}") return 0 watch() diff --git a/systemd/user/ekklesia-classroom-audio.service b/systemd/user/ekklesia-classroom-audio.service index ddc3a67..98c56a8 100644 --- a/systemd/user/ekklesia-classroom-audio.service +++ b/systemd/user/ekklesia-classroom-audio.service @@ -1,8 +1,14 @@ [Unit] Description=Ekklesia Classroom audio output policy Documentation=file:///usr/local/bin/classroom-audio -After=pipewire.service wireplumber.service -Wants=pipewire.service wireplumber.service +# pactl talks to PipeWire's PulseAudio server, not to pipewire itself. +# Ordering only after pipewire and wireplumber is what let this service +# win the race against it at boot, fail its one startup apply, and then +# sit subscribed and idle while the room stayed on WirePlumber's choice. +# The daemon waits for the server as well: the socket can exist before +# anything will answer on it, so ordering alone is not enough. +After=pipewire.service pipewire-pulse.socket pipewire-pulse.service wireplumber.service +Wants=pipewire.service pipewire-pulse.socket wireplumber.service PartOf=graphical-session.target [Service] diff --git a/tests/mock-pactl b/tests/mock-pactl new file mode 100755 index 0000000..9559bf8 --- /dev/null +++ b/tests/mock-pactl @@ -0,0 +1,319 @@ +#!/usr/bin/env python3 + +"""A pactl that answers for a classroom nobody has to be standing in. + +This exists because the one thing the room actually does — a television +switched off while the computer boots and switched on afterwards — cannot +be produced by any sound card a lab has. ALSA reports a television through +the HDMI port's availability, and no loopback or dummy driver has one. + +So the scenarios that matter are played through this instead, and the real +classroom-audio daemon runs against it unmodified. Everything here is +shaped the way PipeWire 1.4.2 and WirePlumber 0.5.8 really answer, checked +against both running in the lab: + + cards "ports" is an object keyed by port name, a port carries NO + "direction", and an unknown availability is the phrase + "availability unknown" + sinks have no top-level "card"; the link to the card is + properties["device.name"], and "active_port" is a port name + profile switching one destroys the old sink and creates a new one, + and emits a burst of events rather than a single one + +It also records every command that changes anything, so a test can say +"and nothing was switched twice", which is the property the room needs +most and the one that is invisible from a single snapshot. +""" + +import json +import os +import sys +import time + +STATE = os.environ["MOCK_AUDIO_STATE"] +EVENTS = os.environ["MOCK_AUDIO_EVENTS"] +JOURNAL = os.environ["MOCK_AUDIO_JOURNAL"] + + +def load(): + with open(STATE) as handle: + return json.load(handle) + + +def save(state): + temporary = f"{STATE}.new" + + with open(temporary, "w") as handle: + json.dump(state, handle, indent=2) + + os.replace(temporary, STATE) + + +def record(line): + with open(JOURNAL, "a") as handle: + handle.write(line + "\n") + + +def emit(*events): + with open(EVENTS, "a") as handle: + for event in events: + handle.write(event + "\n") + + +def output_token(profile): + """hdmi-stereo, from output:hdmi-stereo+input:analog-stereo.""" + head = (profile or "").split("+", 1)[0] + + return head.split(":", 1)[1] if ":" in head else "" + + +def active_port_of(card): + profile = card.get("active_profile") or "" + + for name, port in (card.get("ports") or {}).items(): + if profile in (port.get("profiles") or []) and "output" in profile: + # The port whose own kind matches the output half of the + # profile, so an analog profile does not light the HDMI port. + token = output_token(profile) + + if name.startswith("hdmi") or name.startswith("displayport"): + if "hdmi" in token or "dp" in token: + return name, port + elif "analog" in token or "stereo" in token: + return name, port + + return None, None + + +def sinks_of(state): + """One sink per card, for whatever its active profile turned on.""" + sinks = [] + index = 40 + + for card in state["cards"]: + profile = card.get("active_profile") or "" + index += 1 + + if not profile.startswith("output:"): + continue + + name, port = active_port_of(card) + + if name is None: + continue + + suffix = card["name"].split(".", 1)[-1] + sink_name = f"alsa_output.{suffix}.{output_token(profile)}" + levels = state.setdefault("levels", {}) + level = levels.get(sink_name, {"volume": 100, "mute": False}) + + sinks.append({ + "index": index, + "state": "SUSPENDED", + "name": sink_name, + "description": card.get("description", "Built-in Audio"), + "mute": level["mute"], + "volume": { + "front-left": {"value_percent": f"{level['volume']}%"}, + "front-right": {"value_percent": f"{level['volume']}%"}, + }, + "properties": { + "device.name": card["name"], + "node.name": sink_name, + "alsa.card_name": card.get("description", "Built-in Audio"), + "device.profile.name": output_token(profile), + }, + "ports": [{ + "name": name, + "availability": port.get("availability", + "availability unknown"), + "priority": port.get("priority", 0), + }], + "active_port": name, + }) + + return sinks + + +def sink_named(state, name): + for sink in sinks_of(state): + if sink["name"] == name: + return sink + + return None + + +def main(): + argv = sys.argv[1:] + + if argv[:2] == ["-f", "json"]: + argv = argv[2:] + as_json = True + else: + as_json = False + + if not argv: + return 1 + + state = load() + + # The server not being up yet is the whole of the boot race, so it is + # a state this has to be able to be in. + if not state.get("server_up", True) and argv[0] != "subscribe": + sys.stderr.write("Connection failure: Connection refused\n") + return 1 + + command = argv[0] + + if command == "info": + if not state.get("server_up", True): + sys.stderr.write("Connection failure: Connection refused\n") + return 1 + print("Server Name: PulseAudio (on PipeWire 1.4.2)") + return 0 + + if command == "list": + what = argv[1] if len(argv) > 1 else "" + + if what == "cards": + payload = state["cards"] + elif what == "sinks": + payload = sinks_of(state) + elif what == "sink-inputs": + payload = state.get("streams", []) + else: + payload = [] + + print(json.dumps(payload) if as_json else "") + return 0 + + if command == "get-default-sink": + print(state.get("default_sink") or "") + return 0 + + if command == "set-default-sink": + name = argv[1] + + if sink_named(state, name) is None: + sys.stderr.write(f"Failure: No such entity {name}\n") + return 1 + + if state.get("default_sink") != name: + record(f"set-default-sink {name}") + state["default_sink"] = name + save(state) + # A no-op set-default-sink emits nothing on the real server; + # measured. Only a real change is announced. + emit("Event 'change' on server #4294967295") + + return 0 + + if command == "set-card-profile": + card_name, profile = argv[1], argv[2] + + for card in state["cards"]: + if card["name"] != card_name: + continue + + if profile not in (card.get("profiles") or []): + sys.stderr.write(f"Failure: No such profile {profile}\n") + return 1 + + record(f"set-card-profile {card_name} {profile}") + old = sinks_of(state) + card["active_profile"] = profile + save(state) + new = sinks_of(state) + + # Switching a profile tears the old sink down and builds a new + # one, and the server says all of it. + events = [] + for sink in old: + if sink["name"] not in [item["name"] for item in new]: + events.append(f"Event 'remove' on sink #{sink['index']}") + events.append(f"Event 'change' on card #{card.get('index', 0)}") + for sink in new: + if sink["name"] not in [item["name"] for item in old]: + events.append(f"Event 'new' on sink #{sink['index']}") + emit(*events) + + # A stream on a sink that has gone is re-landed by the server + # on whatever is default, exactly as WirePlumber does. + survivors = [item["name"] for item in new] + for stream in state.get("streams", []): + if stream.get("sink_name") not in survivors: + fallback = state.get("default_sink") or ( + survivors[0] if survivors else None) + stream["sink_name"] = fallback + target = sink_named(state, fallback) if fallback else None + stream["sink"] = target["index"] if target else -1 + save(state) + return 0 + + sys.stderr.write(f"Failure: No such card {card_name}\n") + return 1 + + if command == "set-sink-volume": + name, value = argv[1], argv[2] + record(f"set-sink-volume {name} {value}") + state.setdefault("levels", {}).setdefault( + name, {"volume": 100, "mute": False}) + state["levels"][name]["volume"] = int(value.rstrip("%")) + save(state) + emit(f"Event 'change' on sink #{sink_named(state, name)['index']}") + return 0 + + if command == "set-sink-mute": + name, value = argv[1], argv[2] + record(f"set-sink-mute {name} {value}") + state.setdefault("levels", {}).setdefault( + name, {"volume": 100, "mute": False}) + state["levels"][name]["mute"] = value not in ("0", "false", "no") + save(state) + emit(f"Event 'change' on sink #{sink_named(state, name)['index']}") + return 0 + + if command == "move-sink-input": + index, name = int(argv[1]), argv[2] + target = sink_named(state, name) + + if target is None: + sys.stderr.write(f"Failure: No such entity {name}\n") + return 1 + + for stream in state.get("streams", []): + if stream["index"] == index: + if stream.get("sink_name") != name: + record(f"move-sink-input {index} {name}") + stream["sink_name"] = name + stream["sink"] = target["index"] + save(state) + emit(f"Event 'change' on sink-input #{index}") + return 0 + + sys.stderr.write(f"Failure: No such entity {index}\n") + return 1 + + if command == "subscribe": + # Blocks and prints events as they happen, like the real one. Only + # events written from now on: a subscription never replays what it + # missed, which is precisely how the rooms came to be silent. + with open(EVENTS) as handle: + handle.seek(0, os.SEEK_END) + + while True: + line = handle.readline() + + if not line: + time.sleep(0.05) + continue + + sys.stdout.write(line) + sys.stdout.flush() + + sys.stderr.write(f"mock-pactl: unhandled {' '.join(argv)}\n") + return 1 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/tests/test-classroom-audio-daemon.sh b/tests/test-classroom-audio-daemon.sh new file mode 100755 index 0000000..804a8b8 --- /dev/null +++ b/tests/test-classroom-audio-daemon.sh @@ -0,0 +1,516 @@ +#!/bin/bash +# The audio policy daemon, driven through the situations a classroom is +# actually in, with the real script and a pactl that answers the way +# PipeWire really does. +# +# These are the properties a snapshot cannot show: that the room converges +# when the sound server was not ready at boot, that a television switched +# on later is picked up whether or not an event announces it, and that +# nothing is switched over and over when everything is already right. +set -uo pipefail + +ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" + +PYTHONPATH="$ROOT/lib" CLASSROOM_ROOT="$ROOT" python3 - <<'PY' +import json +import os +import shutil +import subprocess +import sys +import tempfile +import time + +ROOT = os.environ["CLASSROOM_ROOT"] +DAEMON = os.path.join(ROOT, "scripts", "classroom-audio") +MOCK = os.path.join(ROOT, "tests", "mock-pactl") + +passed = failed = 0 + + +def check(label, condition, detail=""): + global passed, failed + if condition: + print(f" ok {label}") + passed += 1 + else: + print(f" FAIL {label}") + if detail: + print(f" {detail}") + failed += 1 + + +ANALOG_PROFILES = [ + "output:analog-stereo", + "output:analog-stereo+input:analog-stereo", + "output:analog-surround-40+input:analog-stereo", +] +HDMI_PROFILES = [ + "output:hdmi-stereo", + "output:hdmi-stereo+input:analog-stereo", + "output:hdmi-surround+input:analog-stereo", +] +ALL_PROFILES = ["off"] + ANALOG_PROFILES + HDMI_PROFILES + +ANALOG_SINK = "alsa_output.pci-0000_00_1f.3.analog-stereo" +HDMI_SINK = "alsa_output.pci-0000_00_1f.3.hdmi-stereo" + + +def room(hdmi="not available", jack="not available", + active="output:analog-stereo+input:analog-stereo", + server_up=True): + """The River Kids machine, as pactl described it over SSH. + + `jack` is what the onboard analog output reports. River Kids has + nothing plugged into it, which is why it says "not available" and why + that room prefers HDMI even with the television off: there is nowhere + better for the sound to go. A room with speakers in the jack is a + different room, and it is the one that can fall back. + """ + return { + "server_up": server_up, + "default_sink": ANALOG_SINK, + "levels": {}, + "streams": [], + "cards": [{ + "name": "alsa_card.pci-0000_00_1f.3", + "index": 47, + "description": "Built-in Audio", + "active_profile": active, + "profiles": ALL_PROFILES, + "ports": { + "analog-output-lineout": { + "availability": jack, + "priority": 9900, + "profiles": ANALOG_PROFILES, + }, + "hdmi-output-0": { + "availability": hdmi, + "priority": 5900, + "profiles": HDMI_PROFILES, + }, + }, + }], + } + + +class Lab: + def __init__(self, state): + self.dir = tempfile.mkdtemp(prefix="classroom-audio-") + self.state_path = os.path.join(self.dir, "state.json") + self.events = os.path.join(self.dir, "events") + self.journal = os.path.join(self.dir, "journal") + self.log = os.path.join(self.dir, "daemon.log") + self.write(state) + open(self.events, "w").close() + open(self.journal, "w").close() + + # A pactl that is this mock and nothing else. + self.bin = os.path.join(self.dir, "bin") + os.makedirs(self.bin) + os.symlink(MOCK, os.path.join(self.bin, "pactl")) + + self.process = None + + def write(self, state): + with open(self.state_path, "w") as handle: + json.dump(state, handle, indent=2) + + def read(self): + with open(self.state_path) as handle: + return json.load(handle) + + def edit(self, change): + state = self.read() + change(state) + self.write(state) + + def start(self): + environment = dict(os.environ) + environment["PATH"] = self.bin + os.pathsep + environment["PATH"] + environment["MOCK_AUDIO_STATE"] = self.state_path + environment["MOCK_AUDIO_EVENTS"] = self.events + environment["MOCK_AUDIO_JOURNAL"] = self.journal + environment["XDG_STATE_HOME"] = os.path.join(self.dir, "state-home") + # device.conf is not readable here, so the daemon falls back to + # auto, which is what the classroom machines are set to. + environment["PYTHONPATH"] = os.path.join(ROOT, "lib") + + self.process = subprocess.Popen( + [sys.executable, DAEMON], + stdout=open(self.log, "w"), stderr=subprocess.STDOUT, + env=environment, + ) + + def stop(self): + if self.process: + self.process.terminate() + try: + self.process.wait(timeout=10) + except subprocess.SubprocessError: + self.process.kill() + + def journal_lines(self): + with open(self.journal) as handle: + return [line.strip() for line in handle if line.strip()] + + def daemon_log(self): + with open(self.log) as handle: + return handle.read() + + def await_log(self, text, timeout=40): + """Wait for the daemon to SAY it has done something. + + Waiting on the sink cannot distinguish "the daemon chose this" + from "the fixture already said this", and a test that cannot tell + those apart races the daemon's first decision. + """ + deadline = time.monotonic() + timeout + + while time.monotonic() < deadline: + if text in self.daemon_log(): + return True + time.sleep(0.25) + + return False + + def await_sink(self, name, timeout=40): + """Wait for the room to be playing through a particular sink.""" + deadline = time.monotonic() + timeout + + while time.monotonic() < deadline: + if self.read().get("default_sink") == name: + return True + time.sleep(0.25) + + return False + + def clean(self): + self.stop() + shutil.rmtree(self.dir, ignore_errors=True) + + +def profile_of(state): + return state["cards"][0]["active_profile"] + + +def switches(lab): + return [line for line in lab.journal_lines() + if line.startswith("set-card-profile")] + + +# ---------------------------------------------------------------- 1 +print("1. the computer starts with the television already on") +lab = Lab(room(hdmi="available")) +try: + lab.start() + check("HDMI is selected without anyone touching anything", + lab.await_sink(HDMI_SINK), lab.daemon_log()) + check("and on a profile that keeps the card's input", + profile_of(lab.read()) == "output:hdmi-stereo+input:analog-stereo", + profile_of(lab.read())) +finally: + lab.clean() + +# ---------------------------------------------------------------- 2 +print("2. the television is off at boot, then switched on (with an event)") +lab = Lab(room(hdmi="not available", jack="available")) +try: + lab.start() + check("the room falls back to the jack rather than going silent", + lab.await_log("output is analog-output-lineout"), lab.daemon_log()) + + def switch_on(state): + state["cards"][0]["ports"]["hdmi-output-0"]["availability"] = "available" + + lab.edit(switch_on) + with open(lab.events, "a") as handle: + handle.write("Event 'change' on card #47\n") + + check("the television is picked up when it announces itself", + lab.await_sink(HDMI_SINK), lab.daemon_log()) +finally: + lab.clean() + +# ---------------------------------------------------------------- 3 +print("3. the television is switched on and NOTHING announces it") +# ALSA's jack change does not always surface as a pactl event. The old +# policy could only ever act on an event, so this was a room that stayed +# silent all morning. +lab = Lab(room(hdmi="not available", jack="available")) +try: + lab.start() + check("the room starts on the jack", + lab.await_log("output is analog-output-lineout"), lab.daemon_log()) + + def switch_on(state): + state["cards"][0]["ports"]["hdmi-output-0"]["availability"] = "available" + + lab.edit(switch_on) + # Deliberately no event written. + check("the television is still picked up, by looking again", + lab.await_sink(HDMI_SINK), lab.daemon_log()) +finally: + lab.clean() + +# ---------------------------------------------------------------- 4 +print("4. the boot race that silenced the rooms on 0.2.2") +# The daemon starts before PipeWire's PulseAudio server will answer. The +# old code failed its single startup apply, subscribed successfully a +# moment later, and then waited forever for an event that had already +# happened — leaving the card on WirePlumber's own profile, which is +# exactly what was found in River Kids. +lab = Lab(room(hdmi="available", server_up=False)) +try: + lab.start() + time.sleep(3) + check("nothing is applied while the server refuses connections", + lab.read().get("default_sink") == ANALOG_SINK) + + def server_up(state): + state["server_up"] = True + + lab.edit(server_up) + # No event is written: at a real boot the card's events all happen + # while the daemon cannot connect, and none arrive afterwards. + check("the room converges on HDMI once the server answers", + lab.await_sink(HDMI_SINK), lab.daemon_log()) + check("and the card is left on a profile the policy chose", + profile_of(lab.read()) == "output:hdmi-stereo+input:analog-stereo", + profile_of(lab.read())) +finally: + lab.clean() + +# ---------------------------------------------------------------- 5 +print("5. the television is switched off and on again while a lesson plays") +# Speakers in the jack, so there is somewhere to fall back TO. The room +# that has nothing in the jack is scenario 5b below. +lab = Lab(room(hdmi="available", jack="available")) +try: + lab.start() + check("the lesson starts out on the television", lab.await_sink(HDMI_SINK)) + + def add_stream(state): + state["streams"] = [{ + "index": 700, + "sink": 41, + "sink_name": HDMI_SINK, + "properties": {"application.name": "Chromium"}, + }] + + lab.edit(add_stream) + + def switch_off(state): + state["cards"][0]["ports"]["hdmi-output-0"]["availability"] = \ + "not available" + + lab.edit(switch_off) + with open(lab.events, "a") as handle: + handle.write("Event 'change' on card #47\n") + + check("it falls back to the jack while the set is off", + lab.await_sink(ANALOG_SINK), lab.daemon_log()) + + def switch_on(state): + state["cards"][0]["ports"]["hdmi-output-0"]["availability"] = "available" + + lab.edit(switch_on) + with open(lab.events, "a") as handle: + handle.write("Event 'change' on card #47\n") + + check("and comes back to the television when it returns", + lab.await_sink(HDMI_SINK), lab.daemon_log()) + + time.sleep(2) + stream = lab.read()["streams"][0] + check("the lesson that never stopped playing is on the television too", + stream["sink_name"] == HDMI_SINK, + f"stream left on {stream['sink_name']}") +finally: + lab.clean() + +# ---------------------------------------------------------------- 5b +print("5b. River Kids: the same power cycle with nothing in the jack") +# This room has no speakers in the analog socket, so when the television +# goes off there is nowhere better for the sound to go and the policy is +# right to stay pointed at the set. What it must not do is thrash between +# two outputs that are both unusable, or lose the television when it comes +# back. +lab = Lab(room(hdmi="available", jack="not available")) +try: + lab.start() + check("the lesson starts on the television", lab.await_sink(HDMI_SINK)) + + def switch_off(state): + state["cards"][0]["ports"]["hdmi-output-0"]["availability"] = \ + "not available" + + lab.edit(switch_off) + with open(lab.events, "a") as handle: + handle.write("Event 'change' on card #47\n") + time.sleep(8) + + check("it stays on the set rather than moving to an empty socket", + lab.read()["default_sink"] == HDMI_SINK, + lab.read()["default_sink"]) + check("and does not switch the card back and forth while it is off", + len(switches(lab)) <= 2, f"profile switches: {switches(lab)}") + + def switch_on(state): + state["cards"][0]["ports"]["hdmi-output-0"]["availability"] = "available" + + lab.edit(switch_on) + check("and the television still works when it comes back", + lab.await_sink(HDMI_SINK), lab.daemon_log()) +finally: + lab.clean() + +# ---------------------------------------------------------------- 6 +print("6. a television that is never switched on") +lab = Lab(room(hdmi="not available", jack="available")) +try: + lab.start() + check("the room settles on the jack", + lab.await_log("output is analog-output-lineout"), lab.daemon_log()) + time.sleep(25) + moves = switches(lab) + check("the card is not switched over and over while it waits", + len(moves) <= 2, f"{len(moves)} profile switches: {moves}") + check("and the daemon is still alive rather than having given up", + lab.process.poll() is None) + check("and it never went silent", + lab.read()["default_sink"] == ANALOG_SINK) +finally: + lab.clean() + +# ---------------------------------------------------------------- 7 +print("7. a room that is already right is left alone") +lab = Lab(room(hdmi="available")) +try: + lab.start() + check("it selects the television once", lab.await_sink(HDMI_SINK)) + time.sleep(20) + check("and then changes nothing at all, however long it runs", + len(switches(lab)) == 1, + f"profile switches: {switches(lab)}") + check("no repeated default-sink writes either", + len([line for line in lab.journal_lines() + if line.startswith("set-default-sink")]) == 1, + str(lab.journal_lines())) +finally: + lab.clean() + +# ---------------------------------------------------------------- 8 +print("8. the teacher's volume and mute are left alone") +lab = Lab(room(hdmi="not available", jack="available")) +try: + lab.start() + check("the room starts on the jack", + lab.await_log("output is analog-output-lineout"), lab.daemon_log()) + + # The teacher turns it down and mutes it on purpose. + def teacher(state): + state["levels"] = { + ANALOG_SINK: {"volume": 35, "mute": True}, + HDMI_SINK: {"volume": 55, "mute": True}, + } + state["cards"][0]["ports"]["hdmi-output-0"]["availability"] = "available" + + lab.edit(teacher) + check("the television is picked up", lab.await_sink(HDMI_SINK), + lab.daemon_log()) + time.sleep(2) + + levels = lab.read()["levels"] + check("the television's own volume is not overwritten", + levels[HDMI_SINK]["volume"] == 55, + f"volume became {levels[HDMI_SINK]['volume']}") + check("an output muted on purpose is not unmuted", + levels[HDMI_SINK]["mute"] is True) + volume_commands = [line for line in lab.journal_lines() + if line.startswith("set-sink-volume")] + check("the only volume ever set is the one first run on the jack", + len(volume_commands) == 1 + and ANALOG_SINK in volume_commands[0] + and "70%" in volume_commands[0], + str(volume_commands)) + check("and the television's volume was never written", + not [line for line in volume_commands if HDMI_SINK in line], + str(volume_commands)) + check("and mute was never touched", + not [line for line in lab.journal_lines() + if line.startswith("set-sink-mute")], + str(lab.journal_lines())) +finally: + lab.clean() + +# ---------------------------------------------------------------- 9 +print("9. sound that is already playing follows the television") +lab = Lab(room(hdmi="not available", jack="available")) +try: + lab.start() + check("the room starts on the jack", + lab.await_log("output is analog-output-lineout"), lab.daemon_log()) + + def lesson_and_tv(state): + state["streams"] = [ + {"index": 701, "sink": 41, "sink_name": ANALOG_SINK, + "properties": {"application.name": "Wonder Ink"}}, + {"index": 702, "sink": 41, "sink_name": ANALOG_SINK, + "properties": {"application.name": "Chromium"}}, + ] + state["cards"][0]["ports"]["hdmi-output-0"]["availability"] = "available" + + lab.edit(lesson_and_tv) + check("the television is picked up", lab.await_sink(HDMI_SINK), + lab.daemon_log()) + time.sleep(2) + + streams = lab.read()["streams"] + check("Wonder Ink follows without being restarted", + streams[0]["sink_name"] == HDMI_SINK, + f"left on {streams[0]['sink_name']}") + check("and so does Chrome", + streams[1]["sink_name"] == HDMI_SINK, + f"left on {streams[1]['sink_name']}") + check("a stream that starts afterwards lands on the television", + lab.read()["default_sink"] == HDMI_SINK) +finally: + lab.clean() + +# ---------------------------------------------------------------- 10 +print("10. a machine with no digital output never waits for one") +laptop = { + "server_up": True, + "default_sink": "alsa_output.pci-0000_00_1f.3.analog-stereo", + "levels": {}, + "streams": [], + "cards": [{ + "name": "alsa_card.pci-0000_00_1f.3", + "index": 47, + "description": "Built-in Audio", + "active_profile": "output:analog-stereo+input:analog-stereo", + "profiles": ["off"] + ANALOG_PROFILES, + "ports": { + "analog-output-speaker": { + "availability": "available", + "priority": 10000, + "profiles": ANALOG_PROFILES, + }, + }, + }], +} +lab = Lab(laptop) +try: + lab.start() + check("it uses the speakers it has", + lab.await_sink("alsa_output.pci-0000_00_1f.3.analog-stereo")) + time.sleep(15) + check("and settles without hunting for a television that cannot exist", + len(switches(lab)) <= 1, f"profile switches: {switches(lab)}") +finally: + lab.clean() + +print() +print(f"{passed} passed, {failed} failed") +raise SystemExit(1 if failed else 0) +PY diff --git a/tests/test-classroom-audio.sh b/tests/test-classroom-audio.sh index bd735fe..bd204ed 100755 --- a/tests/test-classroom-audio.sh +++ b/tests/test-classroom-audio.sh @@ -4,7 +4,9 @@ set -uo pipefail ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" PYTHONPATH="$ROOT/lib" python3 - <<'PY' -from classroom_audio import ANALOG_ONLY, AUTO, HDMI, candidates, choose, profile_for +from classroom_audio import ( + ANALOG_ONLY, AUTO, HDMI, candidates, choose, profile_for, settled, +) passed = failed = 0 @@ -21,15 +23,45 @@ def check(label, condition, detail=""): failed += 1 -def card(name, ports): +# The shapes here are what `pactl -f json list cards` really emits, taken +# from PipeWire 1.4.2 and WirePlumber 0.5.8 running in the lab. Two things +# the first set of fixtures here got wrong, and both of them mattered: +# +# * a port carries no "direction" key at all, so nothing can be filtered +# on it and the port names are doing all of the work; and +# * an unknown availability is the phrase "availability unknown", not an +# empty string. +# +# Fixtures that describe a machine nobody has cannot catch a bug on a +# machine somebody does have, which is most of why 0.2.2 shipped. +UNKNOWN_AVAILABILITY = "availability unknown" + +# Every profile a real Intel HDA card lists against these ports, trimmed +# to the ones that matter here: each output appears both on its own and +# paired with the analog input. +ANALOG_PROFILES = [ + "output:analog-stereo", + "output:analog-stereo+input:analog-stereo", + "output:analog-surround-40", + "output:analog-surround-40+input:analog-stereo", +] +HDMI_PROFILES = [ + "output:hdmi-stereo", + "output:hdmi-stereo+input:analog-stereo", + "output:hdmi-surround", + "output:hdmi-surround+input:analog-stereo", +] + + +def card(name, ports, active_profile="output:analog-stereo+input:analog-stereo"): return { "name": name, "index": 0, + "active_profile": active_profile, "ports": { port: { "availability": availability, "priority": priority, - "direction": "Output", "profiles": profiles, } for port, availability, priority, profiles in ports @@ -41,10 +73,8 @@ def card(name, ports): # working PCM audio, and an onboard analog jack with nothing in it that # reports itself unavailable. WirePlumber chose analog. THE_ROOM = [card("alsa_card.pci-0000_00_1f.3", [ - ("analog-output-lineout", "not available", 9900, - ["output:analog-stereo", "output:analog-stereo+input:analog-stereo"]), - ("hdmi-output-0", "available", 5900, - ["output:hdmi-stereo", "output:hdmi-surround"]), + ("analog-output-lineout", "not available", 9900, ANALOG_PROFILES), + ("hdmi-output-0", "available", 5900, HDMI_PROFILES), ])] print("1. the classroom that went to analog") @@ -52,14 +82,17 @@ chosen = choose(THE_ROOM, AUTO) check("auto picks the television, not the empty jack", chosen and chosen["port"] == "hdmi-output-0", f"chose {chosen and chosen['port']}") -check("and a stereo output profile for it", - profile_for(chosen) == "output:hdmi-stereo", +check("and the stereo television profile that keeps the input", + profile_for(chosen) == "output:hdmi-stereo+input:analog-stereo", f"chose {profile_for(chosen)}") +check("which is the profile an administrator reaches for by hand", + profile_for(chosen) + == "output:hdmi-stereo+input:analog-stereo") print("2. an unavailable digital port is not a candidate") TV_OFF = [card("alsa_card.pci", [ - ("analog-output-lineout", "available", 9900, ["output:analog-stereo"]), - ("hdmi-output-0", "not available", 5900, ["output:hdmi-stereo"]), + ("analog-output-lineout", "available", 9900, ANALOG_PROFILES), + ("hdmi-output-0", "not available", 5900, HDMI_PROFILES), ])] chosen = choose(TV_OFF, AUTO) check("auto falls back to analog with the television off", @@ -68,18 +101,22 @@ check("auto falls back to analog with the television off", print("3. availability is not always reported") UNKNOWN = [card("alsa_card.pci", [ - ("analog-output-lineout", "", 9900, ["output:analog-stereo"]), - ("hdmi-output-0", "", 5900, ["output:hdmi-stereo"]), + ("analog-output-lineout", UNKNOWN_AVAILABILITY, 9900, ANALOG_PROFILES), + ("hdmi-output-0", UNKNOWN_AVAILABILITY, 5900, HDMI_PROFILES), ])] chosen = choose(UNKNOWN, AUTO) check("a silent card still prefers the digital output", chosen and chosen["port"] == "hdmi-output-0", f"chose {chosen and chosen['port']}") +check("the real phrase for unknown is read as unknown, not as absent", + [item for item in candidates(UNKNOWN) + if item["availability"] == "unknown"], + "'availability unknown' was not understood") print("4. an available analog jack does not outrank a live television") BOTH = [card("alsa_card.pci", [ - ("analog-output-lineout", "available", 9900, ["output:analog-stereo"]), - ("hdmi-output-0", "available", 5900, ["output:hdmi-stereo"]), + ("analog-output-lineout", "available", 9900, ANALOG_PROFILES), + ("hdmi-output-0", "available", 5900, HDMI_PROFILES), ])] chosen = choose(BOTH, AUTO) check("auto still picks HDMI when both are connected", @@ -93,13 +130,15 @@ check("hdmi forces the television even when it is off", choose(TV_OFF, HDMI)["port"] == "hdmi-output-0") check("hdmi still falls back rather than leaving the room silent", choose([card("alsa_card.pci", [ - ("analog-output-lineout", "available", 9900, ["output:analog-stereo"]), + ("analog-output-lineout", "available", 9900, ANALOG_PROFILES), ])], HDMI)["port"] == "analog-output-lineout") print("6. two displays") TWO = [card("alsa_card.pci", [ - ("hdmi-output-0", "not available", 5900, ["output:hdmi-stereo"]), - ("hdmi-output-1", "available", 5800, ["output:hdmi-stereo-extra1"]), + ("hdmi-output-0", "not available", 5900, HDMI_PROFILES), + ("hdmi-output-1", "available", 5800, + ["output:hdmi-stereo-extra1", + "output:hdmi-stereo-extra1+input:analog-stereo"]), ])] chosen = choose(TWO, AUTO) check("the one that is switched on wins, whatever its priority", @@ -111,8 +150,9 @@ check("a machine with no sound card decides nothing rather than crashing", choose([], AUTO) is None) check("and a card with only inputs is not an output", choose([{"name": "c", "index": 0, "ports": { - "analog-input-mic": {"direction": "Input", "availability": "available", - "priority": 100, "profiles": ["input:analog-stereo"]}}}], + "analog-input-mic": {"availability": UNKNOWN_AVAILABILITY, + "priority": 100, + "profiles": ["input:analog-stereo"]}}}], AUTO) is None) print("8. ports that are not outputs of interest are ignored") @@ -121,6 +161,41 @@ check("a bluetooth headset port is not mistaken for a display", ("headset-output", "available", 100, ["headset-head-unit"])])]) if item["kind"] == HDMI]) +print("9. the profile chosen is always a real one on the port") +for fixture in (THE_ROOM, TV_OFF, UNKNOWN, BOTH, TWO): + pick = choose(fixture, AUTO) + check(f"{pick['port']}: profile is one the port actually offers", + profile_for(pick) in pick["profiles"], + f"{profile_for(pick)} not in {pick['profiles']}") + +print("10. stereo is preferred over surround for a television") +check("a card offering only surround still yields an output profile", + profile_for({"profiles": ["output:hdmi-surround71", + "output:hdmi-surround71+input:analog-stereo"]}) + == "output:hdmi-surround71+input:analog-stereo") +check("a port with no profiles at all decides nothing", + profile_for({"profiles": []}) is None) + +print("11. knowing whether there is anything left to wait for") +# This is what stops the room polling when it is already right, and what +# keeps it looking when a television might still be switched on. +check("a room already on its television is settled", + settled(THE_ROOM, AUTO, choose(THE_ROOM, AUTO))) +check("a room on analog with an HDMI port that is off is NOT settled", + not settled(TV_OFF, AUTO, choose(TV_OFF, AUTO)), + "a television switched on later would never be looked for") +check("a machine with no digital output at all is settled on analog", + settled([card("alsa_card.pci", [ + ("analog-output-lineout", "available", 9900, ANALOG_PROFILES), + ])], AUTO, choose([card("alsa_card.pci", [ + ("analog-output-lineout", "available", 9900, ANALOG_PROFILES), + ])], AUTO)), + "a laptop with only a jack would poll for a television forever") +check("an analog preference is settled once it has the jack", + settled(BOTH, ANALOG_ONLY, choose(BOTH, ANALOG_ONLY))) +check("a machine with no sound card at all is settled", + settled([], AUTO, None)) + print() print(f"{passed} passed, {failed} failed") raise SystemExit(1 if failed else 0) diff --git a/tools/build-release.sh b/tools/build-release.sh index 8295886..43f730f 100755 --- a/tools/build-release.sh +++ b/tools/build-release.sh @@ -49,7 +49,7 @@ for policy in "$ROOT"/config/chrome/policies/*/*.json; do python3 -c 'import json, sys; json.load(open(sys.argv[1]))' "$policy" done -find "$ROOT/scripts" "$ROOT/lib" \ +find "$ROOT/scripts" "$ROOT/lib" "$ROOT/tests" \ -name '__pycache__' -type d -prune -exec rm -rf {} + 2>/dev/null || true for test in "$ROOT"/tests/test-*.sh; do diff --git a/tools/validate-trixie-release.sh b/tools/validate-trixie-release.sh index 89a42f7..82b42a8 100755 --- a/tools/validate-trixie-release.sh +++ b/tools/validate-trixie-release.sh @@ -106,6 +106,23 @@ systemctl is-enabled NetworkManager.service >/dev/null systemctl is-enabled cups.service >/dev/null ! systemctl is-enabled NetworkManager-wait-online.service >/dev/null 2>&1 +# The audio policy reaches a session, and is ordered after the server it +# actually talks to. Ordering it only after pipewire and wireplumber is +# what let it race PipeWire's PulseAudio server at boot, fail its one +# startup attempt and then sit idle — the rooms were silent on 0.2.2 for +# exactly this reason, so the ordering is asserted rather than assumed. +audio_unit=/etc/systemd/user/ekklesia-classroom-audio.service +[[ -f "$audio_unit" ]] +grep -q 'pipewire-pulse' "$audio_unit" +[[ -L /etc/systemd/user/plasma-workspace.target.wants/ekklesia-classroom-audio.service ]] +command -v classroom-audio >/dev/null +command -v pactl >/dev/null + +# The policy module and the daemon agree on what they import, on a machine +# rather than in a checkout. +PYTHONPATH=/usr/local/lib/ekklesia-classroom python3 -c \ + 'import classroom_audio; classroom_audio.settled([], "auto", None)' + grep -q '^managed=false$' /etc/NetworkManager/NetworkManager.conf # A normal Docker container has Ethernet and no Wi-Fi adapter. Reaching this