search

azlux / botamusique

Bot to play youtube / soundcloud / radio / local music on Mumble (using pymumble).
MIT License
311 stars 79 forks source link

Some radios cause the bot to remain stuck #223

Closed Elinvention closed 3 years ago

Elinvention commented 3 years ago

Describe the bug Some radios cause the bot to remain stuck

Affected version latest docker

To Reproduce Steps to reproduce the behavior:

  1. !rbplay 54270e37-880f-11e9-aa30-52543be04c81
  2. wait and hope
  3. radio doesn't start
  4. !clear, !skip, !stop, !play, web interface can't start the radio nor any other track

Expected behavior Be able to listen to KBS

Desktop (please complete the following information):

TerryGeng commented 3 years ago

Looks like you are having trouble accessing this specific radio station. Can you try some other radio stations?

Elinvention commented 3 years ago

Yes, all KBS radios have this issue. Other radios work fine. They might have something different that botamusique doesn't like. However botamusique should handle this gracefully and not require a restart to play the next song.

TerryGeng commented 3 years ago

Can you start the bot in verbose mode by adding "-v" parameter to it and examine the log when you "!rbplay"?

Elinvention commented 3 years ago

How can I do that with docker?

TerryGeng commented 3 years ago

I'm not an expert on docker.... Maybe @azlux knows how.

azlux commented 3 years ago

Should be docker run -it azlux/botamusique /botamusique/venv/bin/python mumbleBot.py -v

Elinvention commented 3 years ago

With that command I get this error:

[2020-11-16 18:22:14,496] > [MainThread] > [cache.py:109] library: rebuild directory cache
[2020-11-16 18:22:14,498] > [MainThread] > [mumbleBot.py:40] bot: botamusique version 7.1, starting...
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/botamusique/venv/lib/python3.8/site-packages/pymumble_py3/mumble.py", line 126, in run
    raise ConnectionRejectedError("Connection error with the Mumble (murmur) Server")
pymumble_py3.errors.ConnectionRejectedError: 'Connection error with the Mumble (murmur) Server'
TerryGeng commented 3 years ago

I think you need to specify the configuration file you are using in the command.

azlux commented 3 years ago 
XANA   | [Nov 18 10:38:21 INFO] bot: received command rbplay - 54270e37-880f-11e9-aa30-52543be04c81 by Azlux
XANA   | [Nov 18 10:38:24 INFO] cmd: Found url: http://live.kbskme.gscdn.com/www_1tv/_definst_/1tv_5.stream/playlist.m3u8

I see the radio is redirect to a m3u8 playlist instead of a direct radio stream. I wonder if it's a issue on radio-browser.info database.

TerryGeng commented 3 years ago

Looks like M3U8 is some of Apple's playlist formats. But the one azlux's log has shown is broken I think... It points to another m3u8 file inside and when I try to reach that file I got a 404.

Do we need to add M3U8 support?

Elinvention commented 3 years ago

I think M3U8 support is nice to have, however the main issue here is that the bot remains in an unresponsive state and is unable to recover unless I restart it.

TerryGeng commented 3 years ago

Sure... I think I'm going to put some safeguards in place. But can you help me validate the M3U8 file of that radio? Can you open it with other applications?

Elinvention commented 3 years ago

You are right, I tried with Shortwave and that specific radio appears to be broken. I made some tests with shortwave and botamusique.

These radios work with both shortwave and botamusique:

These radios work with shortwave, but not with botamusique:

These radios don't work with either:

I can test more if you want.

Elinvention commented 3 years ago

I was finally able to pass -v to botamusique with docker and your command was right, but I messed up by changing entrypoint :disappointed:. This is what happens with KBS 1R:

botamusique    | [2020-11-19 15:00:49,842] > [Thread-4] > [mumbleBot.py:262] bot: received command rbplay - 6d4a1b58-b7c6-11e9-acb2-52543be04c81 by Elinvention
botamusique    | [2020-11-19 15:00:49,843] > [Thread-4] > [command.py:452] cmd: Play a station by ID
botamusique    | [2020-11-19 15:00:49,843] > [Thread-4] > [command.py:458] cmd: Retreiving url for station ID 6d4a1b58-b7c6-11e9-acb2-52543be04c81
botamusique    | [2020-11-19 15:00:50,067] > [Thread-4] > [command.py:472] cmd: Added station to playlist KBS 1R
botamusique    | [2020-11-19 15:00:50,069] > [Thread-4] > [command.py:475] cmd: Found url: http://serpent0.duckdns.org:8088/kbs1radio.pls
botamusique    | [2020-11-19 15:00:50,070] > [Thread-4] > [cache.py:54] library: music found in database: [radio] KBS 1R (http://serpent0.duckdns.org:8088/kbs1radio.pls)
botamusique    | [2020-11-19 15:00:50,096] > [MainThread] > [mumbleBot.py:526] bot: next into the song: [radio] KBS 1R (http://serpent0.duckdns.org:8088/kbs1radio.pls)
botamusique    | [2020-11-19 15:00:50,097] > [MainThread] > [cache.py:81] library: music save into database: [radio] KBS 1R (http://serpent0.duckdns.org:8088/kbs1radio.pls)
botamusique    | [2020-11-19 15:00:50,171] > [Validating] > [playlist.py:223] playlist: start validating...
botamusique    | [2020-11-19 15:00:50,171] > [Validating] > [playlist.py:227] playlist: validating [radio] KBS 1R (http://serpent0.duckdns.org:8088/kbs1radio.pls)
botamusique    | [2020-11-19 15:00:50,171] > [Thread-4] > [command.py:478] cmd: add to playlist: [radio] KBS 1R (http://serpent0.duckdns.org:8088/kbs1radio.pls)
botamusique    | [2020-11-19 15:00:50,171] > [Validating] > [cache.py:81] library: music save into database: [radio] KBS 1R (http://serpent0.duckdns.org:8088/kbs1radio.pls)
botamusique    | [2020-11-19 15:00:50,171] > [Thread-4] > [mumbleBot.py:409] bot: Async download next asked 
botamusique    | [2020-11-19 15:00:50,185] > [Validating] > [playlist.py:243] playlist: validating finished.
botamusique    | [2020-11-19 15:00:50,209] > [MainThread] > [mumbleBot.py:379] bot: play music [radio] KBS 1R (http://serpent0.duckdns.org:8088/kbs1radio.pls)
botamusique    | [2020-11-19 15:00:50,209] > [MainThread] > [radio.py:65] radio: fetching radio server description
botamusique    | [2020-11-19 15:00:50,752] > [MainThread] > [radio.py:85] radio: unsuccessful attempts on fetching radio title (icy)
botamusique    | [2020-11-19 15:00:50,753] > [MainThread] > [mumbleBot.py:394] bot: execute ffmpeg command: ffmpeg -v debug -nostdin -i http://serpent0.duckdns.org:8088/kbs1radio.pls -ss 0.000000 -ac 2 -f s16le -ar 48000 -
botamusique    | [2020-11-19 15:00:50,762] > [MainThread] > [mumbleBot.py:409] bot: Async download next asked 
botamusique    | [2020-11-19 15:00:52,284] > [MainThread] > [mumbleBot.py:481] ffmpeg: ffmpeg version 4.1.6-1~deb10u1 Copyright (c) 2000-2020 the FFmpeg developers
botamusique    | [2020-11-19 15:00:52,384] > [MainThread] > [mumbleBot.py:481] ffmpeg:   built with gcc 8 (Debian 8.3.0-6)
botamusique    | [2020-11-19 15:00:52,485] > [MainThread] > [mumbleBot.py:481] ffmpeg:   configuration: --prefix=/usr --extra-version='1~deb10u1' --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --arch=amd64 --enable-gpl --disable-stripping --enable-avresample --disable-filter=resample --enable-avisynth --enable-gnutls --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libcodec2 --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libgme --enable-libgsm --enable-libjack --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librsvg --enable-librubberband --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libssh --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzmq --enable-libzvbi --enable-lv2 --enable-omx --enable-openal --enable-opengl --enable-sdl2 --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-chromaprint --enable-frei0r --enable-libx264 --enable-shared
botamusique    | [2020-11-19 15:00:52,585] > [MainThread] > [mumbleBot.py:481] ffmpeg:   libavutil      56. 22.100 / 56. 22.100
botamusique    | [2020-11-19 15:00:52,686] > [MainThread] > [mumbleBot.py:481] ffmpeg:   libavcodec     58. 35.100 / 58. 35.100
botamusique    | [2020-11-19 15:00:52,787] > [MainThread] > [mumbleBot.py:481] ffmpeg:   libavformat    58. 20.100 / 58. 20.100
botamusique    | [2020-11-19 15:00:52,887] > [MainThread] > [mumbleBot.py:481] ffmpeg:   libavdevice    58.  5.100 / 58.  5.100
botamusique    | [2020-11-19 15:00:52,988] > [MainThread] > [mumbleBot.py:481] ffmpeg:   libavfilter     7. 40.101 /  7. 40.101
botamusique    | [2020-11-19 15:00:53,088] > [MainThread] > [mumbleBot.py:481] ffmpeg:   libavresample   4.  0.  0 /  4.  0.  0
botamusique    | [2020-11-19 15:00:53,189] > [MainThread] > [mumbleBot.py:481] ffmpeg:   libswscale      5.  3.100 /  5.  3.100
botamusique    | [2020-11-19 15:00:53,289] > [MainThread] > [mumbleBot.py:481] ffmpeg:   libswresample   3.  3.100 /  3.  3.100
botamusique    | [2020-11-19 15:00:53,390] > [MainThread] > [mumbleBot.py:481] ffmpeg:   libpostproc    55.  3.100 / 55.  3.100
botamusique    | [2020-11-19 15:00:53,490] > [MainThread] > [mumbleBot.py:481] ffmpeg: Splitting the commandline.
botamusique    | [2020-11-19 15:00:53,591] > [MainThread] > [mumbleBot.py:481] ffmpeg: Reading option '-v' ... matched as option 'v' (set logging level) with argument 'debug'.
botamusique    | [2020-11-19 15:00:53,691] > [MainThread] > [mumbleBot.py:481] ffmpeg: Reading option '-nostdin' ... matched as option 'stdin' (enable or disable interaction on standard input) with argument 0.
botamusique    | [2020-11-19 15:00:53,792] > [MainThread] > [mumbleBot.py:481] ffmpeg: Reading option '-i' ... matched as input url with argument 'http://serpent0.duckdns.org:8088/kbs1radio.pls'.
botamusique    | [2020-11-19 15:00:53,892] > [MainThread] > [mumbleBot.py:481] ffmpeg: Reading option '-ss' ... matched as option 'ss' (set the start time offset) with argument '0.000000'.
botamusique    | [2020-11-19 15:00:53,993] > [MainThread] > [mumbleBot.py:481] ffmpeg: Reading option '-ac' ... matched as option 'ac' (set number of audio channels) with argument '2'.
botamusique    | [2020-11-19 15:00:54,093] > [MainThread] > [mumbleBot.py:481] ffmpeg: Reading option '-f' ... matched as option 'f' (force format) with argument 's16le'.
botamusique    | [2020-11-19 15:00:54,194] > [MainThread] > [mumbleBot.py:481] ffmpeg: Reading option '-ar' ... matched as option 'ar' (set audio sampling rate (in Hz)) with argument '48000'.
botamusique    | [2020-11-19 15:00:54,294] > [MainThread] > [mumbleBot.py:481] ffmpeg: Reading option '-' ... matched as output url.
botamusique    | [2020-11-19 15:00:54,395] > [MainThread] > [mumbleBot.py:481] ffmpeg: Finished splitting the commandline.
botamusique    | [2020-11-19 15:00:54,495] > [MainThread] > [mumbleBot.py:481] ffmpeg: Parsing a group of options: global .
botamusique    | [2020-11-19 15:00:54,596] > [MainThread] > [mumbleBot.py:481] ffmpeg: Applying option v (set logging level) with argument debug.
botamusique    | [2020-11-19 15:00:54,696] > [MainThread] > [mumbleBot.py:481] ffmpeg: Applying option nostdin (enable or disable interaction on standard input) with argument 0.
botamusique    | [2020-11-19 15:00:54,797] > [MainThread] > [mumbleBot.py:481] ffmpeg: Successfully parsed a group of options.
botamusique    | [2020-11-19 15:00:54,897] > [MainThread] > [mumbleBot.py:481] ffmpeg: Parsing a group of options: input url http://serpent0.duckdns.org:8088/kbs1radio.pls.
botamusique    | [2020-11-19 15:00:54,998] > [MainThread] > [mumbleBot.py:481] ffmpeg: Successfully parsed a group of options.
botamusique    | [2020-11-19 15:00:55,098] > [MainThread] > [mumbleBot.py:481] ffmpeg: Opening an input file: http://serpent0.duckdns.org:8088/kbs1radio.pls.
botamusique    | [2020-11-19 15:00:55,199] > [MainThread] > [mumbleBot.py:481] ffmpeg: [NULL @ 0x55c10936a880] Opening 'http://serpent0.duckdns.org:8088/kbs1radio.pls' for reading
botamusique    | [2020-11-19 15:00:55,299] > [MainThread] > [mumbleBot.py:481] ffmpeg: [http @ 0x55c10936b340] Setting default whitelist 'http,https,tls,rtp,tcp,udp,crypto,httpproxy'
botamusique    | [2020-11-19 15:00:55,400] > [MainThread] > [mumbleBot.py:481] ffmpeg: [tcp @ 0x55c10936d180] Original list of addresses:
botamusique    | [2020-11-19 15:00:55,501] > [MainThread] > [mumbleBot.py:481] ffmpeg: [tcp @ 0x55c10936d180] Address 112.150.126.35 port 8088
botamusique    | [2020-11-19 15:00:55,601] > [MainThread] > [mumbleBot.py:481] ffmpeg: [tcp @ 0x55c10936d180] Interleaved list of addresses:
botamusique    | [2020-11-19 15:00:55,702] > [MainThread] > [mumbleBot.py:481] ffmpeg: [tcp @ 0x55c10936d180] Address 112.150.126.35 port 8088
botamusique    | [2020-11-19 15:00:55,802] > [MainThread] > [mumbleBot.py:481] ffmpeg: [tcp @ 0x55c10936d180] Starting connection attempt to 112.150.126.35 port 8088
botamusique    | [2020-11-19 15:00:55,903] > [MainThread] > [mumbleBot.py:481] ffmpeg: [tcp @ 0x55c10936d180] Successfully connected to 112.150.126.35 port 8088
botamusique    | [2020-11-19 15:00:56,003] > [MainThread] > [mumbleBot.py:481] ffmpeg: [http @ 0x55c10936b340] request: GET /kbs1radio.pls HTTP/1.1
botamusique    | [2020-11-19 15:00:56,104] > [MainThread] > [mumbleBot.py:481] ffmpeg: User-Agent: Lavf/58.20.100
botamusique    | [2020-11-19 15:00:56,204] > [MainThread] > [mumbleBot.py:481] ffmpeg: Accept: */*
botamusique    | [2020-11-19 15:00:56,305] > [MainThread] > [mumbleBot.py:481] ffmpeg: Range: bytes=0-
botamusique    | [2020-11-19 15:00:56,405] > [MainThread] > [mumbleBot.py:481] ffmpeg: Connection: close
botamusique    | [2020-11-19 15:00:56,506] > [MainThread] > [mumbleBot.py:481] ffmpeg: Host: serpent0.duckdns.org:8088
botamusique    | [2020-11-19 15:00:56,606] > [MainThread] > [mumbleBot.py:481] ffmpeg: Icy-MetaData: 1
botamusique    | [2020-11-19 15:00:56,707] > [MainThread] > [mumbleBot.py:481] ffmpeg: 
botamusique    | [2020-11-19 15:00:56,808] > [MainThread] > [mumbleBot.py:481] ffmpeg: 
botamusique    | [2020-11-19 15:00:56,908] > [MainThread] > [mumbleBot.py:481] ffmpeg: [lrc @ 0x55c10936a880] Format lrc detected only with low score of 5, misdetection possible!
botamusique    | [2020-11-19 15:00:57,009] > [MainThread] > [mumbleBot.py:481] ffmpeg: [lrc @ 0x55c10936a880] Before avformat_find_stream_info() pos: 713 bytes read:713 seeks:0 nb_streams:1
botamusique    | [2020-11-19 15:00:57,109] > [MainThread] > [mumbleBot.py:481] ffmpeg: [lrc @ 0x55c10936a880] All info found
botamusique    | [2020-11-19 15:00:57,209] > [MainThread] > [mumbleBot.py:481] ffmpeg: [lrc @ 0x55c10936a880] After avformat_find_stream_info() pos: 713 bytes read:713 seeks:0 frames:0
botamusique    | [2020-11-19 15:00:57,310] > [MainThread] > [mumbleBot.py:481] ffmpeg: Input #0, lrc, from 'http://serpent0.duckdns.org:8088/kbs1radio.pls':
botamusique    | [2020-11-19 15:00:57,410] > [MainThread] > [mumbleBot.py:481] ffmpeg:   Duration: N/A, bitrate: N/A
botamusique    | [2020-11-19 15:00:57,511] > [MainThread] > [mumbleBot.py:481] ffmpeg:     Stream #0:0, 0, 1/1000: Subtitle: text
botamusique    | [2020-11-19 15:00:57,612] > [MainThread] > [mumbleBot.py:481] ffmpeg: Successfully opened the file.
botamusique    | [2020-11-19 15:00:57,712] > [MainThread] > [mumbleBot.py:481] ffmpeg: Parsing a group of options: output url -.
botamusique    | [2020-11-19 15:00:57,813] > [MainThread] > [mumbleBot.py:481] ffmpeg: Applying option ss (set the start time offset) with argument 0.000000.
botamusique    | [2020-11-19 15:00:57,913] > [MainThread] > [mumbleBot.py:481] ffmpeg: Applying option ac (set number of audio channels) with argument 2.
botamusique    | [2020-11-19 15:00:58,014] > [MainThread] > [mumbleBot.py:481] ffmpeg: Applying option f (force format) with argument s16le.
botamusique    | [2020-11-19 15:00:58,114] > [MainThread] > [mumbleBot.py:481] ffmpeg: Applying option ar (set audio sampling rate (in Hz)) with argument 48000.
botamusique    | [2020-11-19 15:00:58,215] > [MainThread] > [mumbleBot.py:481] ffmpeg: Successfully parsed a group of options.
botamusique    | [2020-11-19 15:00:58,315] > [MainThread] > [mumbleBot.py:481] ffmpeg: Opening an output file: -.
botamusique    | [2020-11-19 15:00:58,416] > [MainThread] > [mumbleBot.py:481] ffmpeg: Output #0, s16le, to 'pipe:':
botamusique    | [2020-11-19 15:00:58,517] > [MainThread] > [mumbleBot.py:481] ffmpeg: Output file #0 does not contain any stream
botamusique    | [2020-11-19 15:00:58,617] > [MainThread] > [mumbleBot.py:481] ffmpeg: [AVIOContext @ 0x55c10936e2c0] Statistics: 713 bytes read, 0 seeks
botamusique    | [2020-11-19 15:05:01,534] > [Thread-5] > [mumbleBot.py:262] bot: received command play -  by Elinvention
botamusique    | [2020-11-19 15:05:01,535] > [Thread-5] > [radio.py:65] radio: fetching radio server description
botamusique    | [2020-11-19 15:05:02,112] > [Thread-5] > [radio.py:85] radio: unsuccessful attempts on fetching radio title (icy)
botamusique    | [2020-11-19 15:05:08,998] > [Thread-6] > [mumbleBot.py:262] bot: received command stop -  by Elinvention
botamusique    | [2020-11-19 15:05:09,099] > [Thread-6] > [cache.py:100] library: cache freed for item: [radio] KBS 1R (http://serpent0.duckdns.org:8088/kbs1radio.pls)
botamusique    | [2020-11-19 15:05:09,099] > [Thread-6] > [mumbleBot.py:657] bot: music stopped.
botamusique    | [2020-11-19 15:05:14,022] > [Thread-7] > [mumbleBot.py:262] bot: received command clear -  by Elinvention
botamusique    | [2020-11-19 15:05:14,123] > [Thread-7] > [cache.py:104] library: all cache freed
botamusique    | [2020-11-19 15:05:14,123] > [Thread-7] > [mumbleBot.py:650] bot: music stopped. playlist trashed.
botamusique    | [2020-11-19 15:05:33,126] > [Thread-8] > [mumbleBot.py:262] bot: received command se - death star by Elinvention
botamusique    | [2020-11-19 15:05:33,127] > [Thread-8] > [mumbleBot.py:298] bot: se matches search
botamusique    | [2020-11-19 15:05:37,056] > [Thread-9] > [mumbleBot.py:262] bot: received command sl - 4 by Elinvention
botamusique    | [2020-11-19 15:05:37,058] > [Thread-9] > [cache.py:54] library: music found in database: [file] Star Wars VI - Main Title - Approaching The Death Star (Star Wars/Star Wars VI - Main Title - Approaching The Death Star.ogg)
botamusique    | [2020-11-19 15:05:37,159] > [Validating] > [playlist.py:223] playlist: start validating...
botamusique    | [2020-11-19 15:05:37,159] > [Validating] > [playlist.py:227] playlist: validating [file] Star Wars VI - Main Title - Approaching The Death Star (Star Wars/Star Wars VI - Main Title - Approaching The Death Star.ogg)
botamusique    | [2020-11-19 15:05:37,159] > [Thread-9] > [command.py:1079] cmd: add to playlist: [file] Star Wars VI - Main Title - Approaching The Death Star (Star Wars/Star Wars VI - Main Title - Approaching The Death Star.ogg)
botamusique    | [2020-11-19 15:05:37,159] > [Validating] > [playlist.py:243] playlist: validating finished.
TerryGeng commented 3 years ago

Sorry for the late reply. Thanks for your investigation. I just posted a fix to let the bot not get stuck when radio fails.