diff --git a/docs/audio.md b/docs/audio.md index 76eb6698..da3490aa 100644 --- a/docs/audio.md +++ b/docs/audio.md @@ -398,6 +398,58 @@ one at a time, as there is one player. queue plays out; clearing it would need `SLAndroidSimpleBufferQueueItf::Clear`, which flushes the `AudioTrack`. +## Ducking while Alexa holds focus + +- Alexa takes audio focus as `GAIN_TRANSIENT_MAY_DUCK` while she listens and + answers. Android 5.1 does not duck anything itself: a player has to hear the + focus change and lower its own level. +- The player holds no focus, so it hears nothing. Holding focus would take a + resident Java process, about 25 MB on a Dot with about 110 MB free, and + `app_process` crashes on teardown (above). +- The Sendspin volume is `STREAM_MUSIC`, which her speech plays on too, so the + duck cannot be a stream volume. It is a gain on the stream's own samples, + applied after placement, so timing and sync are untouched. +- `system_server` logs every focus change, and `alexa.FocusWatcher` follows + `logcat -s MediaFocusControl`: + +``` +I/MediaFocusControl( 601): AudioFocus requestAudioFocus() from com.amazon.media.AmazonAudioManager@37705de9amazon.speech.util.AudioFocusHelper$2@22ab2a6e req=3flags=0x0 +I/MediaFocusControl( 601): AudioFocus abandonAudioFocus() from com.amazon.media.AmazonAudioManager@37705de9amazon.speech.util.AudioFocusHelper$2@22ab2a6e +I/MediaFocusControl( 601): AudioFocus removeFocusStackEntry(): removing entry for com.amazon.media.AmazonAudioManager@37705de9amazon.speech.util.AudioFocusHelper$2@22ab2a6e +``` + +- Her requests overlap. One "what time is it" took focus from 3 clients in + turn, each requesting before the last abandoned, over 10.3 seconds. So the + watcher keeps a set of holders, not a flag, and the stream stays ducked until + the set is empty. +- `removeFocusStackEntry` logs whenever an entry leaves from below the top of + the stack: after an abandon, and also after a re-request, which moves the + client to the top. So a removal releases its client unless it comes straight + after that client's own request. +- A client that dies holding focus is logged by its binder + (`android.os.BinderProxy@...`), which names no holder. Only the 15-minute + expiry releases it. + +| `req=` | request | stream level | +|---|---|---| +| 3 | `GAIN_TRANSIENT_MAY_DUCK` | 20% | +| 2, 4 | `GAIN_TRANSIENT`, `GAIN_TRANSIENT_EXCLUSIVE` | 10% | +| 1 | `GAIN` | 100%: a permanent taker plays beside the stream, as before | + +- The deepest holder wins. The levels match sendspinlite's on an Echo Show. +- Nothing handles a permanent taker. If Alexa plays music herself, both streams + play at full level, as they did before. A gain cannot fix that: the stream + would need a pause the Sendspin layer can resume. +- Her speech does duck over her own music, because the deepest holder wins. No + test covers a `req=1` and a `req=3` holder together, which is that pair. +- The gain moves linearly, a full swing taking 50 ms down and 300 ms up: 100% + to 20% in 40 ms, and back in 240 ms. No click on either edge. +- At full gain the samples are not touched, so an unducked stream is + bit-identical to before. +- A stream opened while a holder is held starts at the ducked level. +- It fails toward full level: each holder expires 15 minutes after its + request, and when logcat exits the set is cleared before the retry. + ## Testing audio here - **Never test with a sustained pure tone.** A 20-second 440 Hz sine pulses diff --git a/docs/pitfalls.md b/docs/pitfalls.md index d799efec..d76e6286 100644 --- a/docs/pitfalls.md +++ b/docs/pitfalls.md @@ -72,6 +72,15 @@ covering whatever you are about to touch. "connection refused". `internal/alexa` reads `net.dns1` and `net.dns2` and builds its own resolver. +## logcat followers + +- `internal/alexa` follows logcat in a child process for each watcher. A + restart kills the daemon before its deferred `Kill` runs, so each child used + to be left running under init: two more `logcat` processes per restart, for + the rest of the boot. +- Each child is started with `Pdeathsig: SIGKILL`, so the kernel kills it when + the daemon goes. A daemon killed with `kill` left no `logcat` behind. + ## The firewall - FireOS runs iptables with `INPUT policy DROP` and a port allowlist without diff --git a/docs/usage.md b/docs/usage.md index d391f325..8d0104cf 100644 --- a/docs/usage.md +++ b/docs/usage.md @@ -245,6 +245,8 @@ Sendspin identity. - Setting it from Home Assistant sets the level of the route in `output_device` exactly. It is silent: no key press, so no tick. - Music Assistant can set it over Sendspin too. +- Sendspin ducks to 20% while Alexa listens and answers, and comes back when + she is done. docs/audio.md has how. - Android keeps a level per route: `volume` for the speaker, `jack_volume` for the socket, `bluetooth_volume` for a paired speaker. All 3 are reported whatever is connected. diff --git a/internal/alexa/focus.go b/internal/alexa/focus.go new file mode 100644 index 00000000..323db778 --- /dev/null +++ b/internal/alexa/focus.go @@ -0,0 +1,179 @@ +package alexa + +import ( + "io" + "log" + "strings" + "sync" + "time" +) + +const ( + duckPercent = 20 + deepDuckPercent = 10 + fullPercent = 100 + holdFor = 15 * time.Minute + + requestMark = "requestAudioFocus() from " + reqMark = " req=" + abandonMark = "abandonAudioFocus() from " + removeMark = "removeFocusStackEntry(): removing entry for " +) + +var focusArgv = []string{"/system/bin/logcat", "-T", "1", "-v", "brief", "-s", "MediaFocusControl"} + +type focusHolder struct { + req int + until time.Time +} + +type FocusWatcher struct { + OnLevel func(percent int) + + notify sync.Mutex + mu sync.Mutex + requested string + holders map[string]focusHolder + level int + now func() time.Time +} + +func (w *FocusWatcher) clock() time.Time { + if w.now != nil { + return w.now() + } + return time.Now() +} + +func (w *FocusWatcher) Run() { + go w.sweep() + keepFollowing("focus watcher", focusArgv, w.line, w.reset) +} + +func (w *FocusWatcher) sweep() { + for range time.Tick(sweepEvery) { + w.expire() + } +} + +func (w *FocusWatcher) read(r io.Reader) error { + return readLines(r, w.line) +} + +func (w *FocusWatcher) line(line string) { + if i := strings.Index(line, requestMark); i >= 0 { + rest := line[i+len(requestMark):] + j := strings.LastIndex(rest, reqMark) + if j < 0 { + return + } + req, ok := leadingInt(rest[j+len(reqMark):]) + if !ok { + return + } + client := strings.TrimSpace(rest[:j]) + w.request(client, req) + w.requested = client + return + } + if i := strings.Index(line, abandonMark); i >= 0 { + w.requested = "" + w.release(strings.TrimSpace(line[i+len(abandonMark):])) + return + } + if i := strings.Index(line, removeMark); i >= 0 { + client := strings.TrimSpace(line[i+len(removeMark):]) + requested := w.requested + w.requested = "" + if client == requested { + return + } + w.release(client) + } +} + +func leadingInt(s string) (int, bool) { + n, digits := 0, 0 + for digits < len(s) && digits < 9 && s[digits] >= '0' && s[digits] <= '9' { + n = n*10 + int(s[digits]-'0') + digits++ + } + return n, digits > 0 +} + +func (w *FocusWatcher) request(client string, req int) { + if client == "" { + return + } + w.change(func() { + if w.holders == nil { + w.holders = map[string]focusHolder{} + } + w.holders[client] = focusHolder{req: req, until: w.clock().Add(holdFor)} + }) +} + +func (w *FocusWatcher) release(client string) { + if client == "" { + return + } + w.change(func() { + delete(w.holders, client) + }) +} + +func (w *FocusWatcher) expire() { + dropped := 0 + w.change(func() { + now := w.clock() + for client, h := range w.holders { + if now.After(h.until) { + delete(w.holders, client) + dropped++ + } + } + }) + if dropped > 0 { + log.Printf("focus watcher: %d clients never abandoned audio focus, so their hold"+ + " was dropped after %v", dropped, holdFor) + } +} + +func (w *FocusWatcher) reset() { + w.requested = "" + w.change(func() { + clear(w.holders) + }) +} + +func (w *FocusWatcher) change(mutate func()) { + w.notify.Lock() + defer w.notify.Unlock() + + w.mu.Lock() + mutate() + level := fullPercent + for _, h := range w.holders { + level = min(level, percentFor(h.req)) + } + was := w.level + if was == 0 { + was = fullPercent + } + w.level = level + w.mu.Unlock() + + if level != was && w.OnLevel != nil { + w.OnLevel(level) + } +} + +func percentFor(req int) int { + switch req { + case 3: + return duckPercent + case 2, 4: + return deepDuckPercent + } + return fullPercent +} diff --git a/internal/alexa/focus_test.go b/internal/alexa/focus_test.go new file mode 100644 index 00000000..af4ad01c --- /dev/null +++ b/internal/alexa/focus_test.go @@ -0,0 +1,234 @@ +package alexa + +import ( + "slices" + "strings" + "sync" + "testing" + "time" +) + +type levels struct { + mu sync.Mutex + seen []int +} + +func focusWatcher() (*FocusWatcher, *levels) { + l := &levels{} + w := &FocusWatcher{ + OnLevel: func(percent int) { + l.mu.Lock() + defer l.mu.Unlock() + l.seen = append(l.seen, percent) + }, + } + return w, l +} + +func (l *levels) heard() []int { + l.mu.Lock() + defer l.mu.Unlock() + return append([]int(nil), l.seen...) +} + +func (l *levels) last() int { + seen := l.heard() + if len(seen) == 0 { + return fullPercent + } + return seen[len(seen)-1] +} + +const ( + requestFirst = "I/MediaFocusControl( 601): AudioFocus requestAudioFocus() from com.amazon.media.AmazonAudioManager@37705de9amazon.speech.util.AudioFocusHelper$2@22ab2a6e req=3flags=0x0" + requestSecond = "I/MediaFocusControl( 601): AudioFocus requestAudioFocus() from com.amazon.media.AmazonAudioManager@2b124a00amazon.speech.util.AudioFocusHelper$2@2555b239 req=3flags=0x0" + abandonFirst = "I/MediaFocusControl( 601): AudioFocus abandonAudioFocus() from com.amazon.media.AmazonAudioManager@37705de9amazon.speech.util.AudioFocusHelper$2@22ab2a6e" + removeFirst = "I/MediaFocusControl( 601): AudioFocus removeFocusStackEntry(): removing entry for com.amazon.media.AmazonAudioManager@37705de9amazon.speech.util.AudioFocusHelper$2@22ab2a6e" + abandonSecond = "I/MediaFocusControl( 601): AudioFocus abandonAudioFocus() from com.amazon.media.AmazonAudioManager@2b124a00amazon.speech.util.AudioFocusHelper$2@2555b239" + + otherClient = "android.media.AudioManager@1a2b3c4dcom.example.Player$1@5e6f7a8b" +) + +func requestFrom(client string, req string) string { + return "I/MediaFocusControl( 601): AudioFocus requestAudioFocus() from " + client + + " req=" + req + "flags=0x0" +} + +func abandonFrom(client string) string { + return "I/MediaFocusControl( 601): AudioFocus abandonAudioFocus() from " + client +} + +func lines(ls ...string) *strings.Reader { + return strings.NewReader(strings.Join(ls, "\n") + "\n") +} + +func TestOverlappingRequestsHoldTheDuckUntilTheLastAbandon(t *testing.T) { + w, l := focusWatcher() + + w.read(lines(requestFirst, requestSecond, abandonFirst)) + if got := l.last(); got != duckPercent { + t.Fatalf("level %d after one of two holders abandoned, want %d: her requests overlap "+ + "and the second is still speaking", got, duckPercent) + } + + w.read(lines(removeFirst, abandonSecond)) + if got := l.heard(); !slices.Equal(got, []int{duckPercent, fullPercent}) { + t.Errorf("heard levels %v, want [%d %d]", got, duckPercent, fullPercent) + } +} + +func TestARemovedStackEntryReleasesItsHold(t *testing.T) { + w, l := focusWatcher() + + w.read(lines(requestFirst, requestSecond, removeFirst, abandonSecond)) + if got := l.heard(); !slices.Equal(got, []int{duckPercent, fullPercent}) { + t.Errorf("heard levels %v, want [%d %d]", got, duckPercent, fullPercent) + } +} + +func TestARemovalStraightAfterTheSameClientsRequestKeepsItsHold(t *testing.T) { + w, l := focusWatcher() + + w.read(lines(requestFirst, requestSecond, requestFirst, removeFirst, abandonSecond)) + if got := l.last(); got != duckPercent { + t.Errorf("level %d after a re-request moved the first client up the stack, want %d", + got, duckPercent) + } + w.read(lines(abandonFirst)) + if got := l.last(); got != fullPercent { + t.Errorf("level %d after the last abandon, want %d", got, fullPercent) + } +} + +func TestAPermanentGainDoesNotDuck(t *testing.T) { + w, l := focusWatcher() + + w.read(lines(requestFrom(otherClient, "1"), abandonFrom(otherClient))) + if got := l.heard(); len(got) != 0 { + t.Errorf("heard levels %v for a permanent taker, want none: it plays alongside", got) + } +} + +func TestATransientGainDucksDeeperThanAMayDuck(t *testing.T) { + w, l := focusWatcher() + + w.read(lines(requestFirst, requestFrom(otherClient, "2"))) + if got := l.last(); got != deepDuckPercent { + t.Fatalf("level %d with a req=2 and a req=3 holder, want %d: the deepest wins", + got, deepDuckPercent) + } + + w.read(lines(abandonFrom(otherClient))) + if got := l.heard(); !slices.Equal(got, []int{duckPercent, deepDuckPercent, duckPercent}) { + t.Errorf("heard levels %v, want [%d %d %d]", got, duckPercent, deepDuckPercent, duckPercent) + } +} + +func TestAnExclusiveGainDucksDeep(t *testing.T) { + w, l := focusWatcher() + + w.read(lines(requestFrom(otherClient, "4"))) + if got := l.last(); got != deepDuckPercent { + t.Errorf("level %d for req=4, want %d", got, deepDuckPercent) + } +} + +func TestTheLevelIsOnlySentWhenItChanges(t *testing.T) { + w, l := focusWatcher() + + w.read(lines(requestFirst, requestSecond, requestFirst, abandonFirst, abandonFirst, + abandonSecond, abandonSecond, removeFirst)) + if got := l.heard(); !slices.Equal(got, []int{duckPercent, fullPercent}) { + t.Errorf("heard levels %v, want [%d %d]: a level already set is not news", + got, duckPercent, fullPercent) + } +} + +func TestAReRequestReplacesTheClientsOldRequest(t *testing.T) { + w, l := focusWatcher() + + w.read(lines(requestFrom(otherClient, "3"), requestFrom(otherClient, "2"))) + if got := l.last(); got != deepDuckPercent { + t.Fatalf("level %d after req=3 then req=2 from one client, want %d", got, deepDuckPercent) + } + + w.read(lines(requestFrom(otherClient, "1"))) + if got := l.heard(); !slices.Equal(got, []int{duckPercent, deepDuckPercent, fullPercent}) { + t.Errorf("heard levels %v, want [%d %d %d]: a client holds one request, its latest", + got, duckPercent, deepDuckPercent, fullPercent) + } +} + +func TestAHoldNobodyReleasesExpires(t *testing.T) { + w, l := focusWatcher() + now := time.Now() + w.now = func() time.Time { return now } + + w.read(lines(requestFirst)) + now = now.Add(holdFor - time.Minute) + w.read(lines(requestSecond)) + + now = now.Add(2 * time.Minute) + w.expire() + if got := l.heard(); !slices.Equal(got, []int{duckPercent}) { + t.Fatalf("heard levels %v after the first hold expired, want [%d]: the second "+ + "was requested later and has not", got, duckPercent) + } + + now = now.Add(holdFor) + w.expire() + if got := l.heard(); !slices.Equal(got, []int{duckPercent, fullPercent}) { + t.Fatalf("heard levels %v, want [%d %d]: a missed abandon would otherwise leave "+ + "the music ducked for good", got, duckPercent, fullPercent) + } + + w.expire() + if got := l.heard(); len(got) != 2 { + t.Errorf("heard levels %v; a sweep with nothing to expire sent a level", got) + } +} + +func TestALogcatThatEndsLeavesTheMusicAtFullLevel(t *testing.T) { + w, l := focusWatcher() + + w.read(lines(requestFirst, requestFrom(otherClient, "2"))) + w.reset() + w.reset() + if got := l.heard(); !slices.Equal(got, []int{duckPercent, deepDuckPercent, fullPercent}) { + t.Fatalf("heard levels %v, want [%d %d %d]: the abandons logcat missed while it "+ + "was down will never arrive", got, duckPercent, deepDuckPercent, fullPercent) + } + + w.read(lines(abandonFirst)) + if got := l.heard(); len(got) != 3 { + t.Errorf("heard levels %v; a holder survived the reset", got) + } +} + +func TestAResetAtFullLevelSendsNothing(t *testing.T) { + w, l := focusWatcher() + + w.reset() + if got := l.heard(); len(got) != 0 { + t.Errorf("heard levels %v from a reset with nothing held, want none", got) + } +} + +func TestLinesThatAreNotFocusChangesAreIgnored(t *testing.T) { + w, l := focusWatcher() + + w.read(lines( + "", + "--------- beginning of main", + "I/MediaFocusControl( 601): AudioFocus requestAudioFocus() from "+otherClient, + "I/MediaFocusControl( 601): AudioFocus requestAudioFocus() from "+otherClient+" req=flags=0x0", + "I/MediaFocusControl( 601): AudioFocus requestAudioFocus() from req=3flags=0x0", + "I/MediaFocusControl( 601): AudioFocus abandonAudioFocus() from ", + "I/MediaFocusControl( 601): AudioFocus removeFocusStackEntry(): removing entry for ", + "D/MediaFocusControl( 601): dispatchFocusChange(-3) to "+otherClient, + "I/tts-Server( 940): Playback started: uid(32037)_id(0)_namespace(SpeechSynthesizer)", + )) + if got := l.heard(); len(got) != 0 { + t.Errorf("heard levels %v from lines that request nothing, want none", got) + } +} diff --git a/internal/alexa/logcat.go b/internal/alexa/logcat.go new file mode 100644 index 00000000..986c61ca --- /dev/null +++ b/internal/alexa/logcat.go @@ -0,0 +1,53 @@ +package alexa + +import ( + "bufio" + "io" + "log" + "os/exec" + "syscall" + "time" +) + +func keepFollowing(name string, argv []string, line func(string), ended func()) { + said := false + for { + start := time.Now() + err := follow(argv, line) + if ended != nil { + ended() + } + var say bool + say, said = shouldSay(said, time.Since(start), err) + if say { + log.Printf("%s: %v; retrying every %v, and saying so once", name, err, watchRetry) + } + time.Sleep(watchRetry) + } +} + +func follow(argv []string, line func(string)) error { + cmd := exec.Command(argv[0], argv[1:]...) + cmd.SysProcAttr = &syscall.SysProcAttr{Pdeathsig: syscall.SIGKILL} + stdout, err := cmd.StdoutPipe() + if err != nil { + return err + } + if err := cmd.Start(); err != nil { + return err + } + defer func() { + _ = cmd.Process.Kill() + _ = cmd.Wait() + }() + + return readLines(stdout, line) +} + +func readLines(r io.Reader, line func(string)) error { + sc := bufio.NewScanner(r) + for sc.Scan() { + line(sc.Text()) + } + return sc.Err() +} diff --git a/internal/alexa/playback.go b/internal/alexa/playback.go index 2c415a21..993b747b 100644 --- a/internal/alexa/playback.go +++ b/internal/alexa/playback.go @@ -1,10 +1,7 @@ package alexa import ( - "bufio" "io" - "log" - "os/exec" "strings" "sync" "time" @@ -64,18 +61,7 @@ func (w *PlaybackWatcher) Cancel() { func (w *PlaybackWatcher) Run() { go w.sweep() - said := false - for { - start := time.Now() - err := w.tail() - var say bool - say, said = shouldSay(said, time.Since(start), err) - if say { - log.Printf("playback watcher: %v; retrying every %v, and saying so once", - err, watchRetry) - } - time.Sleep(watchRetry) - } + keepFollowing("playback watcher", watchArgv, w.line, nil) } func shouldSay(said bool, ranFor time.Duration, err error) (say, nowSaid bool) { @@ -109,29 +95,8 @@ func (w *PlaybackWatcher) expire() { } } -func (w *PlaybackWatcher) tail() error { - cmd := exec.Command(watchArgv[0], watchArgv[1:]...) - stdout, err := cmd.StdoutPipe() - if err != nil { - return err - } - if err := cmd.Start(); err != nil { - return err - } - defer func() { - _ = cmd.Process.Kill() - _ = cmd.Wait() - }() - - return w.read(stdout) -} - func (w *PlaybackWatcher) read(r io.Reader) error { - sc := bufio.NewScanner(r) - for sc.Scan() { - w.line(sc.Text()) - } - return sc.Err() + return readLines(r, w.line) } func (w *PlaybackWatcher) line(line string) { diff --git a/internal/alexa/speak.go b/internal/alexa/speak.go index c6fd6d28..8012acd7 100644 --- a/internal/alexa/speak.go +++ b/internal/alexa/speak.go @@ -1,6 +1,7 @@ // Package alexa hands a clip to Alexa's own synthesizer, which is the only way // to play one this daemon does not decode itself. docs/audio.md has the -// measurements and says what the route costs. +// measurements and says what the route costs. It also follows audio focus in +// logcat, so the stream can duck while Alexa holds it. package alexa import ( diff --git a/internal/audio/chime.go b/internal/audio/chime.go index 55bdfa87..7a0602be 100644 --- a/internal/audio/chime.go +++ b/internal/audio/chime.go @@ -1,5 +1,5 @@ -// Package audio renders the chime, sounds it through OpenSL ES, and places a -// server's stream on the frame the player says it belongs on. +// Package audio renders the chime, sounds it through OpenSL ES, places a +// server's stream on the frame the player says it belongs on, and ducks it. package audio import "math" diff --git a/internal/audio/chime_android.go b/internal/audio/chime_android.go index dfe3563e..3867beb6 100644 --- a/internal/audio/chime_android.go +++ b/internal/audio/chime_android.go @@ -27,6 +27,7 @@ type Chime struct { stop chan struct{} done chan struct{} closed bool + cut float64 } func NewChime() (*Chime, error) { @@ -84,7 +85,7 @@ func (c *Chime) OpenStream(rate int, say func(string, ...any)) (*Stream, error) held.Close() c.stream.CompareAndSwap(held, nil) } - s := &Stream{rate: rate, say: say} + s := &Stream{rate: rate, say: say, cut: c.cut, cutTo: c.cut} s.closer = func() { c.stream.CompareAndSwap(s, nil) } if !c.stream.CompareAndSwap(nil, s) { return nil, errors.New("audio: a stream is already open, and this player holds one") @@ -97,6 +98,16 @@ func (c *Chime) OpenStream(rate int, say func(string, ...any)) (*Stream, error) return s, nil } +func (c *Chime) Duck(percent int) { + cut := duckCut(percent) + c.mu.Lock() + defer c.mu.Unlock() + c.cut = cut + if s := c.stream.Load(); s != nil { + s.duck(cut) + } +} + func (c *Chime) retune() bool { c.mu.Lock() defer c.mu.Unlock() diff --git a/internal/audio/chime_other.go b/internal/audio/chime_other.go index 76867efc..0296551b 100644 --- a/internal/audio/chime_other.go +++ b/internal/audio/chime_other.go @@ -18,4 +18,6 @@ func (c *Chime) OpenStream(int, func(string, ...any)) (*Stream, error) { return nil, errors.New("audio: built without OpenSL ES") } +func (c *Chime) Duck(int) {} + func (c *Chime) Close() {} diff --git a/internal/audio/duck_test.go b/internal/audio/duck_test.go new file mode 100644 index 00000000..f4608c0b --- /dev/null +++ b/internal/audio/duck_test.go @@ -0,0 +1,236 @@ +package audio + +import ( + "math" + "slices" + "testing" + "time" +) + +const duckProbe = 30000 + +func ducked(cut float64) *Stream { + s := quiet() + s.cut, s.cutTo = cut, cut + return s +} + +func gains(s *Stream, frames int) []int16 { + var out []int16 + block := make([]int16, BlockSamples) + for len(out) < frames { + for i := range block { + block[i] = duckProbe + } + s.scale(block) + for i := 0; i < len(block); i += ChimeChannels { + if block[i] != block[i+1] { + panic("the channels of one frame were scaled apart") + } + } + out = append(out, left(block)...) + } + return out[:frames] +} + +func firstAt(out []int16, want int16) int { + return slices.Index(out, want) +} + +func TestAFullGainStreamIsBitIdenticalToAnUnduckedOne(t *testing.T) { + now := time.Now() + plain, full := quiet(), quiet() + full.duck(duckCut(100)) + for _, s := range []*Stream{plain, full} { + anchorAt(s, now) + if err := s.Write(now, stereoRamp(0, 4*BlockFrames)); err != nil { + t.Fatalf("Write: %v", err) + } + } + a, b := make([]int16, BlockSamples), make([]int16, BlockSamples) + for n := range 4 { + plain.read(a) + full.read(b) + if !slices.Equal(a, b) { + t.Fatalf("block %d differs at full gain; the normal path has to leave every"+ + " sample as the server sent it", n) + } + } + if full.cut != 0 || full.cutTo != 0 { + t.Errorf("a stream at full level holds cut %v toward %v", full.cut, full.cutTo) + } +} + +func TestADuckRampsDownOverFiftyMillisecondsAFullSwing(t *testing.T) { + s := quiet() + s.duck(duckCut(20)) + swing := frameCount(ChimeRate, duckDownFor) + out := gains(s, int(swing)+BlockFrames) + floor := int16(math.Round(duckProbe * 0.2)) + at := firstAt(out, floor) + if at < 0 || at >= int(swing) { + t.Fatalf("the gain reached 20%% at frame %d, want inside the %d frames of %s", + at, swing, duckDownFor) + } + if want := int(swing) * 8 / 10; at < want-2 { + t.Errorf("the gain reached 20%% at frame %d, well before the %d frames a linear"+ + " ramp takes; the duck stepped rather than ramped", at, want) + } + step := int16(duckProbe/swing) + 1 + prev := int16(duckProbe) + for i, got := range out { + if got > prev || prev-got > step { + t.Fatalf("frame %d went from %d to %d; a duck only falls, and by at most %d"+ + " a frame", i, prev, got, step) + } + if got < floor { + t.Fatalf("frame %d is %d, under the 20%% target of %d", i, got, floor) + } + prev = got + } +} + +func TestReturningToFullRampsUpOverThreeHundredMilliseconds(t *testing.T) { + s := ducked(duckCut(20)) + s.duck(duckCut(100)) + swing := frameCount(ChimeRate, duckUpFor) + out := gains(s, int(swing)+BlockFrames) + at := firstAt(out, duckProbe) + if at < 0 || at >= int(swing) { + t.Fatalf("the gain came back to full at frame %d, want inside the %d frames of %s", + at, swing, duckUpFor) + } + if want := int(swing) * 8 / 10; at < want-2 { + t.Errorf("the gain came back at frame %d, well before the %d frames a linear ramp"+ + " takes", at, want) + } + step := int16(duckProbe/swing) + 1 + prev := int16(math.Round(duckProbe * 0.2)) + for i, got := range out { + if got < prev || got-prev > step { + t.Fatalf("frame %d went from %d to %d; a return only rises, and by at most %d"+ + " a frame", i, prev, got, step) + } + if got > duckProbe { + t.Fatalf("frame %d is %d, louder than the stream sent", i, got) + } + prev = got + } + if s.cut != 0 || s.cutTo != 0 { + t.Errorf("a stream back at full holds cut %v toward %v, so it never returns to"+ + " the untouched path", s.cut, s.cutTo) + } +} + +func TestADuckChangedMidRampTurnsWithoutAJump(t *testing.T) { + s := quiet() + s.duck(duckCut(20)) + out := gains(s, 2*BlockFrames) + s.duck(duckCut(100)) + out = append(out, gains(s, 4*BlockFrames)...) + s.duck(duckCut(10)) + out = append(out, gains(s, 6*BlockFrames)...) + step := int16(duckProbe/frameCount(ChimeRate, duckDownFor)) + 1 + for i := 1; i < len(out); i++ { + if d := out[i] - out[i-1]; d > step || d < -step { + t.Fatalf("frame %d stepped by %d; no change of target may click", i, d) + } + } + if got, want := out[len(out)-1], int16(math.Round(duckProbe*0.1)); got != want { + t.Errorf("the last frame is %d, want %d at 10%%", got, want) + } +} + +func TestAStreamOpenedDuckedStartsAtItsLevel(t *testing.T) { + s := ducked(duckCut(20)) + now := time.Now() + anchorAt(s, now) + if err := s.Write(now, level(BlockFrames, duckProbe)); err != nil { + t.Fatalf("Write: %v", err) + } + block := make([]int16, BlockSamples) + s.read(block) + want := attenuate(duckProbe, 1-duckCut(20)) + for i, got := range block { + if got != want { + t.Fatalf("sample %d is %d, want %d; a stream opened while Alexa holds focus"+ + " starts at her level rather than ramping down to it", i, got, want) + } + } + if d := want - int16(math.Round(duckProbe*0.2)); d > 1 || d < -1 { + t.Errorf("20%% of %d came out %d", duckProbe, want) + } +} + +func TestDuckPercentsAreClamped(t *testing.T) { + for _, c := range []struct { + percent int + cut float64 + }{{-50, 1}, {0, 1}, {20, 0.8}, {100, 0}, {101, 0}, {1000, 0}} { + if got := duckCut(c.percent); got != c.cut { + t.Errorf("duckCut(%d) = %v, want %v", c.percent, got, c.cut) + } + } + s := quiet() + s.duck(2) + if s.cutTo != 1 { + t.Errorf("a cut of 2 was held as %v, deeper than silence", s.cutTo) + } + s.duck(-1) + if s.cutTo != 0 { + t.Errorf("a cut of -1 was held as %v, louder than the stream", s.cutTo) + } +} + +func TestAttenuatingRoundsAndStaysInRange(t *testing.T) { + for _, c := range []struct { + in int16 + gain float64 + want int16 + }{ + {math.MinInt16, 1, math.MinInt16}, + {math.MaxInt16, 1, math.MaxInt16}, + {math.MaxInt16, 0.5, 16384}, + {math.MinInt16, 0.5, -16384}, + {-3, 0.5, -2}, + {1000, 0, 0}, + } { + if got := attenuate(c.in, c.gain); got != c.want { + t.Errorf("attenuate(%d, %v) = %d, want %d", c.in, c.gain, got, c.want) + } + } +} + +func TestTheChimeIsMixedAtFullLevelOverADuckedStream(t *testing.T) { + m := newMixer() + s := ducked(duckCut(10)) + c := &clip{pcm: decode(level(BlockFrames, 4000))} + m.add(s) + m.add(c) + block := make([]int16, BlockSamples) + m.next(block) + for i, got := range block { + if got != 4000 { + t.Fatalf("sample %d is %d; the chime was ducked with the stream", i, got) + } + } +} + +func TestADuckLandsWhileTheStreamIsRead(t *testing.T) { + s := quiet() + now := time.Now() + anchorAt(s, now) + done := make(chan struct{}) + go func() { + defer close(done) + block := make([]int16, BlockSamples) + for range 200 { + s.read(block) + } + }() + for i := range 200 { + s.duck(duckCut(i % 101)) + } + <-done + s.Close() +} diff --git a/internal/audio/stream.go b/internal/audio/stream.go index be94806d..5b2554a6 100644 --- a/internal/audio/stream.go +++ b/internal/audio/stream.go @@ -4,6 +4,7 @@ import ( "errors" "fmt" "log" + "math" "slices" "sync" "time" @@ -36,6 +37,9 @@ const ( observeEvery = 10 blindAfter = 100 + + duckDownFor = 50 * time.Millisecond + duckUpFor = 300 * time.Millisecond ) var ( @@ -137,6 +141,9 @@ type Stream struct { lastOut [ChimeChannels]int16 smooth int64 easedAt int64 + + cut float64 + cutTo float64 } func (s *Stream) report(format string, args ...any) { @@ -283,9 +290,44 @@ func (s *Stream) read(block []int16) (int, bool) { s.eased += int64(blended + trimmed) s.index += int64(frames) s.blocks++ + s.scale(block) return len(block), true } +func duckCut(percent int) float64 { + return float64(100-min(max(percent, 0), 100)) / 100 +} + +func (s *Stream) duck(cut float64) { + s.mu.Lock() + defer s.mu.Unlock() + s.cutTo = min(max(cut, 0), 1) +} + +func (s *Stream) scale(block []int16) { + if s.cut == 0 && s.cutTo == 0 { + return + } + down := 1 / float64(max(1, frameCount(s.rate, duckDownFor))) + up := 1 / float64(max(1, frameCount(s.rate, duckUpFor))) + for i := 0; i+ChimeChannels <= len(block); i += ChimeChannels { + switch { + case s.cut < s.cutTo: + s.cut = min(s.cut+down, s.cutTo) + case s.cut > s.cutTo: + s.cut = max(s.cut-up, s.cutTo) + } + gain := 1 - s.cut + for ch := range ChimeChannels { + block[i+ch] = attenuate(block[i+ch], gain) + } + } +} + +func attenuate(v int16, gain float64) int16 { + return int16(min(max(math.Round(float64(v)*gain), math.MinInt16), math.MaxInt16)) +} + func (s *Stream) fill(block []int16) (filled, blended, trimmed int) { frames := len(block) / ChimeChannels snap := frameCount(s.rate, snapAbove) diff --git a/serve.go b/serve.go index f5e12348..2beb16e2 100644 --- a/serve.go +++ b/serve.go @@ -115,6 +115,7 @@ func serve(flags config) error { var player sendspin.Player if chime != nil { player = chimePlayer{chime: chime} + go (&alexa.FocusWatcher{OnLevel: chime.Duck}).Run() } go serveAPI(flags.Name, psk, i, player)