search

savonet / liquidsoap

Liquidsoap is a statically typed scripting general-purpose language with dedicated operators and backend for all thing media, streaming, file generation, automation, HTTP backend and more.
http://liquidsoap.info
GNU General Public License v2.0
1.4k stars 128 forks source link

Broken pipe on switch between input.rtmp() and single() #3003

Closed TheRealMattLear closed 1 year ago

TheRealMattLear commented 1 year ago

Describe the bug

After input.rtmp(listen=false) becomes active we see [output.url:4] Error while encoding data: Avutil.Error(Broken pipe) with the source failing and reconnecting 2 seconds later.

Full output:

[flv @ 0x7faac0034200] 2023/04/14 09:42:57 [output.url:4] Error while encoding data: Avutil.Error(Broken pipe)
2023/04/14 09:42:57 [output.url:4] Raised by primitive operation at Stdlib__List.iter in file "list.ml", line 110, characters 12-15
2023/04/14 09:42:57 [output.url:4] Called from Stdlib__Option.map in file "option.ml", line 24, characters 57-62
2023/04/14 09:42:57 [output.url:4] Called from Ffmpeg_encoder_common.encode in file "encoder/ffmpeg_encoder_common.ml", line 103, characters 4-80
2023/04/14 09:42:57 [output.url:4] Called from Ffmpeg_encoder_common.encoder.encode in file "encoder/ffmpeg_encoder_common.ml", line 226, characters 4-44
2023/04/14 09:42:57 [output.url:4] Called from Pipe_output.url_output#encode in file "outputs/pipe_output.ml", line 177, characters 22-48
2023/04/14 09:42:57 [output.url:4]
Failed to update header with correct duration.
[flv @ 0x7faac0034200] Failed to update header with correct filesize.
[AVIOContext @ 0x7faac000ae80] Statistics: 0 seeks, 848 writeouts
2023/04/14 09:42:57 [output.url:3] Will try again in 2.00 seconds.
[tcp @ 0x7faaa8165000] Starting connection attempt to 69.164.211.48 port 1935
[tcp @ 0x7faaa8165000] Successfully connected to 69.164.211.48 port 1935

To Reproduce

log.level.set(4)
settings.log.file.set(false);

settings.init.allow_root.set(true);
settings.ffmpeg.log.verbosity.set("verbose")
settings.ffmpeg.content.copy.relaxed_compatibility_check.set(true)

live_stream = input.rtmp(listen=false,"rtmp://127.0.0.1:1935/static/live");
live_stream = ffmpeg.filter.bitstream.h264_mp4toannexb(live_stream)

fallback_video = single("/root/fallback.mp4");
fallback_video = ffmpeg.filter.bitstream.h264_mp4toannexb(fallback_video)

s = fallback(track_sensitive=false,[live_stream,fallback_video])
s = ffmpeg.filter.bitstream.aac_adtstoasc(s)

flv = %ffmpeg(
  format="flv",
#  fflags="no_duration_filesize",
  %audio.copy, %video.copy)

output.url(
  fallible=true,
  url="rtmp://127.0.0.1:1935/output/live",
  flv,
  s
  )

Version details

Install method .deb package install via apt

toots commented 1 year ago

Hi @TheRealMattLear. Any chance you could provide more logs from before the error? At face value, it looks like the rtmp output connection broke, trying to see if that's because perhaps the streaming loop got stuck/delayed.

TheRealMattLear commented 1 year ago

Hey @toots thanks so much for reviewing this. I'm actually seeing this more consistently after the disconnect from the rtmp source transitioning through to the single("/root/fallback.mp4") and only ocassionally when connecting the rtmp source initially, such as the example below (same config as above). In the below example i hit CTRL+C at 2023/04/26 00:25:08 to shutdown.

RTMP service provided by nginx-rtmp

nginx-rtmp config Various configurations don't seem to effect anything that i can see. ``` worker_processes 1; # Nginx-rtmp is buggy with more than 1 process user sail; # worker_processes auto; # pid /run/nginx.pid; # include /etc/nginx/modules-enabled/*.conf; error_log /usr/local/nginx/logs/error.log error; events { worker_connections 1024; multi_accept on; } rtmp { server { listen 1935; listen 1936 ssl; ssl_certificate /var/www/html/fullchain.pem; ssl_certificate_key /var/www/html/server.key; notify_relay_redirect off; notify_send_redirect off; application static { live on; idle_streams off; wait_key on; wait_video on; drop_idle_publisher 10s; } application output { live on; idle_streams off; wait_key on; wait_video on; interleave on; sync 50ms; drop_idle_publisher 5s; } } } ```
Log Output ``` root@3273e7eb8030:/var/www/html# liquidsoap test.liq INFO: Loading Sdl_ttf, Target = linux INFO: Loading Sdl_image, Target = linux 2023/04/26 00:24:07 >>> LOG START 2023/04/26 00:24:04 [main:3] Liquidsoap 2.1.5+git@fb688f638 2023/04/26 00:24:04 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] posix-time2=65ec333 pcre=7.5.0 sedlex=3.0 menhirLib=20220210 curl=0.9.2 uri=4.2.0 memtrace=0.2.3 mem_usage=0.0.4 dtools=0.4.4 duppy=0.9.3 cry=0.6.8 mm=0.8.3 xmlplaylist=0.1.5 lastfm=0.3.3 ogg=0.7.3 ogg.decoder=0.7.3 vorbis=0.8.1 vorbis.decoder=0.8.1 opus=0.2.3 opus.decoder=0.2.3 speex=0.4.1 speex.decoder=0.4.1 mad=0.5.3 flac=0.3.1 flac.ogg=0.3.1 flac.decoder=0.3.1 dynlink=[distributed with Ocaml] lame=0.3.6 shine=0.2.3 frei0r=0.1.2 fdkaac=0.3.3 theora=0.4.0 theora.decoder=0.4.0 ffmpeg=1.1.8 bjack=0.1.6 alsa=0.3.0 ao=0.2.4 samplerate=0.1.6 taglib=0.3.10 ssl=0.5.13 magic=0.7.3 camomile=1.0.2 inotify=2.0-58-g1beb568 faad=0.5.2 soundtouch=0.1.9 portaudio=0.2.3 pulseaudio=0.1.6 ladspa=0.2.2 dssi=0.1.5 tsdl=v0.9.9 tsdl-ttf=0.5 tsdl-image=0.5 camlimages=4.2.6 camlimages.freetype=5.0.4 cohttp-lwt-unix=5.0.0 prometheus-app=1.2 srt.constants=0.3.0 srt.types=0.3.0 srt.stubs=0.3.0 srt.stubs.locked=0.3.0 srt=0.3.0 lo=0.2.0 gd=1.0a5 irc-client-unix=[unspecified] 2023/04/26 00:24:04 [main:3] 2023/04/26 00:24:04 [main:3] DISCLAIMER: This version of Liquidsoap has been 2023/04/26 00:24:04 [main:3] compiled from a snapshot of the development code. 2023/04/26 00:24:04 [main:3] As such, it should not be used in production 2023/04/26 00:24:04 [main:3] unless you know what you are doing! 2023/04/26 00:24:04 [main:3] 2023/04/26 00:24:04 [main:3] We are, however, very interested in any feedback 2023/04/26 00:24:04 [main:3] about our development code and committed to fix 2023/04/26 00:24:04 [main:3] issues as soon as possible. 2023/04/26 00:24:04 [main:3] 2023/04/26 00:24:04 [main:3] If you are interested in collaborating to 2023/04/26 00:24:04 [main:3] the development of Liquidsoap, feel free to 2023/04/26 00:24:04 [main:3] drop us a mail at 2023/04/26 00:24:04 [main:3] or to join the slack chat at . 2023/04/26 00:24:04 [main:3] 2023/04/26 00:24:04 [main:3] Please send any bug report or feature request 2023/04/26 00:24:04 [main:3] at . 2023/04/26 00:24:04 [main:3] 2023/04/26 00:24:04 [main:3] We hope you enjoy this snapshot build of Liquidsoap! 2023/04/26 00:24:04 [main:3] 2023/04/26 00:24:04 [clock:3] Using native (high-precision) implementation for latency control 2023/04/26 00:24:07 [frame:4] frame.audio.samplerate set to: 44100 2023/04/26 00:24:07 [frame:4] frame.video.framerate set to: 25 2023/04/26 00:24:07 [frame:4] frame.audio.channels set to: 2 2023/04/26 00:24:07 [frame:4] frame.video.default set to: false 2023/04/26 00:24:07 [frame:4] frame.midi.channels set to: 0 2023/04/26 00:24:07 [frame:4] frame.video.width set to: 1280 2023/04/26 00:24:07 [frame:4] frame.video.height set to: 720 2023/04/26 00:24:07 [frame:4] frame.audio.samplerate set to: 44100 2023/04/26 00:24:07 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main. 2023/04/26 00:24:07 [frame:3] Video frame size set to: 1280x720 2023/04/26 00:24:07 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples. 2023/04/26 00:24:07 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks. 2023/04/26 00:24:07 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks. 2023/04/26 00:24:07 [sandbox:3] Sandboxing disabled 2023/04/26 00:24:07 [video.converter:3] Using preferred video converter: ffmpeg. 2023/04/26 00:24:07 [audio.converter:3] Using samplerate converter: libsamplerate. 2023/04/26 00:24:07 [clock:4] Currently 4 clock(s) allocated. 2023/04/26 00:24:07 [clock.aac_adtstoasc.producer_0.child:4] Starting 1 source(s)... 2023/04/26 00:24:07 [source:4] Source aac_adtstoasc.consumer_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [aac_adtstoasc.consumer_0:4] Content type is {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [source:4] Source switch_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [source:4] Source h264_mp4toannexb.producer_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [h264_mp4toannexb.producer_0:4] Content type is {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [source:4] Source h264_mp4toannexb.consumer_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [h264_mp4toannexb.consumer_0:4] Content type is {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [source:4] Source input.ffmpeg_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [source:4] Source h264_mp4toannexb.producer_1 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [h264_mp4toannexb.producer_1:4] Content type is {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [source:4] Source h264_mp4toannexb.consumer_1 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [h264_mp4toannexb.consumer_1:4] Content type is {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [source:4] Source single_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}. 2023/04/26 00:24:07 [single_0:3] "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4" is static, resolving once for all... 2023/04/26 00:24:07 [decoder.ogg:4] Unsupported file extension for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4"! 2023/04/26 00:24:07 [decoder.ogg:4] Unsupported MIME type for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4": video/mp4! 2023/04/26 00:24:07 [decoder.srt:4] Unsupported file extension for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4"! 2023/04/26 00:24:07 [decoder.srt:4] Unsupported MIME type for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4": video/mp4! 2023/04/26 00:24:07 [decoder:4] Available decoders: FFMPEG (priority: 10), IMAGE (priority: 1) 2023/04/26 00:24:07 [decoder:4] Trying decoder "FFMPEG" [h264 @ 0x7fc6cc00ad40] Reinit context to 1280x720, pix_fmt: yuv420p 2023/04/26 00:24:07 [decoder.ffmpeg:4] ffmpeg recognizes "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4" as: audio: {codec: aac, 48000Hz, 2 channel(s)}, video: {codec: h264, 1280x720, yuv420p} and content-type: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. [AVIOContext @ 0x7fc6cc011f40] Statistics: 65536 bytes read, 0 seeks 2023/04/26 00:24:07 [decoder:4] Selected decoder FFMPEG for file "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4" with expected kind {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none} and detected content {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none} [h264 @ 0x7fc6cc023cc0] Reinit context to 1280x720, pix_fmt: yuv420p [AVIOContext @ 0x7fc6cc0114c0] Statistics: 65536 bytes read, 0 seeks 2023/04/26 00:24:07 [metadata.flac:4] Unsupported file extension for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4"! 2023/04/26 00:24:07 [metadata.flac:4] Unsupported MIME type for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4": video/mp4! 2023/04/26 00:24:07 [metadata.mp4:4] Unsupported MIME type for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4": video/mp4! 2023/04/26 00:24:07 [decoder.ogg:4] Unsupported file extension for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4"! 2023/04/26 00:24:07 [decoder.ogg:4] Unsupported MIME type for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4": video/mp4! 2023/04/26 00:24:07 [decoder.id3:4] Unsupported file extension for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4"! 2023/04/26 00:24:07 [decoder.id3:4] Unsupported MIME type for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4": video/mp4! 2023/04/26 00:24:07 [decoder.id3:4] Unsupported file extension for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4"! 2023/04/26 00:24:07 [decoder.id3:4] Unsupported MIME type for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4": video/mp4! 2023/04/26 00:24:07 [decoder.id3:4] Unsupported file extension for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4"! 2023/04/26 00:24:07 [decoder.id3:4] Unsupported MIME type for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4": video/mp4! 2023/04/26 00:24:07 [decoder.image.metadata:4] Unsupported file extension for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4"! 2023/04/26 00:24:07 [decoder.image.metadata:4] Unsupported MIME type for "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4": video/mp4! [h264 @ 0x7fc6cc0fbb40] Reinit context to 1280x720, pix_fmt: yuv420p [AVIOContext @ 0x7fc6cc0114c0] Statistics: 65536 bytes read, 0 seeks [h264 @ 0x7fc6cc020e00] Reinit context to 1280x720, pix_fmt: yuv420p 2023/04/26 00:24:07 [single_0:3] Prepared "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4" (RID 0). 2023/04/26 00:24:07 [clock.h264_mp4toannexb.producer_1.child:4] Starting 1 source(s)... 2023/04/26 00:24:07 [clock.main:4] Starting 1 source(s)... 2023/04/26 00:24:07 [source:4] Source output.file_0 gets up with content kind: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/04/26 00:24:07 [output.url:4] Content type is {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/04/26 00:24:07 [source:4] Source aac_adtstoasc.producer_0 gets up with content kind: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/04/26 00:24:07 [aac_adtstoasc.producer_0:4] Content type is {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. [tcp @ 0x7fc6cc017080] Starting connection attempt to 69.164.211.48 port 1935 [tcp @ 0x7fc6cc017080] Successfully connected to 69.164.211.48 port 1935 2023/04/26 00:24:07 [threads:4] Created thread "clock_main" (1 total). 2023/04/26 00:24:07 [clock.h264_mp4toannexb.producer_0.child:4] Starting 2 source(s)... 2023/04/26 00:24:07 [clock:4] Main phase starts. 2023/04/26 00:24:07 [threads:4] Created thread "generic queue #1" (1 total). 2023/04/26 00:24:07 [threads:4] Created thread "generic queue #2" (2 total). 2023/04/26 00:24:07 [threads:4] Created thread "non-blocking queue #1" (3 total). 2023/04/26 00:24:07 [threads:4] Created thread "non-blocking queue #2" (4 total). [tcp @ 0x7fc6bc005b00] Starting connection attempt to 127.0.0.1 port 1935 2023/04/26 00:24:07 [video.text:3] Using camlimages implementation [tcp @ 0x7fc6bc005b00] Successfully connected to 127.0.0.1 port 1935 2023/04/26 00:24:07 [clock.main:3] Streaming loop starts in auto-sync mode 2023/04/26 00:24:07 [clock.main:3] Delegating synchronisation to CPU clock 2023/04/26 00:24:07 [switch_0:3] Switch to h264_mp4toannexb.producer_1. [rtmp @ 0x7fc6bc004f00] Server error: No such stream 2023/04/26 00:24:08 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b0007ac0] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b0007ac0] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7fc6b0006ec0] Server error: No such stream 2023/04/26 00:24:10 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b000a340] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b000a340] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7fc6b0007300] Server error: No such stream 2023/04/26 00:24:12 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b000a400] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b000a400] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7fc6b000b640] Server error: No such stream 2023/04/26 00:24:14 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b000cf80] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b000cf80] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7fc6b000c700] Server error: No such stream 2023/04/26 00:24:16 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b000c980] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b000c980] Successfully connected to 127.0.0.1 port 1935 [h264 @ 0x7fc6b001fa80] Reinit context to 1280x720, pix_fmt: yuv420p 2023/04/26 00:24:21 [decoder.ffmpeg:4] ffmpeg recognizes "rtmp://127.0.0.1:1935/static/liveinput" as: audio: {codec: aac, 48000Hz, 2 channel(s)}, video: {codec: h264, 1280x720, yuv420p} and content-type: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/04/26 00:24:21 [switch_0:3] Switch to h264_mp4toannexb.producer_0 with transition. 2023/04/26 00:24:53 [input.ffmpeg_0:4] Feeding failed: Avutil.Error(Input/output error) 2023/04/26 00:24:53 [input.ffmpeg_0:4] Raised by primitive operation at Av.read_input in file "av/av.ml", line 220, characters 2-31 2023/04/26 00:24:53 [input.ffmpeg_0:4] Called from Ffmpeg_decoder.mk_decoder.(fun).f in file "decoder/ffmpeg_decoder.ml", line 669, characters 10-99 2023/04/26 00:24:53 [input.ffmpeg_0:4] Re-raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "decoder/ffmpeg_decoder.ml", line 702, characters 12-48 2023/04/26 00:24:53 [input.ffmpeg_0:4] Called from Ffmpeg_io.input#get_frame in file "io/ffmpeg_io.ml", line 190, characters 10-24 2023/04/26 00:24:53 [input.ffmpeg_0:4] [AVIOContext @ 0x7fc6b000a400] Statistics: 6775820 bytes read, 0 seeks [tcp @ 0x7fc6bc008980] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6bc008980] Successfully connected to 127.0.0.1 port 1935 2023/04/26 00:24:53 [h264_mp4toannexb.consumer_0:3] Source failed (no more tracks) stopping output... 2023/04/26 00:24:53 [switch_0:3] Switch to h264_mp4toannexb.producer_1 with forgetful transition. 2023/04/26 00:24:53 [source:4] Source replay_metadata_0 gets up with content kind: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/04/26 00:24:53 [replay_metadata_0:4] Content type is {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. [rtmp @ 0x7fc6bc0082c0] Server error: No such stream 2023/04/26 00:24:53 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b0035940] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b0035940] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7fc6b040cb00] Server error: No such stream 2023/04/26 00:24:56 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b0006fc0] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b0006fc0] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7fc6b040cb00] Server error: No such stream 2023/04/26 00:24:58 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b0035940] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b0035940] Successfully connected to 127.0.0.1 port 1935 2023/04/26 00:25:00 [decoder:4] Decoding "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4" ended: Ffmpeg_decoder.End_of_file. 2023/04/26 00:25:00 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "decoder/ffmpeg_decoder.ml", line 698, characters 12-29 2023/04/26 00:25:00 [decoder:4] Called from Decoder.mk_decoder.fill in file "decoder/decoder.ml", line 506, characters 10-31 2023/04/26 00:25:00 [decoder:4] [rtmp @ 0x7fc6b040cb00] Server error: No such stream 2023/04/26 00:25:00 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [AVIOContext @ 0x7fc6cc00ae80] 2023/04/26 00:25:00 [single_0:4] Finished with "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4". Statistics: 4281926 bytes read, 0 seeks [h264 @ 0x7fc6b40c25c0] Reinit context to 1280x720, pix_fmt: yuv420p [AVIOContext @ 0x7fc6b564f900] Statistics: 65536 bytes read, 0 seeks [h264 @ 0x7fc6b40c3c40] Reinit context to 1280x720, pix_fmt: yuv420p 2023/04/26 00:25:00 [single_0:3] Prepared "/var/www/html/storage/app/fallback/mljqo2an/fallback.mp4" (RID 0). [tcp @ 0x7fc6b0006fc0] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b0006fc0] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7fc6b040cb00] Server error: No such stream 2023/04/26 00:25:02 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b0035940] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b0035940] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7fc6b040cb00] Server error: No such stream 2023/04/26 00:25:04 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7fc6b0006fc0] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7fc6b0006fc0] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7fc6b040cb00] Server error: No such stream 2023/04/26 00:25:07 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) ^C2023/04/26 00:25:08 [main:3] Shutdown started! 2023/04/26 00:25:08 [main:3] Waiting for main threads to terminate... 2023/04/26 00:25:08 [threads:4] Waiting for thread clock_main to shutdown 2023/04/26 00:25:08 [source:4] Source output.url gets down. [flv @ 0x7fc6cc3aa440] Failed to update header with correct duration. [flv @ 0x7fc6cc3aa440] Failed to update header with correct filesize. [AVIOContext @ 0x7fc6cc16f400] Statistics: 0 seeks, 4470 writeouts 2023/04/26 00:25:08 [source:4] Source aac_adtstoasc.producer_0 gets down. 2023/04/26 00:25:08 [clock.main:3] Streaming loop stopped. 2023/04/26 00:25:08 [threads:4] Thread "clock_main" terminated (0 remaining). 2023/04/26 00:25:08 [main:3] Main threads terminated. 2023/04/26 00:25:08 [threads:3] Shutting down scheduler... 2023/04/26 00:25:08 [threads:4] Thread "non-blocking queue #2" terminated (3 remaining). 2023/04/26 00:25:08 [threads:4] Thread "generic queue #2" terminated (2 remaining). 2023/04/26 00:25:08 [threads:4] Thread "non-blocking queue #1" terminated (1 remaining). 2023/04/26 00:25:08 [threads:4] Thread "generic queue #1" terminated (0 remaining). 2023/04/26 00:25:08 [threads:3] Scheduler shut down. 2023/04/26 00:25:08 [main:3] Cleaning downloaded files... 2023/04/26 00:25:08 [main:3] Freeing memory... ```
TheRealMattLear commented 1 year ago

@toots the problem does not seem to occur if I am to comment out bothh264_mp4toannexb bitstream filters

TheRealMattLear commented 1 year ago

I've done some additional tests that may help you get to the bottom of this:

TESTS - 3 repeats each - 30 second live broadcast w/30 second gap between connections

liquidsoap crash output ``` 2023/05/02 09:06:37 [source:4] Source replay_metadata_16 gets up with content kind: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/05/02 09:06:37 [replay_metadata_16:4] Content type is {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. [rtmp @ 0x7f215000b6c0] Server error: No such stream 2023/05/02 09:06:38 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7f21409426c0] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7f21409426c0] Successfully connected to 127.0.0.1 port 1935 [rtmp @ 0x7f21403b3880] Server error: No such stream 2023/05/02 09:06:40 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Operation not permitted) [tcp @ 0x7f2140093580] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7f2140093580] Successfully connected to 127.0.0.1 port 1935 2023/05/02 09:06:43 [decoder:4] Decoding "/var/www/html/fallback.mp4" ended: Ffmpeg_decoder.End_of_file. 2023/05/02 09:06:43 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "decoder/ffmpeg_decoder.ml", line 698, characters 12-29 2023/05/02 09:06:43 [decoder:4] Called from Decoder.mk_decoder.fill in file "decoder/decoder.ml", line 506, characters 10-31 2023/05/02 09:06:43 [decoder:4] 2023/05/02 09:06:43 [single_0:4] Finished with "/var/www/html/fallback.mp4". [AVIOContext @ 0x7f214542d880] Statistics: 4281926 bytes read, 0 seeks [h264 @ 0x7f2144dfc640] Reinit context to 1280x720, pix_fmt: yuv420p [h264 @ 0x7f21407a8200] Reinit context to 1280x720, pix_fmt: yuv420p [AVIOContext @ 0x7f2145413c40] Statistics: 65536 bytes read, 0 seeks [h264 @ 0x7f2144b67a00] Reinit context to 1280x720, pix_fmt: yuv420p 2023/05/02 09:06:43 [single_0:3] Prepared "/var/www/html/fallback.mp4" (RID 0). [h264 @ 0x7f21407a8200] Increasing reorder buffer to 1 [flv @ 0x7f21443c7c40] 2023/05/02 09:06:43 [output.url:4] Error while encoding data: Avutil.Error(Broken pipe) 2023/05/02 09:06:43 [output.url:4] Raised by primitive operation at Stdlib__List.iter in file "list.ml", line 110, characters 12-15 2023/05/02 09:06:43 [output.url:4] Called from Stdlib__Option.map in file "option.ml", line 24, characters 57-62 2023/05/02 09:06:43 [output.url:4] Called from Ffmpeg_encoder_common.encode in file "encoder/ffmpeg_encoder_common.ml", line 105, characters 4-80 2023/05/02 09:06:43 [output.url:4] Called from Ffmpeg_encoder_common.encoder.encode in file "encoder/ffmpeg_encoder_common.ml", line 226, characters 4-44 2023/05/02 09:06:43 [output.url:4] Called from Pipe_output.url_output#encode in file "outputs/pipe_output.ml", line 177, characters 22-48 2023/05/02 09:06:43 [output.url:4] Failed to update header with correct duration. [flv @ 0x7f21443c7c40] Failed to update header with correct filesize. [AVIOContext @ 0x7f2144cc1b00] Statistics: 0 seeks, 3731 writeouts 2023/05/02 09:06:43 [output.url:3] Will try again in 2.00 seconds. 2023/05/02 09:06:44 [decoder.ffmpeg:4] ffmpeg recognizes "rtmp://127.0.0.1:1935/static/liveinput" as: audio: {codec: aac, 48000Hz, 2 channel(s)}, video: {codec: h264, 1280x720, yuv420p} and content-type: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/05/02 09:06:44 [switch_0:3] Switch to input.ffmpeg_0 with transition. 2023/05/02 09:06:44 [source:4] Source replay_metadata_16 gets down. 2023/05/02 09:06:44 [source:4] Source replay_metadata_17 gets up with content kind: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/05/02 09:06:44 [replay_metadata_17:4] Content type is {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/05/02 09:06:45 [clock.main:2] Source output.url failed while streaming: Invalid_argument("option is None")! 2023/05/02 09:06:45 [clock.main:2] Raised at Stdlib.invalid_arg in file "stdlib.ml", line 30, characters 20-45 2023/05/02 09:06:45 [clock.main:2] Called from Stdlib__Option.get in file "option.ml" (inlined), line 21, characters 41-69 2023/05/02 09:06:45 [clock.main:2] Called from Pipe_output.base#insert_metadata in file "outputs/pipe_output.ml", line 82, characters 31-51 2023/05/02 09:06:45 [clock.main:2] Called from Output.encoded#send_frame.output_chunks.f in file "outputs/output.ml", line 243, characters 24-76 2023/05/02 09:06:45 [clock.main:2] Called from Output.output#output in file "outputs/output.ml", line 174, characters 10-35 2023/05/02 09:06:45 [clock.main:2] Called from Clock.clock#end_tick.(fun) in file "clock.ml", line 300, characters 14-22 2023/05/02 09:06:45 [clock.main:2] 2023/05/02 09:06:45 [source:4] Source output.url gets down. 2023/05/02 09:06:45 [source:4] Source aac_adtstoasc.producer_0 gets down. 2023/05/02 09:06:45 [main:3] Shutdown started! ```
TheRealMattLear commented 1 year ago

I've made some progress here @toots. Adding the aac_adtstoasc filter AFTER each h264_mp4toannexb seems to solve the problem:

liquidsoap filters on each stream ``` log.level.set(4) settings.log.file.set(false); settings.init.allow_root.set(true); settings.ffmpeg.log.verbosity.set("verbose") settings.ffmpeg.content.copy.relaxed_compatibility_check.set(true) live_stream = input.rtmp(listen=false,"rtmp://127.0.0.1:1935/static/live"); live_stream = ffmpeg.filter.bitstream.h264_mp4toannexb(live_stream) live_stream = ffmpeg.filter.bitstream.aac_adtstoasc(live_stream) fallback_video = single("/root/fallback.mp4"); fallback_video = ffmpeg.filter.bitstream.h264_mp4toannexb(fallback_video) fallback_video = ffmpeg.filter.bitstream.aac_adtstoasc(fallback_video) s = fallback(track_sensitive=false,[live_stream,fallback_video]) flv = %ffmpeg( format="flv", # fflags="no_duration_filesize", %audio.copy, %video.copy) output.url( fallible=true, url="rtmp://127.0.0.1:1935/output/live", flv, s ) ```

Just the same, removing the filters on the individual inputs and applying at the end of the script seems to also be successful:

liquidsoap config - single filter group ``` log.level.set(4) settings.log.file.set(false); settings.init.allow_root.set(true); settings.ffmpeg.log.verbosity.set("verbose") settings.ffmpeg.content.copy.relaxed_compatibility_check.set(true) live_stream = input.rtmp(listen=false,"rtmp://127.0.0.1:1935/static/live"); fallback_video = single("/root/fallback.mp4"); s = fallback(track_sensitive=false,[live_stream,fallback_video]) s = ffmpeg.filter.bitstream.h264_mp4toannexb(s) s = ffmpeg.filter.bitstream.aac_adtstoasc(s) flv = %ffmpeg( format="flv", # fflags="no_duration_filesize", %audio.copy, %video.copy) output.url( fallible=true, url="rtmp://127.0.0.1:1935/output/live", flv, s ) ```

Important note, if h264_mp4toannexb came after the aac_adtstoasc filter then i'd see a fairly consistent output.url failed upon the live input disconnection.

Now very last point. If I have the filters on a per stream basis, then i'm seeing the following error on the live input disconnection, however, and here's the catch, the output destination never actually goes down (VLC reports no disconnection at the output url, nor do the nginx-rtmp server logs):

liquidsoap output ``` 2023/05/02 10:16:53 [decoder.ffmpeg:4] ffmpeg recognizes "rtmp://127.0.0.1/static/mljqo2an" as: audio: {codec: aac, 48000Hz, 2 channel(s)}, video: {codec: h264, 1280x720, yuv420p} and content-type: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/05/02 10:16:53 [switch_1:3] Switch to aac_adtstoasc.producer_0 with transition. 2023/05/02 10:16:53 [source:4] Source replay_metadata_2 gets down. 2023/05/02 10:16:53 [source:4] Source replay_metadata_3 gets up with content kind: {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. 2023/05/02 10:16:53 [replay_metadata_3:4] Content type is {audio=ffmpeg.audio.copy(sample_rate=48000,sample_format=fltp,channel_layout="stereo",codec="aac"),video=ffmpeg.video.copy(pixel_format=yuv420p,aspect_ratio=1/1,height=720,width=1280,codec="h264"),midi=none}. [AVIOContext @ 0x7f381cb69600] 2023/05/02 10:17:03 [input.ffmpeg_0:4] Feeding failed: Avutil.Error(Input/output error) 2023/05/02 10:17:03 [input.ffmpeg_0:4] Raised by primitive operation at Av.read_input in file "av/av.ml", line 220, characters 2-31 2023/05/02 10:17:03 [input.ffmpeg_0:4] Called from Ffmpeg_decoder.mk_decoder.(fun).f in file "decoder/ffmpeg_decoder.ml", line 669, characters 10-99 2023/05/02 10:17:03 [input.ffmpeg_0:4] Re-raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "decoder/ffmpeg_decoder.ml", line 702, characters 12-48 2023/05/02 10:17:03 [input.ffmpeg_0:4] Called from Ffmpeg_io.input#get_frame in file "io/ffmpeg_io.ml", line 190, characters 10-24 2023/05/02 10:17:03 [input.ffmpeg_0:4] Statistics: 870019 bytes read, 0 seeks [tcp @ 0x7f381400df80] Starting connection attempt to 127.0.0.1 port 1935 [tcp @ 0x7f381400df80] Successfully connected to 127.0.0.1 port 1935 2023/05/02 10:17:03 [h264_mp4toannexb.consumer_0:3] Source failed (no more tracks) stopping output... 2023/05/02 10:17:03 [aac_adtstoasc.consumer_0:3] Source failed (no more tracks) stopping output... ```
toots commented 1 year ago

Great glad to hear and thanks for the details. These issues can get very technical. I'm moving this to a discussion, feel free to follow-up if needed.