Question about CPU utilization and main loop

[Gert-dev]

Is your feature request related to a problem? Please describe.
I'm running botamusique on a device with an old dual-core ARMv7 CPU and it mostly runs fine. Occasionally, however, the music glitches or gets artifacts for a second or so, likely because the CPU can't keep up under the load. I can reproduce this consistently by doing other things on the device, such as update the system.

I noticed that on this device, botamusique takes about 50% CPU according to top and murmur about 10%. I noticed that there is also a loop in botamusique that sleeps every so often to prevent excessive CPU usage. I'm wondering if it is possible and safe to try and tweak these sleep periods and if it could potentially reduce the CPU usage somewhat.

Describe the solution you'd like
Some way to lower the CPU usage a bit on devices with slow processors.

Describe alternatives you've considered
Get a device with a more powerful processor, or just learn to live with the problem 😄.

[TerryGeng]

Hi. Please be noted that the bot runs ffmpeg as the decoder of audio files. It runs as a subprocess of the main process of the bot. Can you check about the memory usage of the ffmpeg thread? If it is ffmpeg that eats up your CPU, then I think we can do nothing about it.

[Gert-dev]

Thanks for your response.

I checked it out, but it does seem to be the bot itself (Python) that is consuming the most:

This is during playback of a YouTube video.

• murmurd is the Mumble server Murmur.
• ffmpeg is likely the process actually playing the music, as mentioned.
• python3 is the process running botamusique itself.

I noticed that even when idle python3 is consuming around 2% CPU usage - not a lot, but just thought I'd mention it, since it's not really doing anything except running the main loop, I'm guessing.

[TerryGeng]

Okay. Thanks for investigating for us! The fact is we are not doing anything other than pushing music to the murmur server. Since the music data has to be compressed by Opus and be encrypted through TLS, I think that would be the things that cost your CPU level.

Also, when the bot is not playing anything, as long as the ducking is enabled, the bot requests audio data from the murmur server and decode them, which might be a problem. I will try to fix this in the next release, but I think that won't help a lot in your case.

[Gert-dev]

Thanks for the information, that makes sense.

I've tried turning some of the knobs around the sleep calls, but nothing seems to have a particularly noticeable impact. I also have ducking disabled currently.

Is there a way to quickly verify that the Opus encoding and/or TLS encryption are bottlenecks? I presume the source of this would be somewhere in pymumble? I also encountered azlux/pymumble#66; if the encryption is indeed the problem and the cypher is going to be changed (mumble-voip/mumble#3918), perhaps there are certain cyphers that are less straining for ARM CPU's and I could add to that Mumble discussion by testing the ciphers :-).

[TerryGeng]

Actually we haven't implemented UDP support in pymumble yet. No good package for doing AES-OCB2 used by UDP transmission can be found and it looks like there're some disputes on whether changing to another algorithm but currently the discussion is stalled.

To verify the CPU cost of encoding and encrypting, etc., you can just make the bot muted by comment L491-492, L494-495, and L497-498 in the mumbleBot.py. Then after you start the bot, the CPU cost would be the "net" cost of the bot.

[Gert-dev]

Thanks for the information.

Commenting these lines had some... unexpected results regarding CPU utilization:

murmurd no longer shows up, probably because it has nothing to process now, seeing as the server was empty apart from me and the bot and my microphone was muted.

Two things that surprise me is that one, the ffmpeg usage spikes really hard, even though the bot is doing pretty much the same as far as ffmpeg is concerned - it's still consuming the data, just not sending it to the server anymore, and two, the botamusique usage is still fairly high, though around 10% lower.

I verified these results multiple times and the result was the same: with the original code the ffmpeg process doesn't take that much CPU, but without these couple of lines, it takes a much larger amount. It seems as if more CPU is available and ffmpeg then wants to take that, but the CPU already wasn't capped at 100% before, so it isn't immediately clear to me why it's going up so much now.

For completeness' sake, this is the code I have now for that block:

                if raw_music:
                    # Adjust the volume and send it to mumble
                    self.volume_cycle()

                    if not self.on_interrupting and len(raw_music) == self.pcm_buffer_size:
                        pass
                        #self.mumble.sound_output.add_sound(
                        #    audioop.mul(raw_music, 2, self.volume_helper.real_volume))
                    elif self.read_pcm_size == 0:
                        pass
                        #self.mumble.sound_output.add_sound(
                        #    audioop.mul(self._fadeout(raw_music, self.stereo, fadein=True), 2, self.volume_helper.real_volume))
                    elif self.on_interrupting or len(raw_music) < self.pcm_buffer_size:
                        #self.mumble.sound_output.add_sound(
                        #    audioop.mul(self._fadeout(raw_music, self.stereo, fadein=False), 2, self.volume_helper.real_volume))
                        self.thread.kill()
                        self.thread = None
                        time.sleep(0.1)
                        self.on_interrupting = False

Of course I'd be happy to help pinpoint where the CPU is spending its time now in botamusique, if you can provide pointers - I'm not too familiar with Python.

[TerryGeng]

Sorry that I have neglected some important things the pymumble does when sending music data. It actually limited the speed the data being sent. If you sent too fast, it will just block the main thread so the ffmpeg can not write to the pipe and hence are effectively in "sleep" most of the time. If such speed limit is not implemented, the ffmpeg will work like crazy at its full speed.

Now we have to do this manually. we read 960 samples into the buffer each time, which accounts for 20ms of music data. You have to do time.sleep(20/1000) on L489.

[Gert-dev]

Aha, that makes sense. I've tried adding the sleep and the results are much lower now:

I've also tried disabling the audioop.mul and self._fadeout calls, just to be sure, but disabling them offers little benefit, so this seems to move the problem "down the chain" to pymumble, where it is likely indeed due to encryption overhead.

This means this issue can be closed here, I think, since botamusique is not the cause and around 4% on this slow CPU seems quite acceptable. Since you are also familiar with pymumble, would it be useful for me to try and pinpoint the issue further inside pymumble to be sure it's due to the encoding and/or encryption?

[TerryGeng]

Thanks for your effort! Sure. All the audio data encoding and sending happen in L49 of https://github.com/azlux/pymumble/blob/pymumble_py3/pymumble_py3/soundoutput.py, the send_audio() function.

The encryption is done by the native SSL library of python, https://github.com/azlux/pymumble/blob/ab6bd98cf897aba96a30222b7a8926694b651918/pymumble_py3/mumble.py#L156

I think I shall close this issue for now. If you made any discovery, you are welcome to open an issue in the pymumble repo. :)