Skip to content

Commit 9ec73e0

Browse files
pksgitclaude
andcommitted
Send EOS for every appsrc linked into the pipeline (CS-1547)
A track subscribed during the CloseWriters() window has its appsrc linked into the running pipeline by OnTrackAdded(), but never sends EOS: cleanup guards on playing.IsBroken(), and the PLAYING notification that would break that fuse is dropped by submitOp() once closing is set. The mixer waits on that input pad forever and shutdown hangs - "endStreamProcessed not broken after 3 seconds", then ErrPipelineFrozen 30s later. Guard cleanup on a new addedToPipeline fuse instead, broken where the appsrc actually becomes part of the pipeline: after OnTrackAdded() for post-init subscriptions, and on BuildReady for tracks present at startup. Playing() breaks it too, since reaching PLAYING implies being linked. This is cfce5d0 re-landed with the hole that forced its revert closed. There, addedToPipeline was broken during source init, so a track that EOF'd during the build phase reached OnEOSSent() -> SendEOS() -> c.p.Stop() with c.p still nil - a panic, and an unsynchronized read of a field BuildPipeline was still writing. Now the fuse is never broken before BuildReady closes, which is what publishes c.p, and onEOSSent() returns early if the pipeline is not built yet. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
1 parent feae0c7 commit 9ec73e0

6 files changed

Lines changed: 437 additions & 1 deletion

File tree

pkg/pipeline/controller.go

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -489,6 +489,17 @@ func (c *Controller) trackStreamRetry(ctx context.Context, stream *config.Stream
489489
}
490490

491491
func (c *Controller) onEOSSent() {
492+
// A writer can finish before BuildPipeline() has published the pipeline - a
493+
// track that EOFs during the build phase. Touching c.p then is both a nil
494+
// dereference and an unsynchronized read of a field BuildPipeline is still
495+
// writing; closing BuildReady is what publishes it safely. Nothing to stop if
496+
// the pipeline does not exist yet.
497+
select {
498+
case <-c.callbacks.BuildReady:
499+
default:
500+
return
501+
}
502+
492503
// for video-only track/track composite, EOS might have already
493504
// made it through the pipeline by the time endRecording is closed
494505
if (c.Passthrough || c.RequestType == types.RequestTypeTrackComposite) && !c.AudioEnabled {

pkg/pipeline/controller_test.go

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,13 +22,15 @@ import (
2222
"testing"
2323
"time"
2424

25+
"github.com/stretchr/testify/require"
2526
"google.golang.org/grpc"
2627
"google.golang.org/protobuf/types/known/emptypb"
2728

2829
"github.com/livekit/egress/pkg/config"
2930
"github.com/livekit/egress/pkg/gstreamer"
3031
"github.com/livekit/egress/pkg/ipc"
3132
"github.com/livekit/egress/pkg/pipeline/source"
33+
"github.com/livekit/egress/pkg/types"
3234
"github.com/livekit/protocol/livekit"
3335
"github.com/livekit/protocol/rpc"
3436
)
@@ -166,3 +168,33 @@ func TestUnsolicitedEOSBeforeSendEOS(t *testing.T) {
166168
t.Fatal("output file is empty")
167169
}
168170
}
171+
172+
// TestOnEOSSentBeforePipelineBuilt covers the failure that forced the revert of
173+
// cfce5d0, the first attempt at fixing CS-1547.
174+
//
175+
// A writer whose track EOFs during the build phase runs its cleanup while
176+
// BuildPipeline() is still running. Sending EOS from there reaches OnEOSSent()
177+
// -> SendEOS() -> c.p.Stop() with c.p not yet assigned: a nil dereference, and
178+
// an unsynchronized read of a field BuildPipeline is concurrently writing. A
179+
// production panic was observed roughly 1ms into the build.
180+
//
181+
// The config below is the one combination that makes onEOSSent() forward to
182+
// SendEOS(): passthrough / track composite with no audio.
183+
func TestOnEOSSentBeforePipelineBuilt(t *testing.T) {
184+
c := &Controller{
185+
PipelineConfig: &config.PipelineConfig{
186+
RequestType: types.RequestTypeTrackComposite,
187+
Passthrough: true,
188+
AudioConfig: config.AudioConfig{AudioEnabled: false},
189+
},
190+
// BuildReady still open and p still nil: BuildPipeline has not published
191+
// the pipeline yet.
192+
callbacks: &gstreamer.Callbacks{BuildReady: make(chan struct{})},
193+
}
194+
195+
require.NotPanics(t, c.onEOSSent,
196+
"cleanup running during the build phase must not dereference the pipeline")
197+
require.False(t, c.eosSent.IsBroken(),
198+
"onEOSSent must not start the EOS sequence before the pipeline exists")
199+
require.Nil(t, c.p, "sanity: the test covers the pre-build window")
200+
}

pkg/pipeline/source/sdk/appwriter.go

Lines changed: 40 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -104,6 +104,7 @@ type AppWriter struct {
104104
lastReceived atomic.Time
105105
lastPushed atomic.Time
106106
playing core.Fuse
107+
addedToPipeline core.Fuse
107108
draining core.Fuse
108109
unsubscribed core.Fuse
109110
endStreamSignaled core.Fuse
@@ -260,6 +261,7 @@ func (w *AppWriter) start() {
260261
w.logger.Errorw("endStreamProcessed not broken after 3 seconds, bug in the draining logic!", nil,
261262
"endStreamSourceProcessed", w.endStreamSourceProcessed.IsBroken(),
262263
"playing", w.playing.IsBroken(),
264+
"addedToPipeline", w.addedToPipeline.IsBroken(),
263265
"active", w.active.Load(),
264266
"lastReceived", w.lastReceived.Load(),
265267
"lastPushed", w.lastPushed.Load(),
@@ -268,7 +270,22 @@ func (w *AppWriter) start() {
268270
}
269271

270272
// clean up
271-
if w.playing.IsBroken() {
273+
if w.shouldSendEOS() {
274+
if !w.playing.IsBroken() {
275+
// The appsrc was linked into the pipeline but its PLAYING notification
276+
// never arrived - the CloseWriters race (CS-1547). Under the old
277+
// playing.IsBroken() guard this writer would have skipped EOS and hung
278+
// the shutdown, so this line means the race happened and was handled.
279+
// Expect it to be rare and to coincide with a shutdown; if it is common,
280+
// or appears outside one, the PLAYING notification is being lost far more
281+
// often than the race alone would explain.
282+
w.logger.Warnw("appsrc never reported PLAYING, sending EOS anyway", nil,
283+
"active", w.active.Load(),
284+
"draining", w.draining.IsBroken(),
285+
"unsubscribed", w.unsubscribed.IsBroken(),
286+
"lastReceived", w.lastReceived.Load(),
287+
)
288+
}
272289
w.callbacks.OnEOSSent()
273290
flow := w.src.EndStream()
274291
if flow == gst.FlowFlushing {
@@ -665,9 +682,31 @@ func (w *AppWriter) maybeCheckPipelineLag(pts time.Duration) {
665682
}
666683

667684
func (w *AppWriter) Playing() {
685+
// reaching PLAYING implies the appsrc is linked into the pipeline
686+
w.addedToPipeline.Break()
668687
w.playing.Break()
669688
}
670689

690+
// MarkAddedToPipeline signals that the appsrc has been linked into the GStreamer
691+
// pipeline. From this point the pipeline has an input pad for this writer and
692+
// will block EOS aggregation until the writer ends its stream.
693+
func (w *AppWriter) MarkAddedToPipeline() {
694+
w.addedToPipeline.Break()
695+
}
696+
697+
// shouldSendEOS reports whether cleanup must push EOS into this writer's appsrc.
698+
//
699+
// The condition that matters is whether the appsrc was linked into the pipeline,
700+
// NOT whether we were told it reached PLAYING. GStreamer propagates the state
701+
// change to a newly added element asynchronously, and the resulting notification
702+
// is dropped outright once CloseWriters() sets closing (submitOp returns early,
703+
// and the worker may already be gone). A writer added moments before shutdown
704+
// would therefore never send EOS, and the mixer would wait on its pad forever -
705+
// the frozen pipeline in CS-1547.
706+
func (w *AppWriter) shouldSendEOS() bool {
707+
return w.addedToPipeline.IsBroken()
708+
}
709+
671710
// Drain blocks until finished
672711
func (w *AppWriter) Drain(force bool) {
673712
w.draining.Once(func() {
Lines changed: 243 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,243 @@
1+
// Copyright 2026 LiveKit, Inc.
2+
//
3+
// Licensed under the Apache License, Version 2.0 (the "License");
4+
// you may not use this file except in compliance with the License.
5+
// You may obtain a copy of the License at
6+
//
7+
// http://www.apache.org/licenses/LICENSE-2.0
8+
//
9+
// Unless required by applicable law or agreed to in writing, software
10+
// distributed under the License is distributed on an "AS IS" BASIS,
11+
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12+
// See the License for the specific language governing permissions and
13+
// limitations under the License.
14+
15+
package sdk
16+
17+
import (
18+
"testing"
19+
"time"
20+
21+
"github.com/go-gst/go-gst/gst"
22+
"github.com/go-gst/go-gst/gst/app"
23+
"github.com/stretchr/testify/require"
24+
)
25+
26+
// TestShouldSendEOS pins the cleanup decision in AppWriter.start().
27+
//
28+
// CS-1547: the guard used to be playing.IsBroken(), which asks "did GStreamer's
29+
// PLAYING notification reach us?" rather than "is this appsrc linked into the
30+
// pipeline?". Those differ during shutdown, because CloseWriters() sets closing
31+
// before GStreamer finishes the async state change and submitOp() then drops the
32+
// notification - permanently. The middle case below is the frozen pipeline.
33+
func TestShouldSendEOS(t *testing.T) {
34+
t.Run("never added to the pipeline", func(t *testing.T) {
35+
w := &AppWriter{}
36+
37+
require.False(t, w.shouldSendEOS(),
38+
"no appsrc in the pipeline means nothing downstream is waiting for EOS")
39+
})
40+
41+
t.Run("added to the pipeline but PLAYING never delivered", func(t *testing.T) {
42+
w := &AppWriter{}
43+
w.MarkAddedToPipeline()
44+
45+
require.False(t, w.playing.IsBroken(),
46+
"precondition: this is the race - the PLAYING notification was dropped")
47+
require.True(t, w.shouldSendEOS(),
48+
"CS-1547: the appsrc is linked into the pipeline, so cleanup must send EOS "+
49+
"even though we were never told it reached PLAYING")
50+
51+
// this state - owing EOS without ever having been told PLAYING - is exactly
52+
// what AppWriter.start() logs as "appsrc never reported PLAYING, sending EOS
53+
// anyway", the signal that the race occurred and was handled
54+
})
55+
56+
t.Run("PLAYING implies added to the pipeline", func(t *testing.T) {
57+
w := &AppWriter{}
58+
w.Playing()
59+
60+
require.True(t, w.addedToPipeline.IsBroken(),
61+
"an appsrc cannot reach PLAYING without being linked into the pipeline")
62+
require.True(t, w.shouldSendEOS(),
63+
"the normal path must keep sending EOS exactly as before")
64+
})
65+
}
66+
67+
const (
68+
testAudioCaps = "audio/x-raw,format=S16LE,layout=interleaved,rate=48000,channels=1"
69+
testFrameSize = 1920 // 20ms of 48kHz mono S16LE
70+
testFrameDuration = 20 * time.Millisecond
71+
eosWaitTimeout = 5 * time.Second
72+
)
73+
74+
type mixerTestPipeline struct {
75+
pipeline *gst.Pipeline
76+
mixer *gst.Element
77+
}
78+
79+
func newMixerTestPipeline(t *testing.T) *mixerTestPipeline {
80+
t.Helper()
81+
gst.Init(nil)
82+
83+
pipeline, err := gst.NewPipeline("cs-1547")
84+
require.NoError(t, err)
85+
86+
mixer, err := gst.NewElement("audiomixer")
87+
require.NoError(t, err)
88+
sink, err := gst.NewElement("fakesink")
89+
require.NoError(t, err)
90+
require.NoError(t, sink.SetProperty("sync", false))
91+
92+
require.NoError(t, pipeline.AddMany(mixer, sink))
93+
require.NoError(t, mixer.Link(sink))
94+
95+
p := &mixerTestPipeline{pipeline: pipeline, mixer: mixer}
96+
t.Cleanup(func() { _ = pipeline.SetState(gst.StateNull) })
97+
return p
98+
}
99+
100+
// addTrack links a new appsrc into the pipeline, exactly like OnTrackAdded().
101+
func (p *mixerTestPipeline) addTrack(t *testing.T, name string) *app.Source {
102+
t.Helper()
103+
104+
elem, err := gst.NewElementWithName("appsrc", "app_"+name)
105+
require.NoError(t, err)
106+
conv, err := gst.NewElement("audioconvert")
107+
require.NoError(t, err)
108+
109+
src := app.SrcFromElement(elem)
110+
src.SetCaps(gst.NewCapsFromString(testAudioCaps))
111+
src.SetArg("format", "time")
112+
require.NoError(t, elem.SetProperty("is-live", false))
113+
114+
require.NoError(t, p.pipeline.AddMany(elem, conv))
115+
require.NoError(t, gst.ElementLinkMany(elem, conv, p.mixer))
116+
117+
// dynamic add: bring the new branch up to the pipeline's state
118+
require.True(t, elem.SyncStateWithParent())
119+
require.True(t, conv.SyncStateWithParent())
120+
121+
return src
122+
}
123+
124+
func pushSilence(t *testing.T, src *app.Source, frames int, startPTS time.Duration) time.Duration {
125+
t.Helper()
126+
127+
pts := startPTS
128+
silence := make([]byte, testFrameSize)
129+
for i := 0; i < frames; i++ {
130+
b := gst.NewBufferFromBytes(silence)
131+
b.SetPresentationTimestamp(gst.ClockTime(uint64(pts)))
132+
b.SetDuration(gst.ClockTime(uint64(testFrameDuration)))
133+
require.Equal(t, gst.FlowOK, src.PushBuffer(b))
134+
pts += testFrameDuration
135+
}
136+
return pts
137+
}
138+
139+
// waitForEOS returns true if the pipeline reached EOS within eosWaitTimeout.
140+
func (p *mixerTestPipeline) waitForEOS(t *testing.T) bool {
141+
t.Helper()
142+
143+
bus := p.pipeline.GetPipelineBus()
144+
deadline := time.Now().Add(eosWaitTimeout)
145+
for time.Now().Before(deadline) {
146+
msg := bus.TimedPopFiltered(gst.ClockTime(uint64(500*time.Millisecond)), gst.MessageEOS|gst.MessageError)
147+
if msg == nil {
148+
continue
149+
}
150+
switch msg.Type() {
151+
case gst.MessageEOS:
152+
return true
153+
case gst.MessageError:
154+
t.Fatalf("pipeline error: %s", msg.String())
155+
}
156+
}
157+
return false
158+
}
159+
160+
// TestMissingEOSFreezesPipeline: the late writer never sends EOS
161+
// (cleanup guard skipped), so the mixer never forwards EOS and shutdown hangs.
162+
func TestMissingEOSFreezesPipeline(t *testing.T) {
163+
p := newMixerTestPipeline(t)
164+
165+
srcA := p.addTrack(t, "A")
166+
require.NoError(t, p.pipeline.SetState(gst.StatePlaying))
167+
pts := pushSilence(t, srcA, 10, 0)
168+
169+
// a subscription lands inside the CloseWriters() window: the appsrc is
170+
// linked into the running pipeline
171+
srcB := p.addTrack(t, "B")
172+
pushSilence(t, srcB, 2, pts)
173+
174+
// shutdown: A drains and sends EOS, B's cleanup skipped EndStream()
175+
// because playing.IsBroken() == false
176+
require.Equal(t, gst.FlowOK, srcA.EndStream())
177+
178+
require.False(t, p.waitForEOS(t),
179+
"CS-1547: expected the pipeline to hang - it should NOT reach EOS while app_B never sent EOS")
180+
}
181+
182+
// TestEOSFromAllWritersCompletes is the control: with EndStream() on
183+
// every appsrc that was linked into the pipeline, EOS propagates immediately.
184+
func TestEOSFromAllWritersCompletes(t *testing.T) {
185+
p := newMixerTestPipeline(t)
186+
187+
srcA := p.addTrack(t, "A")
188+
require.NoError(t, p.pipeline.SetState(gst.StatePlaying))
189+
pts := pushSilence(t, srcA, 10, 0)
190+
191+
srcB := p.addTrack(t, "B")
192+
pushSilence(t, srcB, 2, pts)
193+
194+
require.Equal(t, gst.FlowOK, srcA.EndStream())
195+
require.Equal(t, gst.FlowOK, srcB.EndStream())
196+
197+
require.True(t, p.waitForEOS(t), "pipeline should reach EOS once every appsrc sent EOS")
198+
}
199+
200+
// TestEOSFromNotYetPlayingAppsrc is the premise the fix rests on: EOS
201+
// from an appsrc that was linked and asked to start, but has not been reported
202+
// as PLAYING, still reaches the mixer.
203+
//
204+
// This is the state a track is in during the race. AddSourceBin links the new
205+
// bin and calls SyncStateWithParent (gstreamer/bin.go), so the element is on its
206+
// way to PLAYING via PAUSED while our Go code is still waiting for a bus message
207+
// that CloseWriters will cause to be dropped. Sending EOS from there works.
208+
//
209+
// Boundary worth knowing: an appsrc left in NULL - never asked to change state -
210+
// accepts EndStream() with FlowOK but never propagates it, and the pipeline hangs.
211+
// egress never links a bin without syncing its state; if that ever changes, EOS
212+
// alone will not be enough to unblock shutdown.
213+
func TestEOSFromNotYetPlayingAppsrc(t *testing.T) {
214+
p := newMixerTestPipeline(t)
215+
216+
srcA := p.addTrack(t, "A")
217+
require.NoError(t, p.pipeline.SetState(gst.StatePlaying))
218+
pts := pushSilence(t, srcA, 10, 0)
219+
220+
// linked and started, but only as far as PAUSED - PLAYING was never confirmed
221+
elem, err := gst.NewElementWithName("appsrc", "app_B")
222+
require.NoError(t, err)
223+
conv, err := gst.NewElement("audioconvert")
224+
require.NoError(t, err)
225+
226+
srcB := app.SrcFromElement(elem)
227+
srcB.SetCaps(gst.NewCapsFromString(testAudioCaps))
228+
srcB.SetArg("format", "time")
229+
require.NoError(t, elem.SetProperty("is-live", false))
230+
require.NoError(t, p.pipeline.AddMany(elem, conv))
231+
require.NoError(t, gst.ElementLinkMany(elem, conv, p.mixer))
232+
require.NoError(t, elem.SetState(gst.StatePaused))
233+
require.NoError(t, conv.SetState(gst.StatePaused))
234+
require.Equal(t, gst.StatePaused, elem.GetCurrentState(), "precondition: never reported PLAYING")
235+
236+
pushSilence(t, srcB, 2, pts)
237+
require.Equal(t, gst.FlowOK, srcA.EndStream())
238+
require.Equal(t, gst.FlowOK, srcB.EndStream())
239+
240+
require.True(t, p.waitForEOS(t),
241+
"EOS from a linked-but-not-yet-PLAYING appsrc must still complete the pipeline - "+
242+
"this is what makes addedToPipeline a valid guard")
243+
}

0 commit comments

Comments
 (0)