High cpu usage on long requests.

[Leonqn]

Hello! Starting from 1.2 version this simple program consumes almost 50% of one cpu.

use std::time::Duration;

fn main() {
    async_std::task::spawn(isahc_loop());
    async_std::task::block_on(start_http());
}

async fn isahc_loop() {
    let isahc = isahc::HttpClient::new().unwrap();
    loop {
        println!("Start handling");
        let _resp = isahc.get_async("127.0.0.1:1234").await.unwrap();
    }
}

async fn start_http() -> async_std::io::Result<()> {
    let mut app = tide::with_state(());
    app.at("/").get(|_req: tide::Request<()>| async move {
        async_std::task::sleep(Duration::from_secs(30)).await;
        Ok(tide::Response::new(200))
    });
    app.listen("0.0.0.0:1234").await
}

On 1.1 version it works fine.

[sagebind]

Thanks for filing an issue, this definitely doesn't sound like intended behavior! I'll look into this as soon as I am able. Here are some things that might help me in preparation:

• What OS are you testing on?
• What version of async-std are you using?

[Leonqn]

This example was tested on macOS 11.5.2 with async-std 1.10.0.
But originally, I found this issue on our service(it uses long-poll requests) which is hosted on ubuntu 18.04 and uses async-std 1.9.0

[jacobmischka]

I can't admit to fully understanding what's going on here, the interface with curl's multi client is pretty confusing, but it seems that isahc's timer is not behaving as curl expects.

The timer provided by curl should be fired only once and not repeat (https://github.com/alexcrichton/curl-rust/blob/master/src/multi.rs#L207-L225), and does not seem to be explicitly cleared via the timer_function callback after firing. Thus, I think we merely need to clear the timer once it has expired, and then fall back to our default timeout until curl gives us something new.

#350

Before:

After:

[sagebind]

That's excellent detective work @jacobmischka, thanks for taking the time to look into it! Your analysis looks sound, and I'll be sure to get your fix into a release soon.

This is for sure a regression from when we switched from using curl's provided I/O selector to our own, since previously curl was managing the timers on our behalf (and presumably clearing the timer properly after it expires).

I can't admit to fully understanding what's going on here, the interface with curl's multi client is pretty confusing, but it seems that isahc's timer is not behaving as curl expects.

This is a good reminder for me to expand the documentation on Isahc's internals. Basically we're using the most advanced version of the multi interface described in Drive with multi_socket and using polling as our I/O driver since it uses the most low-latency selector across platforms. But the integration of the two is a little tricky so there is a fair bit of code around it.

[sagebind]

This is now fixed in the 1.5.1 release!