[email protected]: High idle CPU consumption

[almetica]

Version used: e20b0f0
Rust: 1.43.1
Platform: stable-x86_64-pc-windows-msvc and stable-x86_64-pc-windows-gnu

After upgrading my application to the 1.6.0 beta1, my profiler showed high CPU consumption on idle. I think it's because of the switch to the next smol runtime, which is fully utilizing two threads on idle.

To test my assumption I compiled this small programm:

use async_std::task;
use std::time::Duration;

#[async_std::main]
async fn main() {
    loop {
        task::sleep(Duration::from_secs(1)).await;
    }
}

With async 1.5.0 everything is alright and the program idles and consumes nrealy none CPU resources. With the 1.6.0-beta1 (e20b0f0) this program uses two full threads and consumes high CPU resources.

I only have tested this under windows (with both GNU and MSVC targets).

[dignifiedquire]

Thank you for the report, will investigate

[yoshuawuyts]

@almetica out of interest, what is that profiler? That looks like a useful utility to investigate performance issues in the future.

[almetica]

@yoshuawuyts It's superluminal. It's a proprietary profiler that supports Rust. It's windows and msvc only though.

https://superluminal.eu/

[yoshuawuyts]

@almetica amazing, thank you! I mainly develop on Windows MSVC so this is perfect.

[GopherJ]

@almetica Awesome, I love it, thanks for the info.

[jimblandy]

This sounds similar to #771. You might check if this was introduced by faea222 as well.

[leo-lb]

@yoshuawuyts

If you're looking for crazy debugging tools here's one :

https://www.tetrane.com/

It's capable of recording debug sessions of whole VMs and do taint analysis across the whole system which means you can track where data comes from, how it is transformed, across programs and the kernel.. it can also go forward and back like rr.. and replay VGA graphical output.. it's insane but unfortunately it's proprietary..

rr: https://rr-project.org/

[ghost]

Published a smol v0.1.5 with a fix for this issue. Can you do cargo update to make sure async-std is using the latest version of smol and see if the issue is resolved?

[almetica]

Hi @stjepang,

Thank you for looking into the issue.

    Updating git repository `https://github.com/async-rs/async-std/`
    Updating crates.io index
    Updating async-std v1.6.0-beta.1 (https://github.com/async-rs/async-std/#e20b0f0d) -> #2b6c7fed
    ...
    Updating smol v0.1.4 -> v0.1.5
    ...

After updating the above mentioned example, I still see the high CPU consumption on idle (windows msvc):

[yoshuawuyts]

@almetica hmm, I remember looking at mio output recently which seemed to be polling in a hot loop even when idle. This was confusing and didn't match behavior observed on Linux. smol and mio both rely on the wepoll C library. Perhaps there's something in the implementation of wepoll that causes this to run hot.

[jimblandy]

I'm also seeing this, on Linux with smol-0.1.8.

[jimblandy]

My program is calling recvfrom on a socket repeatedly, even though every call returns EAGAIN. In smol::run, we try to block but local.event().notified() is always immediately ready. Nothing calls IoEvent::clear to clear the ThreadLocalExecutor's event, so we busy-wait.

[dignifiedquire]

@jimblandy the original report here, seems specific to windows, could you share a minimal version of your pogram taht triggers this on linux please?

[sopium]

@jimblandy the original report here, seems specific to windows, could you share a minimal version of your pogram taht triggers this on linux please?

I can reproduce with the following example, but not reliably. (And I wasn't able to reproduce it with smol directly.)

use std::time::Duration;

fn main() {
    async_std::task::block_on(async {
        loop {
            futures_timer::Delay::new(Duration::from_secs(1)).await;
        }    
    })
}

[sopium]

I have a reproduce with smol directly. Will open a issue there.

[dignifiedquire]

Please retest with [email protected] by running cargo update

[almetica]

@dignifiedquire [email protected] looks fine now. Idle CPU consumption seems normal now. The traces I just did seem to confirm this assumption.