[Bug] bot does not play audio after user has joined server

using docker, if jjmumblebot remains unused for an extended period of time (eg overnight), when i go back into mumble and try to play something eg with !link I get the following response:

An audio plugin(server_tools) is already using the audio interface.

when I !restart it works fine.

Hi, is this a consistent issue? I've only encountered this rarely when multiple audio commands are issued at the same time.

yes, tested it again just now. it always happens for me. I don't often issue multiple commands at the same time either, typical usage for me is periodically adding urls to the queue.

i just tried doing !stop first and that seems to work around the issue as well.

probably related, I think VLC process is turning into a zombie process, as ps aux | grep Z shows:

root      251325  0.0  0.0      0     0 ?        Z    15:04   0:02 [vlc] <defunct>

pstree -p -s 251325 shows:

systemd(1)───containerd(937)───containerd-shim(249360)───python(249377)───vlc(251325)

249377 is the PID of jjmumblebot (which is being run in a docker container).

If the !stop command fixes the issue, it's probably as you suspected with VLC becoming a zombie process. One of the ways the bot determines the audio interface is currently in use is with the presence of the VLC process along with another internal flag.
Although I'm not exactly sure how to prevent this from happening... VLC is provided with an auto-exit flag after playing the track so it shouldn't become a zombie process.

some more observations:

on a fresh run, the vlc process turns into a zombie after there are no more links in the queue, but if I add another link the process unzombifies, plays the link and then turns into a zombie again.
if i exit mumble, enter again and try to enter a link i get the error, which is fixed by restarting or stop/starting.

i think the process is turning zombie because even though vlc exits, a subprocess opened by Popen is not able to close itself. I was able to get rid of the zombie process issue by adding stop_audio_instance() after global_settings.aud_interface.reset() in line 115:

                if global_settings.aud_interface.next_track():
                    create_audio_thread(audio_lib_path=audio_lib_path, audio_lib_type=audio_lib_type,
                                        uri=global_settings.aud_interface.status.get_track().uri, skipto=0, quiet=quiet,
                                        stereo=stereo)
                else:
                    global_settings.aud_interface.reset()
                    sleep(0.5)
                    rutils.mute()
                    stop_audio_instance()

i also think this would be a good place to re-mute the bot with rutils.mute(). when I did that the audio got distorted at the very end, sleep(0.5) seems to work around that okay.

UPDATE: upon further testing it seems that the end-audio distortion seems to happen consistently between two tracks in the queue. adding sleep(0.5) seems to fix this as well if it is moved to the top of that conditional block:

            else:
                sleep(0.5)
                if global_settings.aud_interface.next_track():
                    ...

happy to submit a PR if you're interested.

This didn't actually solve the original problem though, which i guess makes sense since the error message points to server_tools being the plugin that's actually locking it up.

based on the error message, i do think i have found the source of the issue! I think it's here; surely enough, when I had a user join the server immediately after restarting the bot I still get the same error. when I comment this conditional block out and replace it with return, the issue disappears. Obviously there needs to be additional code to retain the audio login clip functionality but i don't use that and have not looked at it closely.

Thanks for the detailed report! I'll be doing some testing to further investigate the issue.

based on the error message, i do think i have found the source of the issue! I think it's here; surely enough, when I had a user join the server immediately after restarting the bot I still get the same error. when I comment this conditional block out and replace it with return, the issue disappears. Obviously there needs to be additional code to retain the audio login clip functionality but i don't use that and have not looked at it closely.

This is odd, the server_tools plugin (and sound_board plugin) utilizes ffmpeg instead of vlc to play the audio clips so it shouldn't be affecting VLC being a zombie process, however it would explain why the audio interface would remain busy.

The code in the server_tools plugin to set the "do not interfere" flag and play an audio clip is identical to how the sound_board plugin plays audio clips by setting the audio interface ownership to itself and playing the clip. After the clip is played the audio interface should clear the plugin ownership, but it looks like somewhere in this process it doesn't clear the plugin ownership and the bot thinks the audio interface is still busy.

The code related to "dni" means "do not interfere" which is used to indicate which plugin is currently utilizing the audio interface, without this flag multiple plugins could play at the same time and cause an overlapping mess of audio.

As a temporary measure, since you're not utilizing the login audio clip feature, you can disable it in the server_tools plugin's metadata.ini file located in the plugin folder: JJMumbleBot/plugins/core/server_tools/metadata.ini and setting PlayAudioClipOnUserJoin to False.

UPDATE:
Upon further investigation, it looks like if the login audio clip feature is enabled (which it is by default) it is supposed to play a built-in 'ping' audio clip whenever a user joins, unless you change it to a custom audio clip. This built-in clip is called default_user_sound.wav and is supposed to be located in the JJMumbleBot/plugins/core/server_tools/resources/ directory, however I am not seeing that in the git repository which might be why this problem is occurring. I think the server_tools plugin might be running into an error trying to retrieve the built-in clip and it can't find it causing the audio interface to become stuck.
Does your server_tools plugin contain the default_user_sound.wav file or is it missing? I think this might be the problem

Code reference that uses built-in clip if a custom clip isn't set:

JJMumbleBot/JJMumbleBot/plugins/core/server_tools/server_tools.py

Line 120 in 194c889

track_obj = TrackInfo(

Metadata parameter that uses built-in clip by default:

JJMumbleBot/JJMumbleBot/plugins/core/server_tools/metadata.ini

Line 35 in 194c889

UseBuiltInAudioClip = True

UPDATE 2:
It also looks like the error-checking code in the server_tools plugin for handling missing audio clips is handled incorrectly. I'll fix this and also add the missing default clip in the dev branch.

This is odd, the server_tools plugin (and sound_board plugin) utilizes ffmpeg instead of vlc to play the audio clips so it shouldn't be affecting VLC being a zombie process, however it would explain why the audio interface would remain busy.

I think the zombie process was a red herring and is a separate issue that is relatively harmless. probably still worth fixing.

Does your server_tools plugin contain the default_user_sound.wav file or is it missing? I think this might be the problem

nope, it isn't there! makes sense too since i've never heard the sound since i've been using the bot and didn't know it was a feature until i started poking around haha.

It also looks like the error-checking code in the server_tools plugin for handling missing audio clips is handled incorrectly. I'll fix this and also add the missing default clip in the dev branch.

awesome, thank you!

As a temporary measure, since you're not utilizing the login audio clip feature, you can disable it in the server_tools plugin's metadata.ini file located in the plugin folder: JJMumbleBot/plugins/core/server_tools/metadata.ini and setting PlayAudioClipOnUserJoin to False.

quick note -- for some reason, setting PlayAudioClipOnUserJoin = False prevents the welcome message from displaying.

I think the zombie process was a red herring and is a separate issue that is relatively harmless. probably still worth fixing.

I'll definitely look into it after fixing some other remaining issues.

nope, it isn't there! makes sense too since i've never heard the sound since i've been using the bot and didn't know it was a feature until i started poking around haha.

Yeah my bad, it looks like all audio file formats were excluded in my .gitignore so I didn't notice that it wasn't included.
I've fixed it in this dev branch commit: 3c9ed8c

quick note -- for some reason, setting PlayAudioClipOnUserJoin = False prevents the welcome message from displaying.

I'm not sure why this is occurring, the code seems fine and it's working on my testing system.
As seen in the snippet below, it is the first bit of code that is executed in the user connection callback, so it shouldn't be prevented by any other settings.

JJMumbleBot/JJMumbleBot/plugins/core/server_tools/server_tools.py

Lines 67 to 74 in 194c889

    
           def clbk_user_connected(self, user): 
        
               # Display the welcome message to the user if any. 
        
               if self.metadata.getboolean(C_PLUGIN_SET, P_USE_WELCOME_MSG, fallback=False): 
        
                   if len(self.metadata[C_PLUGIN_SET][P_WELCOME_MSG]) > 0: 
        
                       gs.gui_service.quick_gui(f"{self.metadata[C_PLUGIN_SET][P_WELCOME_MSG]}", 
        
                                                text_type='header', 
        
                                                box_align='left', 
        
                                                user=user[0]['name'])

DEV BRANCH: Server Tools Plugin Updates (and some others) - January 31, 2022

I've updated the server_tools plugin a lot to better handle the audio clip handling and error-checking/error-logging in the last few commits in the dev-branch: 570cb7b cdff8f9 3c9ed8c 12f26b2 4873dc0 af805db

Patch notes:

Added the missing default user connection sound file to the server_tools plugin.
Fixed .gitignore issue that filtered the default user connection sound file.
Updated docs/comments in server_tools metadata to highlight that custom generic clips must include the file extension.
Added utility method to locate files in the dir_utils library file.
Added utility methods to find audio clips from the media directory and sound board media directory for the server_tools plugin.
Greatly improved error-handling for audio files and improved error log detail.
Error messages are now properly logged if a required audio file or directory is missing for the server_tools plugin.
Refactored the user connected callback almost completely to better handle finding and playing audio clips.
Added checks to make sure the audio clip exists before setting it as a default login sound or a user's login sound.
Optimized some imports in the server_tools plugin.

Additional notes:

I've also decoupled the sound_board plugin dependency that the server_tools plugin needed to work. Since this plugin has an option to use audio clips from the sound board media directory, I had previously also imported a sound board utility method which meant that users were required to have the sound_board plugin installed. Since this is an optional feature, and the plugin is supposed to be separate, I've fixed this issue in the dev-branch.
To summarize: You should no longer require the sound_board plugin to be installed to use the server_tools plugin unless you have the UseSoundBoardClips option enabled in the metadata file.

For the VLC zombie process issue, I'll try the workaround you mentioned and test it further!

awesome! looking forward to it.

	def clbk_user_connected(self, user):
	# Display the welcome message to the user if any.
	if self.metadata.getboolean(C_PLUGIN_SET, P_USE_WELCOME_MSG, fallback=False):
	if len(self.metadata[C_PLUGIN_SET][P_WELCOME_MSG]) > 0:
	gs.gui_service.quick_gui(f"{self.metadata[C_PLUGIN_SET][P_WELCOME_MSG]}",
	text_type='header',
	box_align='left',
	user=user[0]['name'])