MusicBot icon indicating copy to clipboard operation
MusicBot copied to clipboard

Bot disconnects after a few hours from voice channel

Open henryjiang88 opened this issue 4 years ago • 37 comments

Please tick all applicable boxes.

  • [x] I am using Python 3.5.3 or higher (run python --version on the command line)
  • [x] I have followed the official guides to install the bot for my system
  • [x] I have updated my dependencies to the latest version using the appropriate update script

Which version are you using?

  • [x] The latest master version (release-260419)
  • [x] The latest review version

What type of issue are you creating?

  • [x] Bug
  • [ ] Feature request
  • [ ] Question

Description of issue

Running Raspbian. Bot exits the voice server and needs !summon to call it back. It still plays but then may become glitchy and require a complete reboot. Console error message shows:

Task exception was never retrieved
future: <Task finished coro=<MusicPlayer._play() done, defined at /home/pi/MusicBot/musicbot/player.py:259> exception=ClientException('Not connected to voice.')>
Traceback (most recent call last):
  File "/home/pi/MusicBot/musicbot/player.py", line 307, in _play
    self.voice_client.play(self._source, after=self._playback_finished)
  File "/usr/local/lib/python3.7/dist-packages/discord/voice_client.py", line 363, in play
    raise ClientException('Not connected to voice.')
discord.errors.ClientException: Not connected to voice.

Log provided but not sure if useful or not.

UPDATE

Tried with both master and review version same error.

Steps to reproduce

  1. Run bot for a few hours.

  2. Bot will unexpectantly drop offline despite having people in the voice server. Bot is set to stay in the general voice server even when botowner is absent.


Similar case has been reported here but don't see a resolution.

Log file

Please attach your MusicBot log file (located at logs/musicbot.log) to this issue. You can do so by dragging and dropping the file here. If you do not include your log file, you WILL be asked to provide one. musicbot.log

henryjiang88 avatar Apr 05 '20 21:04 henryjiang88

Yeah I've been having this issue in Windows the last few weeks, decided to deploy MusicBot on Ubuntu server 18.04 assuming Win problem, same issue keeps occuring, the basic error log has the same thing on both windows and linux:

 CGroup: /system.slice/MusicBot.service
           ├─  949 /bin/bash /Discord/MusicBot/run.sh
           ├─ 1106 python3 run.py
           └─14772 ffmpeg -nostdin -i audio_cache/youtube-ruScJ-SxfD4-The_Best_of_Retro_VGM_480_-_Ridge_Racer_Arcade_-_Rare_Hero.webm -f s16le -ar 48000 -ac 2 -loglevel warning -vn pipe:1

Apr 07 04:48:57 robots run.sh[949]: Download started: https://www.youtube.com/watch?v=ruScJ-SxfD4
Apr 07 04:48:59 robots run.sh[949]: Download complete: https://www.youtube.com/watch?v=ruScJ-SxfD4
Apr 07 04:48:59 robots run.sh[949]: Task exception was never retrieved
Apr 07 04:48:59 robots run.sh[949]: future: <Task finished coro=<MusicPlayer._play() done, defined at /Discord/RetroBot/musicbot/player.py:259> exception=ClientException('Not connected to voice.',)>
Apr 07 04:48:59 robots run.sh[949]: Traceback (most recent call last):
Apr 07 04:48:59 robots run.sh[949]:   File "/Discord/RetroBot/musicbot/player.py", line 307, in _play
Apr 07 04:48:59 robots run.sh[949]:     self.voice_client.play(self._source, after=self._playback_finished)
Apr 07 04:48:59 robots run.sh[949]:   File "/usr/local/lib/python3.6/dist-packages/discord/voice_client.py", line 363, in play
Apr 07 04:48:59 robots run.sh[949]:     raise ClientException('Not connected to voice.')
Apr 07 04:48:59 robots run.sh[949]: discord.errors.ClientException: Not connected to voice.

I'm going to try enabling a higher level of debug and see if I can catch anything causing it.

ssgoku129 avatar Apr 07 '20 04:04 ssgoku129

I've also been problems with the bot disconnecting after about an hour of playing music but also when typing summon, it join and rapidly goes trough all song in the queue spamming the chat with: Now playing in [CHANNEL]: {Song} by {Artist} added by {USER} without deleting them. I've seen on the Discord they said something about bad internet connections, but I don't know.

InfectedMagic avatar Apr 11 '20 03:04 InfectedMagic

Happens to me on Ubuntu 18.04 with the following error:

Task exception was never retrieved
future: <Task finished coro=<MusicPlayer._play() done, defined at /home/localuser/Documents/MusicBot/musicbot/player.py:259> exception=ClientException('Not connected to voice.',)>
Traceback (most recent call last):
  File "/home/localuser/Documents/MusicBot/musicbot/player.py", line 307, in _play
    self.voice_client.play(self._source, after=self._playback_finished)
  File "/usr/local/lib/python3.6/dist-packages/discord/voice_client.py", line 363, in play
    raise ClientException('Not connected to voice.')
discord.errors.ClientException: Not connected to voice.

My server is hardwired to my router, with 1Gb service, so I don't think a bad internet connection is the issue

gaiacanon avatar Apr 11 '20 05:04 gaiacanon

Happens to me on Ubuntu 18.04 with the following error:

Task exception was never retrieved
future: <Task finished coro=<MusicPlayer._play() done, defined at /home/localuser/Documents/MusicBot/musicbot/player.py:259> exception=ClientException('Not connected to voice.',)>
Traceback (most recent call last):
  File "/home/localuser/Documents/MusicBot/musicbot/player.py", line 307, in _play
    self.voice_client.play(self._source, after=self._playback_finished)
  File "/usr/local/lib/python3.6/dist-packages/discord/voice_client.py", line 363, in play
    raise ClientException('Not connected to voice.')
discord.errors.ClientException: Not connected to voice.

My server is hardwired to my router, with 1Gb service, so I don't think a bad internet connection is the issue

Same here. Mine is enjoying 1.5 Gbps Download and 1.0 Gbps upload fibre and still the same problem.

henryjiang88 avatar Apr 11 '20 15:04 henryjiang88

Should we try deploying in 16.04? Is Ubuntu 18.04 and Windows 10 the problem?

ssgoku129 avatar Apr 13 '20 03:04 ssgoku129

well I'm running the bot on Windows 10 and now after 3 days I've just not been closing/turning the bot off and just using the restart command when this problem comes up, this seems to "stabilize" the bot so it does not disconnect from VC on an hourly basis.

InfectedMagic avatar Apr 13 '20 20:04 InfectedMagic

Seeing the same behavior/alerts here, on an RPi 3b+ running Buster.

Task exception was never retrieved
future: <Task finished coro=<MusicPlayer._play() done, defined at /home/mbot/MusicBot/MusicBot_master/musicbot/player.py:259> exception=ClientException('Not connected to voice.',)>
Traceback (most recent call last):
  File "/usr/lib/python3.5/asyncio/tasks.py", line 240, in _step
    result = coro.send(None)
  File "/home/mbot/MusicBot/MusicBot_master/musicbot/player.py", line 307, in _play
    self.voice_client.play(self._source, after=self._playback_finished)
  File "/usr/local/lib/python3.5/dist-packages/discord/voice_client.py", line 363, in play
    raise ClientException('Not connected to voice.')
discord.errors.ClientException: Not connected to voice.

harbinger1080 avatar Apr 15 '20 17:04 harbinger1080

Same issue! Running on MacOS via ethernet, getting really annoying now...

ghost avatar Apr 15 '20 20:04 ghost

Same exact problem

Kompas9 avatar Apr 16 '20 13:04 Kompas9

+1 to this error as well on Win10.

rtil5 avatar Apr 16 '20 22:04 rtil5

You guys can see the issue #2051. I find a way to fix it.

RyanL-29 avatar Apr 18 '20 14:04 RyanL-29

@RyanL-29 Where would the site packages be on Ubuntu?

royaltongue avatar Apr 18 '20 18:04 royaltongue

@royaltongue Sorry! I am using Windows 10 to host this bot. I don't know where is the site packages on Ubuntu. But most of time it will contain in the root file of where you install python. Path: Somewhere\Python\Python37\Lib\site-packages. Sorry about I can't help you at all on Ubuntu again

RyanL-29 avatar Apr 19 '20 00:04 RyanL-29

Tried @RyanL-29's suggestion and got this error:

ERROR: unable to download video data: HTTP Error 403: Forbidden Traceback (most recent call last): File "/usr/local/lib/python3.7/dist-packages/youtube_dl/YoutubeDL.py", line 1926, in process_info -snip-

Edit: Aleana - Readability snip

henryjiang88 avatar Apr 19 '20 22:04 henryjiang88

Tried @RyanL-29's suggestion and got this error:

ERROR: unable to download video data: HTTP Error 403: Forbidden Traceback (most recent call last): File "/usr/local/lib/python3.7/dist-packages/youtube_dl/YoutubeDL.py", line 1926, in process_info

Yeah his code doesn't solve the problem or maybe it does something for him but it's not addressing the issue that we're all having.

Firstly - you are probably pinging YouTube too much hence the ""ERROR unable to download video data", if you turn off your firewall for 2m and power it back on, you should get a new WAN IP and stop getting that message.

As for the bot still disconnecting, it's a problem that keeps popping up with this project, you'll see a ton of traces of the exact same problem were having (same error code and everything) in the "Issues" tab but the only solve seems to be "update to the latest version". This bot worked really great a year ago, the last 6mo it's been pretty flaky though I would blame Discord and YouTube API changes more than development.

I have tried the latest stable release, review release, and review release + RyanL's appended line of code, all have failed to produce stable results on both Ubuntu and Windows.

ssgoku129 avatar Apr 19 '20 23:04 ssgoku129

I plan to look into this more over the course of this upcoming week

Regarding the 403 error, this was addressed on youtube-dl's github: ytdl-org/youtube-dl#24794

The solution to the 403 error above would be to run one of the three (depending on what does and doesn't work for your environment): youtube-dl --rm-cache-dir python -m youtube_dl --rm-cache-dir python3 -m youtube_dl --rm-cache-dir

AleanaA avatar Apr 20 '20 00:04 AleanaA

I plan to look into this more over the course of this upcoming week

Regarding the 403 error, this was addressed on youtube-dl's github: ytdl-org/youtube-dl#24794

The solution to the 403 error above would be to run one of the three (depending on what does and doesn't work for your environment): youtube-dl --rm-cache-dir python -m youtube_dl --rm-cache-dir python3 -m youtube_dl --rm-cache-dir

Tried the three commands and reran bot. Still seized after a less than an hour :(

henryjiang88 avatar Apr 20 '20 01:04 henryjiang88

@henryjiang88 The three commands are meant for the 403 error, they're not for the issue of the bot disconnecting. As noted, I plan to look into this in the upcoming week.

AleanaA avatar Apr 20 '20 01:04 AleanaA

@henryjiang88 The three commands are meant for the 403 error, they're not for the issue of the bot disconnecting. As noted, I plan to look into this in the upcoming week.

Awesome, thanks for your contribution to this project, it's my favourite musicbot! This issue has persisted a little bit over a month for me, previously all bugs have been easily thwarted with fresh installation and a little bit of python configuration knowledge (especially when things get mucked up in the installation) but haven't been able to solve this constant disconnect issue.

Happy to test any forks or review updates, please let me know where to look out for updates if not here.

ssgoku129 avatar Apr 20 '20 01:04 ssgoku129

@henryjiang88 The three commands are meant for the 403 error, they're not for the issue of the bot disconnecting. As noted, I plan to look into this in the upcoming week.

Thanks so much for your contribution. The bot now stays online all the time.

My server now runs into the 403 error every 30 minutes even more frequent than it falling offline. I wonder why. My python coding is very rusty or else I'd try it myself but I was wondering if we could incorporate a check every minute to run the youtube_dl commands if a 403 error occurs and reboot the bot.

henryjiang88 avatar Apr 20 '20 14:04 henryjiang88

@ZedRei that 4014 code refers to voice close event code not gateway close event code. I don't think that enabling those intents will solve it but I don't know for sure. If I were to go by that log then I think that it's more likely that we have to initiate a new voice connection (rather than using the old voice connection) after we get RESUME but that isn't the reason that the bot is disconnected in the first place.

TheerapakG avatar Apr 22 '20 07:04 TheerapakG

Seems like it drops off with no console error message but the log looks like this. No obvious cause of the dropout as logs just look like this.

!restart doesn't help. Needs to completely kill the process on my raspberry pi or even reboot.

[4351.8822271823883057] 2020-04-26 14:11:39,694 - DEBUG - musicbot.player | In player.py::MainThread(3069541072), line 306 in _play: Playing <musicbot.player.SourcePlaybackCounter object at 0xb3249130> using <discord.voice_client.VoiceClient object at 0xb44d6530> [4351.8863821029663086] 2020-04-26 14:11:39,698 - DEBUG - musicbot.bot | In bot.py::MainThread(3069541072), line 474 in on_player_play: Running on_player_play [4351.8889029026031494] 2020-04-26 14:11:39,700 - DEBUG - musicbot.bot | In bot.py::MainThread(3069541072), line 723 in serialize_queue: Serializing queue for 695815274313678950 [4351.8906004428863525] 2020-04-26 14:11:39,702 - DEBUG - musicbot.bot | In bot.py::MainThread(3069541072), line 528 in on_player_play: no channel to put now playing message into [7808.3370571136474609] 2020-04-26 15:09:16,149 - DEBUG - musicbot.bot | In bot.py::MainThread(3069541072), line 3018 in on_guild_available: Guild "ZEO" has become available. [7810.3294363021850586] 2020-04-26 15:09:18,141 - DEBUG - musicbot.bot | In bot.py::MainThread(3069541072), line 965 in on_ready: Connection established, ready to go. [7810.3299508094787598] 2020-04-26 15:09:18,141 - DEBUG - musicbot.bot | In bot.py::MainThread(3069541072), line 970 in on_ready: Received additional READY event, may have failed to resume

henryjiang88 avatar Apr 26 '20 19:04 henryjiang88

@henryjiang88 Unfortunately the restart command is kinda shit, and we generally don't recommend using it. There were plans to rework it, but the contributor that was planning on doing so fell off the internet.

AleanaA avatar Apr 26 '20 20:04 AleanaA

I am also experiencing this same issue (on review). I've turned the debug value to EVERYTHING and do not explicitly see what's causing the random disconnections in either the discord.log or musicbot.log. While it stays connected to the server, it exits the channel. Any further ideas to try? I'm updating discord.py to the latest version to see if that resolves. Will report back.

Edit: I do not believe that fixed it, as it just totally stopped playing and won't resume with any commands. Is there a totally working version of the bot? Master and review both seem to not be.

jenke15 avatar Apr 27 '20 15:04 jenke15

After taking a look at it today I noticed that the bot states: "Guild 'Server Name' has become available" just before failing due to not connected in voice and this doesn't happen any other time in my tests. Not sure if that could be causing it. Also Guild Unavailable is never called before calling Guild Available.

image

Colink02 avatar Apr 28 '20 07:04 Colink02

Alright, took a step back to look at everything regarding this. From testing, and it's not 100% foolproof testing, it's likely that (for some reason, idk why it's set to be 1.2.5) d.py being set explicitly to 1.2.5 is what's causing the issue. A possible solution as of now would be to manually update d.py. Removing the ==1.2.5 in requirements.txt and running the update script should resolve this issue. I'll put in a PR to remove this once others are able to also verify success with this.

AleanaA avatar Apr 28 '20 21:04 AleanaA

Alright, took a step back to look at everything regarding this. From testing, and it's not 100% foolproof testing, it's likely that (for some reason, idk why it's set to be 1.2.5) d.py being set explicitly to 1.2.5 is what's causing the issue. A possible solution as of now would be to manually update d.py. Removing the ==1.2.5 in requirements.txt and running the update script should resolve this issue. I'll put in a PR to remove this once others are able to also verify success with this.

This has worked for me so far. If I have any further issues I'll post again.

audioclass avatar Apr 29 '20 05:04 audioclass

Not sure if this is related but since updating to the latest version of discord.py it paused because of no one in the voice channel then reconnected to discord a few times but when I rejoined the music didn't restart. When I ran "--resume" to start it said that it wasn't in a voice channel even though it never left. Also just got an issue where it left and rejoined very quickly and the music stopped.

2020-04-29T09:01:04.967411906Z Pausing in The Enfinium Server/🔉General 1🔉 (empty channel or member deafened) 2020-04-29T09:01:04.969484660Z [DEBUG:bot] Running on_player_pause 2020-04-29T11:02:04.054394003Z Reconnected to discord. 2020-04-29T11:28:12.309390569Z Reconnected to discord. 2020-04-29T11:40:50.334512157Z Reconnected to discord. 2020-04-29T12:13:09.902331682Z Reconnected to discord. 2020-04-29T16:00:07.780336479Z Reconnected to discord. 2020-04-29T17:37:44.365246829Z Reconnected to discord. 2020-04-29T18:36:55.688672654Z Reconnected to discord. 2020-04-29T19:06:24.506186370Z 186896151385997312/Colink02#3584: --resume 2020-04-29T19:06:24.512657041Z [ERROR:bot] Error in resume: CommandError: The bot is not in a voice channel. Use --summon to summon it to your voice channel. 2020-04-29T19:06:24.512931779Z Traceback (most recent call last): 2020-04-29T19:06:24.513000736Z File "/usr/src/musicbot/musicbot/bot.py", line 2744, in on_message 2020-04-29T19:06:24.513064538Z handler_kwargs['player'] = await self.get_player(message.channel) 2020-04-29T19:06:24.513142454Z File "/usr/src/musicbot/musicbot/bot.py", line 447, in get_player 2020-04-29T19:06:24.513786354Z 'Use %ssummon to summon it to your voice channel.' % self.config.command_prefix) 2020-04-29T19:06:24.513928072Z musicbot.exceptions.CommandError: The bot is not in a voice channel. Use --summon to summon it to your voice channel. 2020-04-29T19:06:32.109890759Z 186896151385997312/Colink02#3584: --summon 2020-04-29T19:06:32.115889821Z Joining The Enfinium Server/🔉General 1🔉 2020-04-29T19:06:50.703059215Z 186896151385997312/Colink02#3584: --resume 2020-04-29T19:06:50.707758862Z [ERROR:bot] Error in resume: CommandError: The bot is not in a voice channel. Use --summon to summon it to your voice channel. 2020-04-29T19:06:50.708602969Z Traceback (most recent call last): 2020-04-29T19:06:50.708695625Z File "/usr/src/musicbot/musicbot/bot.py", line 2744, in on_message 2020-04-29T19:06:50.708903748Z handler_kwargs['player'] = await self.get_player(message.channel) 2020-04-29T19:06:50.708966300Z File "/usr/src/musicbot/musicbot/bot.py", line 447, in get_player 2020-04-29T19:06:50.709028539Z 'Use %ssummon to summon it to your voice channel.' % self.config.command_prefix) 2020-04-29T19:06:50.709094423Z musicbot.exceptions.CommandError: The bot is not in a voice channel. Use --summon to summon it to your voice channel.

Colink02 avatar Apr 29 '20 19:04 Colink02

This definitely made the stability much better but I don't know if it's fixed, I'm using 10 bots, they all crashed overnight but were successfully running from when I changed the package requirements so that means they have were running for 15 hours which is much better than the previous hourly crashes.

In terms of the crash, same untelling error as before - Will enable debug logging and wait for it to happen again tonight/tomorrow.

ssgoku129 avatar Apr 30 '20 01:04 ssgoku129

So, as mentioned by ssgoku129, the stability IS much improved. I wouldn't call it entirely resolved, but issues appear to only happen once a day or less now, which is much better than the 40m to couple hours it was breaking before.

audioclass avatar May 03 '20 02:05 audioclass