ALSA cpu usage

[alexheretic]

Hello, I recently had a look at Robo Instructus' cpu usage and noticed the audio usage seems high. It's not a huge problem, but I thought I'd raise this in case it tickles the imagination.

I profiled the game without any music, so just occasional sounds and mostly silence. Rodio maintains a single stream and (I presume) will continually write silent bytes -> output.

cpal event loop run_inner is the majority of the game's sampled usage.

Full: robo-instructus-flamegraph.zip

[balping]

Is it better with this: #301 ?

[alexheretic]

Is it better with this: #301 ?

Maybe. It doesn't look like that change will be easy for me to swap in, it'll require a bunch of rodio changes etc.

[alexheretic]

Ok I've reworked rodio to #301 locally, it actually makes rodio simpler.

In terms of CPU usage the news is even better as rodio & cpal are no longer visible on the flamegraph. So #301 should solve this issue.
robo-instructus-cpal-pr301-flame.zip
robo-instructus-cpal-0.10-flame.zip

cpal 0.10

cpal + #301

[ishitatsuyuki]

First I doubt that #301 would make a difference. It can optimize lock handling for other platforms, but for ALSA there's already built-in synchronization and we don't have contention with it.

So please try retaking your profiles.

If that's actually being a bottleneck, though, I think this might be an issue. I'll file a PR after testing that it works. It showed no CPU usage difference (with the beep example), though.

[alexheretic]

Not a huge difference with snd_pcm_avail_update still a similar ~54% of sampled usage.

robo-instructus-cpal-avail-update-flame.zip

I wonder if the profiling is just missing the new cpal thread?

[ishitatsuyuki]

Given that on PulseAudio we should be using a somewhat big buffer size (around 100ms), cpal being a bottleneck just doesn’t make sense.

Also most time looks like being spent in polling, which is also strange because typically time is spent in sample generation (data callback). Are you sure that’s not the time we block (idle) waiting next period?

[alexheretic]

Well I'm not sure of anything other than these are the flamegraphs I got.

The game has a few thread loops, most actively the render & compute loops. But also some mostly idle threads to do with io. Then there's the audio event loop thread. So that the audio thread is mostly idle and the profiling is wrong doesn't sound convincing to me.

[alexheretic]

On the other hand I'm having trouble reproducing those flames today. I'm more confused now. I'll close for now until I get a better handle on this.

[alexheretic]

There is definitely high CPU usage from the event loop with alsa, at least on my system. I've reproduced it using the rodio music_ogg example (as my game uses ogg, but it happens with anything).

I'm testing cpal/rodio master against cpal#301/rodio#247. Annoyingly I have to patch cpal on both sides to revert #307 as this causes large audio delay for me.

I've produced two Linux binaries that play music_ogg for 30 seconds. These can be used for reproduction. Though you may need a recent glibc.

• Master: rodio-example-music-ogg.zip
• Engineless/no-eventloop: rodio-engineless-example-music-ogg.zip

Then use flamegraph to profile each. I also set echo -1 | sudo tee /proc/sys/kernel/perf_event_paranoid in case that would help improve perf.

The flames I get (view them in firefox so you can zoom, etc):

• Master: rodio-music-flame.zip
  Produces a flame similar to the one I first reported. The event loop is churning. CPU usage is noticeable.
• Engineless/no-eventloop: rodio-engineless-music-flame.zip
  Totally different flame. CPU usage is around 0%.

So I'm convinced there is an issue which is fixed by #301. But I can't explain why the event loop is bad and the new thread is good. Is there something about looping over potentially multiple streams which is inefficient there?

[ishitatsuyuki]

I ran your binaries and they both ran with 1% CPU usage, which is negligible. I also ran them with Cachegrind, the instruction difference is under 0.5%, completely inside the margin of error. Sorry, this cannot be reproduced.

This sounds more like an issue fixed in latest versions of PulseAudio or libalsa. Maybe update your system?