search

AzuraCast / AzuraCast

A self-hosted web radio management suite, including turnkey installer tools for the full radio software stack and a modern, easy-to-use web app to manage your stations.
https://www.azuracast.com/
GNU Affero General Public License v3.0
3.06k stars 568 forks source link

Streamers Get Booted Immediately After Stream Start if MP3 Recording is Enabled. #5079

Closed FendleTruck closed 2 years ago

FendleTruck commented 2 years ago

Installation Method

Docker Installation

AzuraCast Release Channel

Rolling Release Channel

Current AzuraCast Version

Rolling Release #4f6c342

What happened?

When recording of live broadcasts is enabled, selecting MP3 as the format causes BUTT to lose connection after 5 seconds (I suspect immediately in reality).

Changing the format to OGG produces no such error.

Relevant log output


When using ogg:
2022/02/07 07:15:53 [lang:3] DJ Source connected! Last authenticated DJ: [removed authentication info], ("User-Agent", "butt 0.1.30"), ("Content-Type", "audio/mpeg"), ("ice-name", "no name"), ("ice-public", "0"), ("ice-audio-info", "ice-bitrate=128;ice-channels=2;ice-samplerate=48000"), ("Expect", "100-continue")]
2022/02/07 07:15:53 [lang:3] live_connected: Sending AzuraCast API DJ onConnect command...
2022/02/07 07:15:53 [lang:3] live_connected: AzuraCast API Response: /var/azuracast/stations/english/temp/Stream2/stream_20220207-071553.ogg
2022/02/07 07:15:53 [input_streamer:3] Decoding...
2022/02/07 07:15:57 [live_fallback:3] Switch to map_metadata_0 with transition.
2022/02/07 07:15:57 [map_metadata_0:3] Inserting missing metadata.
2022/02/07 07:16:58 [input_streamer:2] Feeding stopped: Mad.End_of_stream. (This is when I stopped streaming)

When using mp3:
2022/02/07 07:46:42 [lang:3] DJ Source connected! Last authenticated DJ: [removed authentication info], ("User-Agent", "butt 0.1.30"), ("Content-Type", "audio/mpeg"), ("ice-name", "no name"), ("ice-public", "0"), ("ice-audio-info", "ice-bitrate=128;ice-channels=2;ice-samplerate=48000"), ("Expect", "100-continue")]
2022/02/07 07:46:42 [lang:3] live_connected: Sending AzuraCast API DJ onConnect command...
2022/02/07 07:46:42 [lang:3] live_connected: AzuraCast API Response: /var/azuracast/stations/english/temp/Stream2/stream_20220207-074642.mp3
2022/02/07 07:46:42 [input_streamer:3] Decoding...
2022/02/07 07:46:47 [live_fallback:3] Switch to map_metadata_0 with transition.
2022/02/07 07:46:50 >>> LOG START
2022/02/07 07:46:48 [main:3] Liquidsoap 2.0.3+git@59795a50
2022/02/07 07:46:48 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.5.0 sedlex=2.5 menhirLib=20211128 curl=0.9.2 dtools=0.4.4 duppy=0.9.2 cry=0.6.6 mm=0.7.4 ogg=0.7.0 ogg.decoder=0.7.0 vorbis=0.8.0 vorbis.decoder=0.8.0 opus=0.2.1 opus.decoder=0.2.1 mad=0.5.2 flac=0.3.0 flac.ogg=0.3.0 flac.decoder=0.3.0 dynlink=[distributed with Ocaml] lame=0.3.5 frei0r=0.1.2 fdkaac=0.3.2 ffmpeg=1.1.1 samplerate=0.1.6 taglib=0.3.8 ssl=0.5.9 camomile=1.0.2 faad=0.5.0 ladspa=0.2.2
2022/02/07 07:46:48 [main:3] 
2022/02/07 07:46:48 [main:3] DISCLAIMER: This version of Liquidsoap has been
2022/02/07 07:46:48 [main:3] compiled from a snapshot of the development code.
2022/02/07 07:46:48 [main:3] As such, it should not be used in production
2022/02/07 07:46:48 [main:3] unless you know what you are doing!
2022/02/07 07:46:48 [main:3] 
2022/02/07 07:46:48 [main:3] We are, however, very interested in any feedback
2022/02/07 07:46:48 [main:3] about our development code and committed to fix
2022/02/07 07:46:48 [main:3] issues as soon as possible.
2022/02/07 07:46:48 [main:3] 
2022/02/07 07:46:48 [main:3] If you are interested in collaborating to
2022/02/07 07:46:48 [main:3] the development of Liquidsoap, feel free to
2022/02/07 07:46:48 [main:3] drop us a mail at <savonet-devl@lists.sf.net>
2022/02/07 07:46:48 [main:3] or to join the slack chat at <http://slack.liquidsoap.info>.
2022/02/07 07:46:48 [main:3] 
2022/02/07 07:46:48 [main:3] Please send any bug report or feature request
2022/02/07 07:46:48 [main:3] at <https://github.com/savonet/liquidsoap/issues>.
2022/02/07 07:46:48 [main:3] 
2022/02/07 07:46:48 [main:3] We hope you enjoy this snapshot build of Liquidsoap!
2022/02/07 07:46:48 [main:3] 
2022/02/07 07:46:49 [clock:3] Using builtin (low-precision) implementation for latency control
2022/02/07 07:46:50 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2022/02/07 07:46:50 [frame:3] Video frame size set to: 1280x720
2022/02/07 07:46:50 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2022/02/07 07:46:50 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2022/02/07 07:46:50 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2022/02/07 07:46:50 [sandbox:3] Running inside a docker container, disabling sandboxing.
2022/02/07 07:46:50 [video.converter:3] Using preferred video converter: ffmpeg.
2022/02/07 07:46:50 [audio.converter:3] Using samplerate converter: ffmpeg.
2022/02/07 07:46:50 [harbor:3] Adding mountpoint '/' on port 8045
2022/02/07 07:46:51 [error_jingle:3] /usr/local/share/icecast/web/error.mp3 is static, resolving once for all...
2022/02/07 07:46:51 [error_jingle:3] Prepared "/usr/local/share/icecast/web/error.mp3" (RID 1).
2022/02/07 07:46:51 [local_1:3] Connecting mount /radio.mp3 for source@127.0.0.1...
2022/02/07 07:46:51 [local_1:3] Connection setup was successful.
2022/02/07 07:46:51 [lang:3] autodj_next_song: Sending AzuraCast API Call...
2022/02/07 07:46:51 [clock.main:3] Streaming loop starts in auto-sync mode
2022/02/07 07:46:51 [clock.main:3] Delegating synchronisation to CPU clock
[mp3 @ 0x7fe17c006100] Estimating duration from bitrate, this may be inaccurate
2022/02/07 07:46:51 [output.file_0:3] Source failed (no more tracks) stopping output...
2022/02/07 07:46:51 [safe_fallback:3] Switch to error_jingle.
Vaalyn commented 2 years ago

This should be fixed as of the Rolling-Release update I pushed yesterday: https://github.com/AzuraCast/docker-azuracast-radio/pull/15

FendleTruck commented 2 years ago

This should be fixed as of the Rolling-Release update I pushed yesterday: AzuraCast/docker-azuracast-radio#15

Updated to latest rolling release (983b6c5), same issue, different log info:

When recording to MP3:

2022/02/07 14:52:27 [lang:3] DJ Source connected! Last authenticated DJ: Stream1 - [removed, ("User-Agent", "butt 0.1.30"), ("Content-Type", "audio/mpeg"), ("ice-name", "no name"), ("ice-public", "0"), ("ice-audio-info", "ice-bitrate=128;ice-channels=2;ice-samplerate=48000"), ("Expect", "100-continue")]
2022/02/07 14:52:27 [lang:3] API djon - Sending POST request to 'http://web/api/internal/1/djon' with body: { "user": "Stream1" }
2022/02/07 14:52:27 [lang:3] API djon - Response (200): /var/azuracast/stations/teststation/temp/Stream1/stream_20220207-145227.mp3
2022/02/07 14:52:27 [input_streamer:3] Decoding...
2022/02/07 14:52:27 [next_song:3] Prepared "/var/azuracast/stations/teststation/media/Track 1.mp3" (RID 28).
2022/02/07 14:52:27 [lang:3] AutoDJ is ready!
Invalid return value 0 for stream protocol
Invalid return value 0 for stream protocol
Invalid return value 0 for stream protocol
Invalid return value 0 for stream protocol
2022/02/07 14:52:31 [input_streamer:2] Feeding stopped: Ffmpeg_decoder.End_of_file.
2022/02/07 14:52:31 [lang:3] API djoff - Sending POST request to 'http://web/api/internal/1/djoff' with body: { "user": "Stream1" }
2022/02/07 14:52:31 [lang:3] API djoff - Response (200): true

When recording to OGG:

2022/02/07 14:54:54 [lang:3] DJ Source connected! Last authenticated DJ: Stream1 - [removed, ("User-Agent", "butt 0.1.30"), ("Content-Type", "audio/mpeg"), ("ice-name", "no name"), ("ice-public", "0"), ("ice-audio-info", "ice-bitrate=128;ice-channels=2;ice-samplerate=48000"), ("Expect", "100-continue")]
2022/02/07 14:54:54 [lang:3] API djon - Sending POST request to 'http://web/api/internal/1/djon' with body: { "user": "Stream1" }
2022/02/07 14:54:54 [lang:3] API djon - Response (200): /var/azuracast/stations/teststation/temp/Stream1/stream_20220207-145454.ogg
2022/02/07 14:54:54 [input_streamer:3] Decoding...
2022/02/07 14:54:59 [live_fallback:3] Switch to map_metadata_0 with transition.
Invalid return value 0 for stream protocol
Invalid return value 0 for stream protocol
Invalid return value 0 for stream protocol
2022/02/07 14:55:30 [input_streamer:2] Feeding stopped: Ffmpeg_decoder.End_of_file.
2022/02/07 14:55:30 [lang:3] API djoff - Sending POST request to 'http://web/api/internal/1/djoff' with body: { "user": "Stream1" }
2022/02/07 14:55:30 [lang:3] API djoff - Response (200): true

Looks about the same, right around the map_metadata_0 things fall apart.

Vaalyn commented 2 years ago

Can verify this on my test server.

I have created a GH issue on the Liquidsoap repository including some detailed traces made with gdb: savonet/ocaml-taglib#11

Thank you for your report. We will get this figured out 👍

FendleTruck commented 2 years ago

I'm surprised I found a real bug, and not just a mistake on my part.

Exciting!

Vaalyn commented 2 years ago

Thank you again for your report.

The fix for this bug is now merged. 👍

FendleTruck commented 2 years ago

Awesome, working perfectly on my server now!

Thank you!