// Command listend mirrors a phone's podcast subscriptions, works out what to skip in them, and // serves both to the phone. // // It exists because detection cannot work on the phone. The intro/outro search needs several // episodes' audio compared at once, which needs more memory than an Android process gets and // more time than WorkManager's ten-minute ceiling allows -- and the attempt burned the battery // while confirming nothing. Here the same work is unremarkable. // // It serves the audio as well as the offsets, which is not a convenience. A show using dynamic // ad insertion returns a different file on every request, so an offset measured on one copy // points at the wrong moment in another. The phone playing the very bytes the detector examined // is what makes the numbers correct. package main import ( "context" "errors" "flag" "fmt" "io" "log" "net/http" "os" "os/signal" "path/filepath" "sync" "syscall" "time" "github.com/terst/listen/server/internal/api" "github.com/terst/listen/server/internal/decode" "github.com/terst/listen/server/internal/feed" "github.com/terst/listen/server/internal/mirror" "github.com/terst/listen/server/internal/safefetch" "github.com/terst/listen/server/internal/signature" "github.com/terst/listen/server/internal/skips" "github.com/terst/listen/server/internal/store" "github.com/terst/listen/server/internal/transcribe" "github.com/terst/listen/server/internal/transcript" "github.com/terst/listen/server/internal/words" ) // minRecurringCorpus is how many of a show's episodes must have words before what they share // means anything. Three: the target and the two others a stretch has to turn up in. const minRecurringCorpus = 3 func main() { var ( addr = flag.String("addr", "127.0.0.1:38090", "address to listen on") dataDir = flag.String("data", "/site/listen.terst.org/data", "where state and audio live") keep = flag.Int("keep", 8, "episodes to mirror per show") pollEvery = flag.Duration("poll", 2*time.Hour, "how often to refresh every feed") tokenFile = flag.String("token-file", "", "file holding the API token (defaults to /token)") once = flag.Bool("once", false, "run one poll cycle and exit, for checking a deployment") whisperBin = flag.String("whisper", "", "whisper-cli binary; empty disables recognition") whisperModel = flag.String("whisper-model", "", "ggml model file for recognition") whisperThreads = flag.Int("whisper-threads", 6, "cores one recognition run may use") transcribeBudget = flag.Duration("transcribe-budget", 45*time.Minute, "how long each cycle may spend recognising episodes") refetchBudget = flag.Duration("refetch-budget", 20*time.Minute, "how long each cycle may spend fetching and recognising second copies") ) flag.Parse() token, err := readToken(*tokenFile, *dataDir) if err != nil { log.Fatalf("token: %v", err) } statePath := filepath.Join(*dataDir, "state.json") audioDir := filepath.Join(*dataDir, "audio") state, err := store.Load(statePath) if err != nil { log.Fatalf("state: %v", err) } signaturePath := filepath.Join(*dataDir, "signatures.json") // A damaged library is not worth stopping for: it is evidence that can be gathered again, // unlike the state file, which holds the only record of where mirrored audio is. signatures, err := signature.Load(signaturePath) if err != nil { log.Printf("signatures: %v -- starting an empty library", err) signatures = signature.NewLibrary() } decoder := decode.Decoder{} transcriptDir := filepath.Join(*dataDir, "transcripts") transcripts := transcript.Store{Dir: transcriptDir} secondCopyDir := filepath.Join(*dataDir, "work", "second") worker := &worker{ state: state, statePath: statePath, signatures: signatures, signaturePath: signaturePath, keep: *keep, mirror: &mirror.Mirror{AudioDir: audioDir, Probe: decoder}, decoder: decoder, words: &words.Pipeline{ State: state, AudioDir: audioDir, Transcripts: transcripts, Harvester: transcript.Harvester{Store: transcripts}, Recogniser: transcribe.Whisper{ Binary: *whisperBin, Model: *whisperModel, Threads: *whisperThreads, // Beside the audio rather than in /tmp: a decoded hour is 115MB of PCM, and // the data directory is the volume with room for it. WorkDir: filepath.Join(*dataDir, "work"), }, SecondCopies: &mirror.Mirror{AudioDir: secondCopyDir, Probe: decoder}, SecondCopyDir: secondCopyDir, RecogniseBudget: *transcribeBudget, SecondCopyBudget: *refetchBudget, }, requests: make(chan request, 64), wakeups: make(chan struct{}, 1), } // Wired after the worker exists, because it is the worker's own save. The pipeline runs // for tens of minutes at a time and persists as each episode finishes, so a restart in // the middle keeps the ones already done. worker.words.Save = worker.save server := api.New(state, worker, api.Options{ Token: token, AudioDir: audioDir, TranscriptDir: transcriptDir, // Persist the list the moment it arrives, then poll. // // Both halves were learned the hard way. The list is the one thing the server cannot // rediscover, and it used to live only in memory until a whole poll cycle completed -- // which for 61 feeds is hours -- so a restart in the meantime lost every subscription // the phone had sent. And acting on it at once matters because waiting for the next // interval leaves a newly-subscribed show with nothing for hours. OnSubscriptions: func([]string) { worker.save() worker.wake() }, // Same reasoning, one step smaller: a label is a tap the listener made once, and it // should not sit in memory until the end of a poll cycle. No wake -- nothing acts on a // label yet, it is corpus for the signature library. OnLabels: worker.save, }) ctx, stop := signal.NotifyContext(context.Background(), syscall.SIGINT, syscall.SIGTERM) defer stop() if *once { worker.words.Reclaim() worker.words.Rederive() worker.pollAll(ctx) // Recognition too, so a deployment check exercises the expensive path rather than // discovering it is misconfigured hours later in a log nobody is reading. worker.words.Recognise(ctx) worker.words.SecondCopy(ctx) if err := state.Save(statePath); err != nil { log.Fatalf("save: %v", err) } log.Printf("one cycle complete") return } var wg sync.WaitGroup wg.Add(1) go func() { defer wg.Done() worker.run(ctx, *pollEvery) }() httpServer := &http.Server{ Addr: *addr, Handler: server.Handler(), ReadHeaderTimeout: 20 * time.Second, } go func() { <-ctx.Done() shutdownCtx, cancel := context.WithTimeout(context.Background(), 20*time.Second) defer cancel() _ = httpServer.Shutdown(shutdownCtx) }() log.Printf("listening on %s, data in %s, keeping %d episodes per show", *addr, *dataDir, *keep) if err := httpServer.ListenAndServe(); err != nil && !errors.Is(err, http.ErrServerClosed) { log.Fatalf("http: %v", err) } wg.Wait() if err := state.Save(statePath); err != nil { log.Printf("save on exit: %v", err) } } // request is an episode the phone asked for that the server did not have. type request struct { feedURL, guid, enclosureURL, title string } type worker struct { state *store.State statePath string // signatures is the library the shadow run learns into. Nothing it holds is published yet. signatures *signature.Library signaturePath string keep int mirror *mirror.Mirror decoder decode.Decoder // transcripts holds each episode's words, and harvester takes the publishers' own where // they describe the copy that was mirrored. See transcript.Fits for when they do not. // words is the transcript side: taking publishers' transcripts, recognising the rest, and // working out what to skip from what was said. It lives in its own package because none // of it could be tested here. words *words.Pipeline requests chan request wakeups chan struct{} } // wake asks for a poll now. Coalescing, so a burst of subscription updates is one poll. func (w *worker) wake() { select { case w.wakeups <- struct{}{}: default: } } // Request implements api.Fetcher. Non-blocking: a full queue drops the request rather than // stalling the phone, and the next poll will pick the episode up anyway. func (w *worker) Request(feedURL, guid, enclosureURL, title string) { select { case w.requests <- request{feedURL, guid, enclosureURL, title}: default: log.Printf("request queue full, dropping %s %s", feedURL, guid) } } func (w *worker) run(ctx context.Context, every time.Duration) { w.words.Reclaim() w.words.Rederive() w.save() w.pollAll(ctx) w.save() w.words.Recognise(ctx) w.words.SecondCopy(ctx) ticker := time.NewTicker(every) defer ticker.Stop() for { select { case <-ctx.Done(): return case <-ticker.C: w.pollAll(ctx) w.save() // Only on the timer. A wakeup is the phone pushing a subscription list and // wanting that show polled now; following it with three quarters of an hour of // recognition would make a new subscription feel broken. w.words.Recognise(ctx) w.words.SecondCopy(ctx) case <-w.wakeups: w.pollAll(ctx) w.save() case req := <-w.requests: w.serveRequest(ctx, req) w.save() } } } // drainRequests serves everything the phone has asked for, without waiting. // // Bounds how long an on-demand episode waits at one feed rather than one cycle. It does not make // the wait short -- a feed carrying detection takes minutes -- but the phone falls back to the // publisher meanwhile, so the cost of waiting is skip offsets rather than playback. func (w *worker) drainRequests(ctx context.Context) { for { if ctx.Err() != nil { return } select { case req := <-w.requests: w.serveRequest(ctx, req) w.save() default: return } } } func (w *worker) save() { if err := w.state.Save(w.statePath); err != nil { log.Printf("save: %v", err) } } // pollAll refreshes every subscribed feed, then mirrors and detects what changed. func (w *worker) pollAll(ctx context.Context) { // Topical shows first and archive last, so a five-hour back-catalogue episode cannot take // a cycle's recognition budget before the morning news has been looked at. feeds := w.state.ByCategory(w.state.Feeds()) if len(feeds) == 0 { log.Printf("no subscriptions yet; waiting for the phone to send its list") return } for _, feedURL := range feeds { if ctx.Err() != nil { return } // Before each feed, not only between cycles. The poll loop and the request queue share // one goroutine, so an episode the phone asked for used to wait out the entire cycle -- // hours across 42 shows, during which a tap on an unmirrored episode did nothing at all. w.drainRequests(ctx) w.pollOne(ctx, feedURL) // After every feed rather than at the end of the cycle: a cycle over 61 feeds takes // hours, and a restart partway through used to discard all of it. w.save() } // Reclaim the audio of shows no longer subscribed to. // // Against the list as it stands *now*, not the snapshot this cycle began with. A cycle over // 61 feeds takes hours; re-applying a stale snapshot would silently undo a subscription the // phone sent during it, and then delete the audio of every show the stale list omitted. current := make(map[string]bool) for _, url := range w.state.Feeds() { current[url] = true } for _, show := range w.state.Shows() { if current[show.FeedURL] { continue } if dropped := w.state.Forget(show.FeedURL); dropped != nil { for _, e := range dropped.Episodes { _ = w.mirror.Prune(e) } log.Printf("%s: unsubscribed, reclaimed %d episodes", show.FeedURL, len(dropped.Episodes)) } } w.save() } func (w *worker) pollOne(ctx context.Context, feedURL string) { raw, err := fetchFeed(ctx, feedURL) if err != nil { w.noteFeedError(feedURL, err) return } channel, err := feed.Parse(raw) if err != nil { w.noteFeedError(feedURL, err) return } show := w.state.Merge(feedURL, channel.Title, channel.Episodes) show.LastPolledUnix = time.Now().Unix() show.LastError = "" kept, pruned := show.Partition(w.keep, time.Now().Unix()) for _, e := range pruned { if e.Mirrored() { _ = w.mirror.Prune(e) } // The words go with the audio -- see words.Pipeline.Forget. w.words.Forget(e) } fetched := 0 for _, e := range kept { if ctx.Err() != nil { return } if e.Mirrored() { continue } if err := w.mirror.Fetch(ctx, e); err != nil { log.Printf("%s: %v", channel.Title, err) continue } fetched++ } if fetched > 0 { log.Printf("%s: mirrored %d new episode(s)", channel.Title, fetched) } // Before anything else looks at this show: an episode just re-mirrored may already have // its words on disk from before its record was lost, and recognising it again would cost // five minutes for text the server is holding. w.words.Reclaim() w.words.Harvest(ctx, show, kept) w.words.Recurring(show) w.detect(ctx, show, kept) } // detect runs the intro/outro search over a show's mirrored episodes and records the result. // // Every mirrored episode at once, which is the whole reason this is a server: the phone could // only hold one episode's clip, so it needed a rolling state machine that accumulated agreement // over weeks and lost it whenever retention reclaimed the file it was holding. func (w *worker) detect(ctx context.Context, show *store.Show, candidates []*store.Episode) { var episodes []skips.Episode var ids []string byID := map[string]*store.Episode{} for _, e := range candidates { if !e.Mirrored() { continue } episodes = append(episodes, skips.Episode{ ID: e.ID, Path: filepath.Join(w.mirror.AudioDir, e.Path), DeclaredDurationMs: e.DeclaredDurationMs, }) ids = append(ids, e.ID) byID[e.ID] = e } if len(episodes) < skips.DefaultConfirmThreshold || ctx.Err() != nil { return } if !show.NeedsDetection(ids) { return } started := time.Now() result, err := skips.Detect(ctx, w.decoder, episodes, skips.DefaultConfig()) if err != nil { log.Printf("%s: detection failed: %v", show.Title, err) return } now := time.Now().Unix() for _, o := range result.Offsets { if e := byID[o.EpisodeID]; e != nil { e.DetectedAtUnix = now } } // Reported, deliberately not published. // // Intro detection assumes the agreeing episodes were fetched independently. Mirroring eight // of them within one minute means they were not, and it showed: the segment confirmed on 8 // of 8 Radiolab episodes was searched for in an ad-free copy of the same episode fetched // hours earlier and scored r = 0.0621. It was an advertisement. Until the agreeing episodes // are required to span more than one fetch occasion these numbers cannot be trusted, and // the advertising they keep finding is better served by the scan that measures itself // against the declared-versus-served length gap. log.Printf("%s: intro on %d/%d%s, outro on %d/%d%s (not published -- see detectAds), took %s", show.Title, result.IntroConfirmedOn, len(episodes), checkNote(result.IntroCheck), result.OutroConfirmedOn, len(episodes), checkNote(result.OutroCheck), time.Since(started).Round(time.Second)) if w.detectAds(ctx, show, episodes, byID) { show.RecordDetected(ids) // After the batch is recorded, so the shadow run's occasion names the batch it // learned from. It publishes nothing -- see runShadow. w.runShadow(ctx, show, candidates) } } // detectAds finds the advertising a batch of episodes shares, which is what simultaneous // mirroring actually makes detectable. // // Separate from intro detection, and trusted differently. Intro detection assumes the episodes // were fetched independently; mirroring eight of them in one minute means they were not, which // is how it came to confirm an advertisement as an intro. This uses that dependence rather than // being defeated by it -- and reports what it found against the declared-versus-served length // gap, a figure it did not produce and which can therefore contradict it. // Reports whether the scan completed, so an interrupted or failed pass is examined again rather // than written off as done. func (w *worker) detectAds( ctx context.Context, show *store.Show, episodes []skips.Episode, byID map[string]*store.Episode, ) bool { if ctx.Err() != nil { return false } started := time.Now() ads, err := skips.DetectAds(ctx, w.decoder, episodes, skips.DefaultAdConfig()) if err != nil { log.Printf("%s: ad scan failed: %v", show.Title, err) return false } var withBreaks, refused int var foundTotal, insertedTotal int64 for _, ep := range episodes { e := byID[ep.ID] if e == nil { continue } acc := ads.Accounting[ep.ID] e.FoundAdMs, e.InsertedAdMs = acc.FoundMs, acc.InsertedMs e.AdsRefused = ads.Refused[ep.ID] e.Breaks = nil for _, br := range ads.Breaks[ep.ID] { e.Breaks = append(e.Breaks, store.Break{ StartMs: br.StartMs, EndMs: br.EndMs, Partners: br.Partners, Kind: string(br.Kind), }) } if len(e.Breaks) > 0 { withBreaks++ } if e.AdsRefused { refused++ } foundTotal += acc.FoundMs insertedTotal += acc.InsertedMs } log.Printf("%s: ads on %d/%d episode(s)%s, accounted %s of %s inserted, took %s", show.Title, withBreaks, len(episodes), refusedNote(refused), clock(foundTotal), clock(insertedTotal), time.Since(started).Round(time.Second)) return true } func refusedNote(refused int) string { if refused == 0 { return "" } return fmt.Sprintf(" (%d refused as too extensive to be advertising)", refused) } func clock(ms int64) string { total := ms / 1000 return fmt.Sprintf("%d:%02d", total/60, total%60) } // checkNote reports a withheld result loudly. A confirmation that could not verify itself is // the case where publishing offsets would cut the wrong audio. func checkNote(r skips.CheckReport) string { if r.Pairs == 0 || r.OK { return "" } return fmt.Sprintf(" (SELF-CHECK FAILED %s vs %s at r=%.3f, offsets withheld)", r.WorstA, r.WorstB, r.WorstScore) } // serveRequest handles an episode the phone wanted that was not mirrored. func (w *worker) serveRequest(ctx context.Context, req request) { e := w.state.Match(req.feedURL, req.guid, req.enclosureURL, req.title) if e == nil { // Not in the feed as last polled. Register it from what the phone told us, so an // episode older than the mirrored window is still playable with offsets. if req.enclosureURL == "" { return } w.state.Merge(req.feedURL, "", []feed.Episode{{ GUID: req.guid, Title: req.title, EnclosureURL: req.enclosureURL, PublishedUnix: time.Now().Unix(), }}) e = w.state.Match(req.feedURL, req.guid, req.enclosureURL, req.title) if e == nil { return } } // The api marks episodes it can see; this covers the one it could not, which was registered // from what the phone told us a moment ago. Without it the newly-known episode has no // record of being wanted and the next poll prunes what was just fetched for it. e.Requested(time.Now().Unix()) if e.Mirrored() { return } if err := w.mirror.Fetch(ctx, e); err != nil { log.Printf("on-demand fetch %s: %v", e.ID, err) return } log.Printf("on-demand: mirrored %s", e.Title) if show := w.state.Show(req.feedURL); show != nil { kept, _ := show.Partition(w.keep, time.Now().Unix()) w.detect(ctx, show, kept) } } func (w *worker) noteFeedError(feedURL string, err error) { log.Printf("%s: %v", feedURL, err) if show := w.state.Show(feedURL); show != nil { show.LastError = err.Error() show.LastPolledUnix = time.Now().Unix() } } func fetchFeed(ctx context.Context, url string) ([]byte, error) { ctx, cancel := context.WithTimeout(ctx, 2*time.Minute) defer cancel() req, err := http.NewRequestWithContext(ctx, http.MethodGet, url, nil) if err != nil { return nil, err } req.Header.Set("User-Agent", "listen-server/1.0 (+https://terst.org)") // A feed URL is whatever the phone sent, so the same rule applies as to everything else // this server fetches: it may only reach a public address. resp, err := safefetch.Client(0).Do(req) if err != nil { return nil, err } defer resp.Body.Close() if resp.StatusCode != http.StatusOK { return nil, fmt.Errorf("%s returned %s", url, resp.Status) } // Feeds are large -- a real subscription produced 2753 episodes -- but not unbounded. return io.ReadAll(io.LimitReader(resp.Body, 64<<20)) } // readToken loads the API token, generating one on first run. func readToken(tokenFile, dataDir string) (string, error) { if tokenFile == "" { tokenFile = filepath.Join(dataDir, "token") } if raw, err := os.ReadFile(tokenFile); err == nil { token := trimSpace(string(raw)) if token == "" { return "", fmt.Errorf("%s is empty", tokenFile) } return token, nil } else if !os.IsNotExist(err) { return "", err } token, err := generateToken() if err != nil { return "", err } if err := os.MkdirAll(filepath.Dir(tokenFile), 0o755); err != nil { return "", err } if err := os.WriteFile(tokenFile, []byte(token+"\n"), 0o600); err != nil { return "", err } log.Printf("generated a new API token in %s", tokenFile) return token, nil } func trimSpace(s string) string { start, end := 0, len(s) for start < end && (s[start] == ' ' || s[start] == '\n' || s[start] == '\r' || s[start] == '\t') { start++ } for end > start && (s[end-1] == ' ' || s[end-1] == '\n' || s[end-1] == '\r' || s[end-1] == '\t') { end-- } return s[start:end] }