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.42k stars 130 forks source link

output.url to rtmp destination not working and triggering multiple connections #2850

Closed TheRealMattLear closed 1 year ago

TheRealMattLear commented 1 year ago

Describe the bug After the initial connection to output.url liquidsoap appears to be sending subsequent connection attempts in liquidsoap 2.1.3 and 2.1.4 (2.1.4+git@f845354f8). It doesn't seem that data is sent to the output.url either. The same script with 2.1.2 is successful.

To Reproduce

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

s = input.rtmp(listen=true,"rtmp://0.0.0.0:19350/live/test")
output.url(fallible=true, url="rtmp://127.0.0.1:1935/output/test", %ffmpeg(format="flv", %audio.copy, %video.copy), s)

Results in 

2023/01/13 07:56:11 [video.converter:3] Using preferred video converter: ffmpeg.
2023/01/13 07:56:11 [audio.converter:3] Using samplerate converter: libsamplerate.
2023/01/13 07:56:11 [clock:4] Currently 1 clock(s) allocated.
2023/01/13 07:56:11 [clock.main:4] Starting 2 source(s)...
2023/01/13 07:56:11 [source:4] Source input.ffmpeg_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}.
2023/01/13 07:56:11 [source:4] Source output.file_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}.
2023/01/13 07:56:11 [output.url:4] Content type is {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}.
2023/01/13 07:56:11 [threads:4] Created thread "clock_main" (1 total).
2023/01/13 07:56:11 [clock:4] Main phase starts.
2023/01/13 07:56:11 [threads:4] Created thread "generic queue #1" (1 total).
2023/01/13 07:56:11 [threads:4] Created thread "generic queue #2" (2 total).
2023/01/13 07:56:11 [threads:4] Created thread "non-blocking queue #1" (3 total).
2023/01/13 07:56:11 [threads:4] Created thread "non-blocking queue #2" (4 total).
2023/01/13 07:56:11 [video.text:3] Using camlimages implementation
2023/01/13 07:56:11 [clock.main:3] Streaming loop starts in auto-sync mode
2023/01/13 07:56:11 [clock.main:3] Delegating synchronisation to CPU clock
[tcp @ 0x7f2eb8006340] Starting connection attempt to 127.0.0.1 port 1935
[tcp @ 0x7f2eb8006340] Successfully connected to 127.0.0.1 port 1935
[h264 @ 0x7f2ec0017c00] Reinit context to 1280x720, pix_fmt: yuv420p
[h264 @ 0x7f2ec0017c00] Increasing reorder buffer to 1
2023/01/13 07:56:40 [decoder.ffmpeg:4] ffmpeg recognizes "rtmp://0.0.0.0:19350/live/test" 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}.
[tcp @ 0x7f2eb8100e40] Starting connection attempt to 127.0.0.1 port 1935
[tcp @ 0x7f2eb8100e40] Successfully connected to 127.0.0.1 port 1935
[rtmp @ 0x7f2eb8100780] Server error: Already publishing
2023/01/13 07:56:40 [output.url:4] Error while streaming: Avutil.Error(Operation not permitted)
2023/01/13 07:56:40 [output.url:4] Raised by primitive operation at Av.open_output in file "av/av.ml", line 250, characters 20-77
2023/01/13 07:56:40 [output.url:4] Called from Ffmpeg_encoder_common.encoder.make in file "encoder/ffmpeg_encoder_common.ml", line 142, characters 22-62
2023/01/13 07:56:40 [output.url:4] Called from Ffmpeg_encoder_common.encoder in file "encoder/ffmpeg_encoder_common.ml", line 160, characters 20-29
2023/01/13 07:56:40 [output.url:4] Called from Pipe_output.base#start in file "outputs/pipe_output.ml", line 63, characters 22-32
2023/01/13 07:56:40 [output.url:4] Called from Pipe_output.url_output#restartify in file "outputs/pipe_output.ml", line 136, characters 24-29
2023/01/13 07:56:40 [output.url:4]
2023/01/13 07:56:40 [output.url:3] Will try to reconnect in 2.00 seconds.
2023/01/13 07:56:40 [output.url:4] Error while streaming: Invalid_argument("option is None")
2023/01/13 07:56:40 [output.url:4] Raised at Stdlib.invalid_arg in file "stdlib.ml", line 30, characters 20-45
2023/01/13 07:56:40 [output.url:4] Called from Stdlib__Option.get in file "option.ml" (inlined), line 21, characters 41-69
2023/01/13 07:56:40 [output.url:4] Called from Pipe_output.base#encode in file "outputs/pipe_output.ml", line 69, characters 16-34
2023/01/13 07:56:40 [output.url:4] Called from Output.encoded#send_frame.output_chunks.f in file "outputs/output.ml", line 239, characters 21-59
2023/01/13 07:56:40 [output.url:4] Called from Output.output#output in file "outputs/output.ml", line 174, characters 10-35
2023/01/13 07:56:40 [output.url:4] Called from Pipe_output.url_output#restartify in file "outputs/pipe_output.ml", line 136, characters 24-29
2023/01/13 07:56:40 [output.url:4]
2023/01/13 07:56:40 [output.url:3] Will try to reconnect in 2.00 seconds.
[tcp @ 0x7f2eb812b600] Starting connection attempt to 127.0.0.1 port 1935
[tcp @ 0x7f2eb812b600] Successfully connected to 127.0.0.1 port 1935
[rtmp @ 0x7f2eb812af40] Server error: Already publishing

receiving service is nginx-rtmp with simple config:


rtmp {
    server {
        listen 1935;
        application output {
            live on;
            idle_streams off;
            wait_key on;
            wait_video on;
            drop_idle_publisher 10s;
        }
    }
}
toots commented 1 year ago

This should be fixed in the latest rolling release. Mind trying there?

TheRealMattLear commented 1 year ago

@toots sorry to report i'm seeing the same issue here with the script published above.

Interestingly, it seems that the first connection to the output is made before i even connect an encoder to rtmp://0.0.0.0:19350/live/test

2023/02/01 04:38:38 >>> LOG START
2023/02/01 04:38:35 [main:3] Liquidsoap 2.1.4+git@9fde65302
2023/02/01 04:38:35 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] posix-time2=2.0.0 pcre=7.5.0 sedlex=3.0 menhirLib=20220210 curl=0.9.2 uri=4.2.0 memtrace=v0.2.2 mem_usage=0.0.4 dtools=0.4.4 duppy=0.9.3 cry=0.6.8 mm=0.8.2 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.2 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.6 bjack=0.1.6 alsa=0.3.0 ao=0.2.4 samplerate=0.1.6 taglib=0.3.10 ssl=0.5.11 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.5 ladspa=0.2.2 dssi=0.1.5 tsdl=v0.9.9 tsdl-ttf=0.3.2 tsdl-image=0.3.2 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/02/01 04:38:35 [main:3]
2023/02/01 04:38:35 [main:3] DISCLAIMER: This version of Liquidsoap has been
2023/02/01 04:38:35 [main:3] compiled from a snapshot of the development code.
2023/02/01 04:38:35 [main:3] As such, it should not be used in production
2023/02/01 04:38:35 [main:3] unless you know what you are doing!
2023/02/01 04:38:35 [main:3]
2023/02/01 04:38:35 [main:3] We are, however, very interested in any feedback
2023/02/01 04:38:35 [main:3] about our development code and committed to fix
2023/02/01 04:38:35 [main:3] issues as soon as possible.
2023/02/01 04:38:35 [main:3]
2023/02/01 04:38:35 [main:3] If you are interested in collaborating to
2023/02/01 04:38:35 [main:3] the development of Liquidsoap, feel free to
2023/02/01 04:38:35 [main:3] drop us a mail at <savonet-devl@lists.sf.net>
2023/02/01 04:38:35 [main:3] or to join the slack chat at <http://slack.liquidsoap.info>.
2023/02/01 04:38:35 [main:3]
2023/02/01 04:38:35 [main:3] Please send any bug report or feature request
2023/02/01 04:38:35 [main:3] at <https://github.com/savonet/liquidsoap/issues>.
2023/02/01 04:38:35 [main:3]
2023/02/01 04:38:35 [main:3] We hope you enjoy this snapshot build of Liquidsoap!
2023/02/01 04:38:35 [main:3]
2023/02/01 04:38:35 [clock:3] Using native (high-precision) implementation for latency control
2023/02/01 04:38:38 [frame:4] frame.audio.samplerate set to: 44100
2023/02/01 04:38:38 [frame:4] frame.video.framerate set to: 25
2023/02/01 04:38:38 [frame:4] frame.audio.channels set to: 2
2023/02/01 04:38:38 [frame:4] frame.video.default set to: false
2023/02/01 04:38:38 [frame:4] frame.midi.channels set to: 0
2023/02/01 04:38:38 [frame:4] frame.video.width set to: 1280
2023/02/01 04:38:38 [frame:4] frame.video.height set to: 720
2023/02/01 04:38:38 [frame:4] frame.audio.samplerate set to: 44100
2023/02/01 04:38:38 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2023/02/01 04:38:38 [frame:3] Video frame size set to: 1280x720
2023/02/01 04:38:38 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2023/02/01 04:38:38 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2023/02/01 04:38:38 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2023/02/01 04:38:38 [sandbox:3] Sandboxing disabled
2023/02/01 04:38:38 [video.converter:3] Using preferred video converter: ffmpeg.
2023/02/01 04:38:38 [audio.converter:3] Using samplerate converter: libsamplerate.
2023/02/01 04:38:38 [clock:4] Currently 1 clock(s) allocated.
2023/02/01 04:38:38 [clock.main:4] Starting 2 source(s)...
2023/02/01 04:38:38 [source:4] Source input.ffmpeg_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}.
2023/02/01 04:38:38 [source:4] Source output.file_0 gets up with content kind: {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}.
2023/02/01 04:38:38 [output.url:4] Content type is {audio=ffmpeg.audio.copy,video=ffmpeg.video.copy,midi=none}.
2023/02/01 04:38:38 [threads:4] Created thread "clock_main" (1 total).
2023/02/01 04:38:38 [clock:4] Main phase starts.
2023/02/01 04:38:38 [threads:4] Created thread "generic queue #1" (1 total).
2023/02/01 04:38:38 [threads:4] Created thread "generic queue #2" (2 total).
2023/02/01 04:38:38 [threads:4] Created thread "non-blocking queue #1" (3 total).
2023/02/01 04:38:38 [threads:4] Created thread "non-blocking queue #2" (4 total).
2023/02/01 04:38:38 [video.text:3] Using camlimages implementation
2023/02/01 04:38:38 [clock.main:3] Streaming loop starts in auto-sync mode
2023/02/01 04:38:38 [clock.main:3] Delegating synchronisation to CPU clock
[tcp @ 0x7f9864006340] Starting connection attempt to 127.0.0.1 port 1935
[tcp @ 0x7f9864006340] Successfully connected to 127.0.0.1 port 1935
[h264 @ 0x7f986c017cc0] Reinit context to 1280x720, pix_fmt: yuv420p
2023/02/01 04:39:01 [decoder.ffmpeg:4] ffmpeg recognizes "rtmp://0.0.0.0:19350/live/test" 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}.
[tcp @ 0x7f9864011040] Starting connection attempt to 127.0.0.1 port 1935
[tcp @ 0x7f9864011040] Successfully connected to 127.0.0.1 port 1935
[rtmp @ 0x7f9864008500] Server error: Already publishing
2023/02/01 04:39:01 [output.url:4] Error while streaming: Avutil.Error(Operation not permitted)
2023/02/01 04:39:01 [output.url:4] Raised by primitive operation at Av.open_output in file "av/av.ml", line 250, characters 20-77
2023/02/01 04:39:01 [output.url:4] Called from Ffmpeg_encoder_common.encoder.make in file "encoder/ffmpeg_encoder_common.ml", line 142, characters 22-62
2023/02/01 04:39:01 [output.url:4] Called from Ffmpeg_encoder_common.encoder in file "encoder/ffmpeg_encoder_common.ml", line 160, characters 20-29
2023/02/01 04:39:01 [output.url:4] Called from Pipe_output.base#start in file "outputs/pipe_output.ml", line 63, characters 22-32
2023/02/01 04:39:01 [output.url:4] Called from Pipe_output.url_output#restartify in file "outputs/pipe_output.ml", line 136, characters 24-29
2023/02/01 04:39:01 [output.url:4]
2023/02/01 04:39:01 [output.url:3] Will try to reconnect in 2.00 seconds.
2023/02/01 04:39:01 [output.url:4] Error while streaming: Invalid_argument("option is None")
2023/02/01 04:39:01 [output.url:4] Raised at Stdlib.invalid_arg in file "stdlib.ml", line 30, characters 20-45
2023/02/01 04:39:01 [output.url:4] Called from Stdlib__Option.get in file "option.ml" (inlined), line 21, characters 41-69
2023/02/01 04:39:01 [output.url:4] Called from Pipe_output.base#encode in file "outputs/pipe_output.ml", line 69, characters 16-34
2023/02/01 04:39:01 [output.url:4] Called from Output.encoded#send_frame.output_chunks.f in file "outputs/output.ml", line 239, characters 21-59
2023/02/01 04:39:01 [output.url:4] Called from Output.output#output in file "outputs/output.ml", line 174, characters 10-35
2023/02/01 04:39:01 [output.url:4] Called from Pipe_output.url_output#restartify in file "outputs/pipe_output.ml", line 136, characters 24-29
2023/02/01 04:39:01 [output.url:4]
2023/02/01 04:39:01 [output.url:3] Will try to reconnect in 2.00 seconds.
[tcp @ 0x7f9864126740] Starting connection attempt to 127.0.0.1 port 1935
[tcp @ 0x7f9864126740] Successfully connected to 127.0.0.1 port 1935
[rtmp @ 0x7f9864126240] Server error: Already publishing
2023/02/01 04:39:03 [output.url:4] Error while streaming: Avutil.Error(Operation not permitted)
2023/02/01 04:39:03 [output.url:4] Raised by primitive operation at Av.open_output in file "av/av.ml", line 250, characters 20-77
2023/02/01 04:39:03 [output.url:4] Called from Ffmpeg_encoder_common.encoder.make in file "encoder/ffmpeg_encoder_common.ml", line 142, characters 22-62
2023/02/01 04:39:03 [output.url:4] Called from Ffmpeg_encoder_common.encoder in file "encoder/ffmpeg_encoder_common.ml", line 160, characters 20-29
2023/02/01 04:39:03 [output.url:4] Called from Pipe_output.base#start in file "outputs/pipe_output.ml", line 63, characters 22-32
2023/02/01 04:39:03 [output.url:4] Called from Pipe_output.url_output#restartify in file "outputs/pipe_output.ml", line 133, characters 16-27
2023/02/01 04:39:03 [output.url:4]
2023/02/01 04:39:03 [output.url:3] Will try to reconnect in 2.00 seconds.
[tcp @ 0x7f98641168c0] Starting connection attempt to 127.0.0.1 port 1935
[tcp @ 0x7f98641168c0] Successfully connected to 127.0.0.1 port 1935
[rtmp @ 0x7f9864123040] Server error: Already publishing
2023/02/01 04:39:05 [output.url:4] Error while streaming: Avutil.Error(Operation not permitted)
2023/02/01 04:39:05 [output.url:4] Raised by primitive operation at Av.open_output in file "av/av.ml", line 250, characters 20-77
2023/02/01 04:39:05 [output.url:4] Called from Ffmpeg_encoder_common.encoder.make in file "encoder/ffmpeg_encoder_common.ml", line 142, characters 22-62
2023/02/01 04:39:05 [output.url:4] Called from Ffmpeg_encoder_common.encoder in file "encoder/ffmpeg_encoder_common.ml", line 160, characters 20-29
2023/02/01 04:39:05 [output.url:4] Called from Pipe_output.base#start in file "outputs/pipe_output.ml", line 63, characters 22-32
2023/02/01 04:39:05 [output.url:4] Called from Pipe_output.url_output#restartify in file "outputs/pipe_output.ml", line 133, characters 16-27
2023/02/01 04:39:05 [output.url:4]
2023/02/01 04:39:05 [output.url:3] Will try to reconnect in 2.00 seconds.
2023/02/01 04:39:06 [input.ffmpeg_0:4] Feeding failed: Avutil.Error(Input/output error)
2023/02/01 04:39:06 [input.ffmpeg_0:4] Raised by primitive operation at Av.read_input in file "av/av.ml", line 220, characters 2-31
2023/02/01 04:39:06 [input.ffmpeg_0:4] Called from Ffmpeg_decoder.mk_decoder.(fun).f in file "decoder/ffmpeg_decoder.ml", line 669, characters 10-99
2023/02/01 04:39:06 [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/02/01 04:39:06 [input.ffmpeg_0:4] Called from Ffmpeg_io.input#get_frame in file "io/ffmpeg_io.ml", line 190, characters 10-24
2023/02/01 04:39:06 [input.ffmpeg_0:4]
[AVIOContext @ 0x7f986c015f40] Statistics: 370609 bytes read, 0 seeks
^C2023/02/01 04:39:07 [main:3] Shutdown started!
2023/02/01 04:39:07 [main:3] Waiting for main threads to terminate...
2023/02/01 04:39:07 [threads:4] Waiting for thread clock_main to shutdown
2023/02/01 04:39:07 [source:4] Source output.url gets down.
2023/02/01 04:39:07 [source:4] Source input.ffmpeg_0 gets down.
2023/02/01 04:39:07 [clock.main:3] Streaming loop stopped.
2023/02/01 04:39:07 [threads:4] Thread "clock_main" terminated (0 remaining).
2023/02/01 04:39:07 [main:3] Main threads terminated.
2023/02/01 04:39:07 [threads:3] Shutting down scheduler...
2023/02/01 04:39:07 [threads:4] Thread "non-blocking queue #2" terminated (3 remaining).
2023/02/01 04:39:07 [threads:4] Thread "non-blocking queue #1" terminated (2 remaining).
2023/02/01 04:39:07 [threads:4] Thread "generic queue #1" terminated (1 remaining).
[rtmp @ 0x7f986c247080] Cannot open connection tcp://0.0.0.0:19350?listen&listen_timeout=-1000
2023/02/01 04:39:07 [input.ffmpeg_0:4] Connection failed: Avutil.Error(Immediate exit requested)
2023/02/01 04:39:07 [threads:4] Thread "generic queue #2" terminated (0 remaining).
2023/02/01 04:39:07 [threads:3] Scheduler shut down.
2023/02/01 04:39:07 [main:3] Cleaning downloaded files...
2023/02/01 04:39:07 [main:3] Freeing memory...
[AVIOContext @ 0x7f9864007780] Statistics: 0 seeks, 0 writeouts
toots commented 1 year ago

Fixed in 0d11087af9cd0000f7f010918109c0db7b4e931c and 96e990fee9f10f907ab65f01b65b30df8ca05f7b