Bug: SMFFMPEG command profile prevents channel switching

[vdrover]

Describe the Bug

Using the default command profile, a stream group is created from the M3U as expected. Opening this group in VLC, each channel can be viewed as expected. Switching between channels in VLC is fast.

When the default command profile is SMFFMPEG, the first channel will play as expected, and the status page shows the channel details. Trying to switch channels results in no playback. The SM notification system reports client started stream, but no channel appears in the staus page, and no playback as noted above.

Steps to Reproduce

1. Change default command profile to SMFFMPEG.
2. Add profile group M3U to VLC.
3. Play 1st channel in vlc.
4. Stop channel, and try to restart the same channel, or start a different channel.

Stream Master Version

0.13.0

Relevant Logs

# Default command profile

"2025-04-07 13:25:22","Information","0","","Adding client 0HNBLQJSMJNHE:00000001 to channel Channel 1.",\n\n"2025-04-07 13:25:22","Information","0","","No existing channel for 10 Channel 1",\n"2025-04-07 13:25:22","Information","0","","Created new channel for: 10 Channel 1",\n"2025-04-07 13:25:22","Information","0","","Check stream limits for Channel 1 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:25:22","Information","0","","Check stream limits for Channel 1 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:25:22","Information","0","","Check stream limits for Channel 1 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:25:22","Information","0","","Created new source stream for: a8f14a834d2d09054715803924e798b2 Channel 1",\n"2025-04-07 13:25:22","Information","0","","Setting source stream Channel 1 to Channel 1",\n"2025-04-07 13:25:22","Information","0","","Getting stream for Channel 1",\n\n"2025-04-07 13:25:25","Information","0","","Got stream for Channel 1 in 2093 ms",\n\n"2025-04-07 13:25:25","Information","0","","Client started streaming Channel 1",\n"2025-04-07 13:25:25","Information","0","","RunPipelineAsync Channel 1",\n"2025-04-07 13:25:25","Information","0","","Channel with ChannelId 10 streaming in 2097ms.",\n\n"2025-04-07 13:25:27","Information","0","","Stopping client 0HNBLQJSMJNHE:00000001.",\n\n"2025-04-07 13:25:27","Information","0","","Unregistered Client 0HNBLQJSMJNHE:00000001 Channel 1 disposing",\n\n"2025-04-07 13:25:29","Warning","0","","No clients connected. Stopping the pipeline.",\n"2025-04-07 13:25:29","Information","0","","Source Broadcaster stopped: Channel 1",\n"2025-04-07 13:25:29","Information","0","","Stream Channel 1 stopped.",\n\n"2025-04-07 13:25:29","Information","0","","Channel Broadcaster stopped: Channel 1",\n\n"2025-04-07 13:25:30","Information","0","","Adding client 0HNBLQJSMJNI0:00000001 to channel Channel 2.",\n"2025-04-07 13:25:30","Information","0","","No existing channel for 11 Channel 2",\n"2025-04-07 13:25:30","Information","0","","Created new channel for: 11 Channel 2",\n"2025-04-07 13:25:30","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:25:30","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:25:30","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:25:30","Information","0","","Created new source stream for: d6b64a19b548bf941f57cdd4c5d71904 Channel 2",\n"2025-04-07 13:25:30","Information","0","","Setting source stream Channel 2 to Channel 2",\n"2025-04-07 13:25:30","Information","0","","Getting stream for Channel 2",\n\n"2025-04-07 13:25:32","Information","0","","Got stream for Channel 2 in 1550 ms",\n"2025-04-07 13:25:32","Information","0","","RunPipelineAsync Channel 2",\n"2025-04-07 13:25:32","Information","0","","Client started streaming Channel 2",\n"2025-04-07 13:25:32","Information","0","","Channel with ChannelId 11 streaming in 1553ms.",\n\n"2025-04-07 13:25:34","Information","0","","Stopping client 0HNBLQJSMJNI0:00000001.",\n"2025-04-07 13:25:34","Information","0","","Unregistered Client 0HNBLQJSMJNI0:00000001 Channel 2 disposing",\n\n"2025-04-07 13:25:36","Information","0","","Channel Broadcaster stopped: Channel 2",\n\n"2025-04-07 13:25:36","Error","0","","Source stream read error: Stream closed unexpectedly",\n"2025-04-07 13:25:36","Information","0","","Source Broadcaster stopped: Channel 2",\n"2025-04-07 13:25:36","Information","0","","Stream Channel 2 stopped.",\n\n"


# SMFFMPEG command profile 

"2025-04-07 13:29:07","Information","0","","Adding client 0HNBLR0CVK886:00000001 to channel Channel 1.",\n\n"2025-04-07 13:29:07","Information","0","","No existing channel for 10 Channel 1",\n"2025-04-07 13:29:07","Information","0","","Created new channel for: 10 Channel 1",\n"2025-04-07 13:29:07","Information","0","","Check stream limits for Channel 1 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:29:07","Information","0","","Check stream limits for Channel 1 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:29:07","Information","0","","Check stream limits for Channel 1 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:29:07","Information","0","","Created new source stream for: a8f14a834d2d09054715803924e798b2 Channel 1",\n"2025-04-07 13:29:07","Information","0","","Setting source stream Channel 1 to Channel 1",\n"2025-04-07 13:29:07","Information","0","","Using Command Profile SMFFMPEG for streaming: Channel 1",\n"2025-04-07 13:29:07","Information","0","","Opened command with args ""ffmpeg -hide_banner -loglevel error -user_agent {clientUserAgent} -fflags \u002Bgenpts\u002Bdiscardcorrupt -i {streamUrl} -map 0:v -map 0:a? -map 0:s? -c copy -f mpegts -copyts -reconnect 1 -reconnect_streamed 1 -reconnect_on_network_error 1 -reconnect_delay_max 10 -fflags \u002Bnobuffer pipe:1"" in 2 ms",\n"2025-04-07 13:29:07","Information","0","","Video info service started for Channel 1",\n"2025-04-07 13:29:07","Information","0","","RunPipelineAsync Channel 1",\n"2025-04-07 13:29:07","Information","0","","Client started streaming Channel 1",\n"2025-04-07 13:29:07","Information","0","","Channel with ChannelId 10 streaming in 97ms.",\n\n"2025-04-07 13:29:15","Information","0","","Stopping client 0HNBLR0CVK886:00000001.",\n\n"2025-04-07 13:29:15","Information","0","","Unregistered Client 0HNBLR0CVK886:00000001 Channel 1 disposing",\n\n"2025-04-07 13:29:17","Information","0","","Channel Broadcaster stopped: Channel 1",\n\n"2025-04-07 13:29:17","Error","0","","Source stream read error: Stream closed unexpectedly",\n"2025-04-07 13:29:17","Information","0","","Source Broadcaster stopped: Channel 1",\n"2025-04-07 13:29:17","Information","0","","Stream Channel 1 stopped.",\n\n"2025-04-07 13:29:18","Information","0","","Adding client 0HNBLR0CVK88S:00000001 to channel Channel 2.",\n"2025-04-07 13:29:18","Information","0","","No existing channel for 11 Channel 2",\n"2025-04-07 13:29:18","Information","0","","Created new channel for: 11 Channel 2",\n"2025-04-07 13:29:18","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:29:18","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:29:18","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 0, maxStreamCount: 2",\n"2025-04-07 13:29:18","Information","0","","Created new source stream for: d6b64a19b548bf941f57cdd4c5d71904 Channel 2",\n"2025-04-07 13:29:18","Information","0","","Setting source stream Channel 2 to Channel 2",\n"2025-04-07 13:29:18","Information","0","","Using Command Profile SMFFMPEG for streaming: Channel 2",\n"2025-04-07 13:29:18","Information","0","","Opened command with args ""ffmpeg -hide_banner -loglevel error -user_agent {clientUserAgent} -fflags \u002Bgenpts\u002Bdiscardcorrupt -i {streamUrl} -map 0:v -map 0:a? -map 0:s? -c copy -f mpegts -copyts -reconnect 1 -reconnect_streamed 1 -reconnect_on_network_error 1 -reconnect_delay_max 10 -fflags \u002Bnobuffer pipe:1"" in 0 ms",\n"2025-04-07 13:29:18","Information","0","","RunPipelineAsync Channel 2",\n"2025-04-07 13:29:18","Information","0","","Attempt 0 to switch channel. Waiting 00:00:01.8745235 before next attempt.",\n\n"2025-04-07 13:29:20","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 1, maxStreamCount: 2",\n"2025-04-07 13:29:20","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 1, maxStreamCount: 2",\n"2025-04-07 13:29:20","Information","0","","Created new source stream for: d6b64a19b548bf941f57cdd4c5d71904 Channel 2",\n"2025-04-07 13:29:20","Information","0","","Setting source stream Channel 2 to Channel 2",\n"2025-04-07 13:29:20","Information","0","","Using Command Profile SMFFMPEG for streaming: Channel 2",\n"2025-04-07 13:29:20","Information","0","","Opened command with args ""ffmpeg -hide_banner -loglevel error -user_agent {clientUserAgent} -fflags \u002Bgenpts\u002Bdiscardcorrupt -i {streamUrl} -map 0:v -map 0:a? -map 0:s? -c copy -f mpegts -copyts -reconnect 1 -reconnect_streamed 1 -reconnect_on_network_error 1 -reconnect_delay_max 10 -fflags \u002Bnobuffer pipe:1"" in 0 ms",\n"2025-04-07 13:29:20","Information","0","","RunPipelineAsync Channel 2",\n"2025-04-07 13:29:20","Information","0","","Attempt 1 to switch channel. Waiting 00:00:01.8651502 before next attempt.",\n\n"2025-04-07 13:29:21","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 1, maxStreamCount: 2",\n"2025-04-07 13:29:21","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 1, maxStreamCount: 2",\n\n"2025-04-07 13:29:21","Information","0","","Created new source stream for: d6b64a19b548bf941f57cdd4c5d71904 Channel 2",\n"2025-04-07 13:29:21","Information","0","","Setting source stream Channel 2 to Channel 2",\n"2025-04-07 13:29:21","Information","0","","Using Command Profile SMFFMPEG for streaming: Channel 2",\n"2025-04-07 13:29:21","Information","0","","Opened command with args ""ffmpeg -hide_banner -loglevel error -user_agent {clientUserAgent} -fflags \u002Bgenpts\u002Bdiscardcorrupt -i {streamUrl} -map 0:v -map 0:a? -map 0:s? -c copy -f mpegts -copyts -reconnect 1 -reconnect_streamed 1 -reconnect_on_network_error 1 -reconnect_delay_max 10 -fflags \u002Bnobuffer pipe:1"" in 0 ms",\n"2025-04-07 13:29:21","Information","0","","RunPipelineAsync Channel 2",\n"2025-04-07 13:29:21","Information","0","","Attempt 2 to switch channel. Waiting 00:00:04.4017502 before next attempt.",\n\n"2025-04-07 13:29:26","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 1, maxStreamCount: 2",\n"2025-04-07 13:29:26","Information","0","","Check stream limits for Channel 2 : currentStreamCount: 1, maxStreamCount: 2",\n\n"2025-04-07 13:29:26","Information","0","","Created new source stream for: d6b64a19b548bf941f57cdd4c5d71904 Channel 2",\n"2025-04-07 13:29:26","Information","0","","Setting source stream Channel 2 to Channel 2",\n"2025-04-07 13:29:26","Information","0","","Using Command Profile SMFFMPEG for streaming: Channel 2",\n"2025-04-07 13:29:26","Information","0","","Opened command with args ""ffmpeg -hide_banner -loglevel error -user_agent {clientUserAgent} -fflags \u002Bgenpts\u002Bdiscardcorrupt -i {streamUrl} -map 0:v -map 0:a? -map 0:s? -c copy -f mpegts -copyts -reconnect 1 -reconnect_streamed 1 -reconnect_on_network_error 1 -reconnect_delay_max 10 -fflags \u002Bnobuffer pipe:1"" in 0 ms",\n"2025-04-07 13:29:26","Information","0","","RunPipelineAsync Channel 2",\n"2025-04-07 13:29:26","Error","0","","Error processing stream request. Parameters: encodedIds=(null), smChannelId=11, streamGroupProfileId=1","StreamMaster.Streams.Domain.Exceptions.SourceBroadcasterNotFoundException: Failed to create source broadcaster\n   at StreamMaster.Streams.Channels.ChannelService.\u003C\u003Ec__DisplayClass29_0.\u003C\u003CSwitchChannelToNextStreamAsync\u003Eb__0\u003Ed.MoveNext() in /src/StreamMaster.Streams/Channels/ChannelService.cs:line 397\n--- End of stack trace from previous location ---\n   at Polly.ResiliencePipeline.\u003C\u003Ec__10\u00601.\u003C\u003CExecuteAsync\u003Eb__10_0\u003Ed.MoveNext()\n--- End of stack trace from previous location ---\n   at Polly.Outcome\u00601.GetResultOrRethrow()\n   at Polly.ResiliencePipeline.ExecuteAsync[TResult](Func\u00602 callback, CancellationToken cancellationToken)\n   at StreamMaster.Streams.Channels.ChannelService.SwitchChannelToNextStreamAsync(IChannelBroadcaster channelBroadcaster, IClientConfiguration clientConfiguration, String overrideSMStreamId) in /src/StreamMaster.Streams/Channels/ChannelService.cs:line 379\n   at StreamMaster.Streams.Channels.ChannelService.GetOrCreateChannelBroadcasterAsync(IClientConfiguration clientConfiguration, Int32 streamGroupProfileId) in /src/StreamMaster.Streams/Channels/ChannelService.cs:line 263\n   at StreamMaster.Streams.Channels.ChannelService.AddClientToChannelAsync(IClientConfiguration clientConfiguration, Int32 streamGroupProfileId, CancellationToken cancellationToken) in /src/StreamMaster.Streams/Channels/ChannelService.cs:line 152\n   at StreamMaster.Streams.Services.VideoService.AddClientToChannelAsync(HttpContext httpContext, Nullable\u00601 streamGroupId, Nullable\u00601 streamGroupProfileId, Nullable\u00601 smChannelId, CancellationToken cancellationToken) in /src/StreamMaster.Streams/Services/VideoService.cs:line 70\n   at StreamMaster.API.Controllers.VsController.HandleStreamRequest(String encodedIds, Nullable\u00601 smChannelId, Nullable\u00601 streamGroupProfileId, CancellationToken cancellationToken) in /src/StreamMaster.API/Controllers/VController.cs:line 50"\n"2025-04-07 13:29:26","Warning","2","NoFormatter","No output formatter was found for content types \u0027video/mp2t, video/mp2t\u0027 to write the response.",\n"2025-04-07 13:29:26","Information","0","","Adding client 0HNBLR0CVK89S:00000001 to channel Channel 2.",\n"2025-04-07 13:29:26","Information","0","","Reuse existing stream handler for 11 Channel 2",\n"2025-04-07 13:29:26","Information","0","","Client started streaming Channel 2",\n"2025-04-07 13:29:26","Information","0","","Channel with ChannelId 11 streaming in 2ms.",\n\n"2025-04-07 13:29:35","Information","0","","Added EPGRemovedExpiredKeys to Queue",\n\n"2025-04-07 13:29:35","Information","0","","Got EPGRemovedExpiredKeys from Queue",\n"2025-04-07 13:29:35","Information","0","","Starting EPGRemovedExpiredKeys",\n"2025-04-07 13:29:35","Information","0","","Starting task: EPGRemovedExpiredKeys",\n"2025-04-07 13:29:35","Information","0","","Finished task: EPGRemovedExpiredKeys",\n"2025-04-07 13:29:35","Information","0","","Finished EPGRemovedExpiredKeys",\n\n"2025-04-07 13:29:37","Information","0","","Stopping client 0HNBLR0CVK89S:00000001.",\n\n"2025-04-07 13:29:37","Information","0","","Unregistered Client 0HNBLR0CVK89S:00000001 Channel 2 disposing",\n\n"2025-04-07 13:29:38","Information","0","","Channel Broadcaster stopped: Channel 2",\n\n"

Relevant Configuration

No response

Verification

• I have included COMPLETE logs, not just error messages
• I have provided detailed reproduction steps
• I have checked for similar issues before creating this report
• I have tried the latest release to see if the issue has already been fixed
• I understand that incomplete reports may be closed without investigation

[carlreid]

Thanks for reporting this. It is being a little tricky to debug, as it only seems to happen when I run the container so far. As in, when I run on Windows / in development, it can't be reproduced.

So I wonder if it's somehow related to the ffmpeg binary being used in the containers currently. Though will need to revisit it and debug it further.

[j0nathan33]

I have the same problem and I found it. When I started to watch channel and I change the channel, the thread is not kill:

I don't have a solution but my provider has a limit of 1 stream

[carlreid]

When I started to watch channel and I change the channel, the thread is not kill:

It's what I concluded too, and was trying some changes on #99 for improving the handling of the underlying process. Though it didn't seem to fix it for my testing yet.

[triksmelb]

I know this isn't helpful but just wanted to say I'm seeing similar issue when changing channels but can't get to the bottom of it. There are too many variables to get a solid pattern in logs but seems like it's mainly occurring when using ffmpeg profiles other than STREAMMASTER default. I agree switching channels in VLC using exactly the same m3u is seamless.