Musicbot: Bot disconnects after a few hours from voice channel

[henryjiang88]

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

[ssgoku129]

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.

[InfectedMagic]

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.

[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

[henryjiang88]

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.

[ssgoku129]

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

[InfectedMagic]

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.

[harbinger1080]

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.

[ghost]

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

[Kompas9]

Same exact problem

[rtil5]

+1 to this error as well on Win10.

[RyanL-29]

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

[royaltongue]

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

[RyanL-29]

@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

[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
-snip-

Edit: Aleana - Readability snip

[ssgoku129]

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.

[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

[henryjiang88]

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 :(

[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.

[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.

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.

[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.

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.

[TheerapakG]

@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.

[ZedRei]

@TheerapakG You're right, I tried getting rid of the post but you beat me to it. After a while it dc'd again with the same errors. Thank you for your input.

[henryjiang88]

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

[AleanaA]

@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.

[cdecker15]

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.

[Colink02]

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.

[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.

[audioclass]

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.

[Colink02]

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.

[ssgoku129]

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.

[audioclass]

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.

[AleanaA]

2070 is intended to resolve more stability issues, but we're unable to merge as a result of Travis.

Feel free to clone the branch and see if that helps any, as it should catch issues with the player, and allow you to resume in the event that a recoverable error occurs. Note that it's based on the review branch, so other issues may arise.

[henryjiang88]

2070 is intended to resolve more stability issues, but we're unable to merge as a result of Travis.

Feel free to clone the branch and see if that helps any, as it should catch issues with the player, and allow you to resume in the event that a recoverable error occurs. Note that it's based on the review branch, so other issues may arise.

Thanks so much @AleanaA for this update. I have been running for more than a day now and it hasn't dropped. The bot has never run this long before. Will keep on monitoring it for the week.

Again, many thanks for your hard work!

[RickeyJLancaster]

2070 is intended to resolve more stability issues, but we're unable to merge as a result of Travis.

Feel free to clone the branch and see if that helps any, as it should catch issues with the player, and allow you to resume in the event that a recoverable error occurs. Note that it's based on the review branch, so other issues may arise.

@AleanaA tried it but got stuck at [DEBUG:playback:MusicBot] trying to get entry...

[TheerapakG]

tried it but got stuck at [DEBUG:playback:MusicBot] trying to get entry...

@RickeyJLancaster It's not really stuck but it is waiting for something to be added but that is not the problem here.

The problem is that you are using the wrong branch from my repository. That phrase is going to come up in the bot that is based on/ is part of the rewritten version of the bot (Just-Some-Bots:cogs-rewrite) which is still very unstable. This includes these following active branches:

• TheerapakG:playground_all (Default branch of my repo)
• TheerapakG:entrybuilders (#2030)

There are more stale branches that are part of the rewrite version but those branches haven't been updated for at least 2 months. So I think you wouldn't mistake those branches for the correct branch.

Make sure you are using the branch TheerapakG:playground_stop_error, which is what #2070 is.

[Flegma]

The problem is happening again, even with discord.py[voice]==1.2.5
Anyone has the solution?
I'm on Ubuntu 18.04.