parallel queries would run sequential at hyper:0.12.8

[jtong11]

I have detected this confusing runtime with the following example code:

// futures = "0.1"
// hyper = "0.12.8"
// signal-hook = "0.1.8"
extern crate futures;
extern crate hyper;
extern crate signal_hook;

use futures::{Future, Stream};
use hyper::service::service_fn;
use hyper::{Body, Request, Response, Server, StatusCode};

use signal_hook::{iterator::Signals, SIGINT, SIGTERM};
use std::thread;
use std::time::{Duration, SystemTime};

type HyperResult = Box<dyn Future<Item = Response, Error = hyper::Error> + 'static + Send>;

fn http_func(req: Request) -> HyperResult {
let body = req.into_body();
println!(
"http_func 1 {:?} {:?}",
SystemTime::now(),
thread::current().id(),
);
Box::new(body.concat2().map(move |_chunk| {
println!(
"http_func 2 {:?} {:?}",
SystemTime::now(),
thread::current().id(),
);
thread::sleep(Duration::from_millis(11));
let empty: &[u8] = b"{}";
Response::builder()
.status(StatusCode::OK)
.body(empty.into())
.unwrap()
}))
}

fn start_http_server(port: u16) {
thread::spawn(move || {
let func = move || service_fn(move |req| http_func(req));
let address = ([0, 0, 0, 0], port).into();
let srv = Server::bind(&address)
.serve(func)
.map_err(|e| eprintln!("server has got an error: {}", e));
hyper::rt::run(srv);
});
}

fn main() {
start_http_server(9527);
let signals = Signals::new(&[SIGINT, SIGTERM]).unwrap();
for _sig in signals.forever() {
break;
}
}

I call it at my server which has 36cpus and 0.5 loadavg, using 8-parallel same queries : '''curl "127.0.0.1:9527" &>/dev/null &'''
,and the confused output like this:

http_func 1 SystemTime { tv_sec: 1602660815, tv_nsec: 789723920 } ThreadId(15)
http_func 2 SystemTime { tv_sec: 1602660815, tv_nsec: 789736249 } ThreadId(15)
http_func 1 SystemTime { tv_sec: 1602660815, tv_nsec: 789950696 } ThreadId(17)
http_func 2 SystemTime { tv_sec: 1602660815, tv_nsec: 789959925 } ThreadId(17)
http_func 1 SystemTime { tv_sec: 1602660815, tv_nsec: 790090523 } ThreadId(3)
http_func 2 SystemTime { tv_sec: 1602660815, tv_nsec: 790098104 } ThreadId(3)
http_func 1 SystemTime { tv_sec: 1602660815, tv_nsec: 801226940 } ThreadId(5)
http_func 2 SystemTime { tv_sec: 1602660815, tv_nsec: 801236823 } ThreadId(5)
http_func 1 SystemTime { tv_sec: 1602660815, tv_nsec: 801243113 } ThreadId(15)
http_func 2 SystemTime { tv_sec: 1602660815, tv_nsec: 801255758 } ThreadId(15)
http_func 1 SystemTime { tv_sec: 1602660815, tv_nsec: 801275338 } ThreadId(7)
http_func 2 SystemTime { tv_sec: 1602660815, tv_nsec: 801284322 } ThreadId(7)
http_func 1 SystemTime { tv_sec: 1602660815, tv_nsec: 801261795 } ThreadId(18)
http_func 2 SystemTime { tv_sec: 1602660815, tv_nsec: 801299670 } ThreadId(18)
http_func 1 SystemTime { tv_sec: 1602660815, tv_nsec: 801259919 } ThreadId(17)
http_func 2 SystemTime { tv_sec: 1602660815, tv_nsec: 801311600 } ThreadId(17)

also 4 parallel:
http_func 1 SystemTime { tv_sec: 1602666799, tv_nsec: 685663417 } ThreadId(3)
http_func 2 SystemTime { tv_sec: 1602666799, tv_nsec: 685676261 } ThreadId(3)
http_func 1 SystemTime { tv_sec: 1602666799, tv_nsec: 685663383 } ThreadId(9)
http_func 2 SystemTime { tv_sec: 1602666799, tv_nsec: 685690930 } ThreadId(9)
http_func 1 SystemTime { tv_sec: 1602666799, tv_nsec: 796806099 } ThreadId(3)
http_func 2 SystemTime { tv_sec: 1602666799, tv_nsec: 796811401 } ThreadId(3)
http_func 1 SystemTime { tv_sec: 1602666799, tv_nsec: 796830727 } ThreadId(15)
http_func 2 SystemTime { tv_sec: 1602666799, tv_nsec: 796838790 } ThreadId(15)

Some sleep-calls start after 11ms, It seems that some threads consume two or more tasks serially?

[sfackler]

thread::sleep blocks the entire OS thread, preventing other nonblocking tasks from running.

[seanmonstar]

Yes, this is the nature of futures in Rust. Multiple futures can be handled on the same thread, since each usually yields when waiting on IO. You should not do blocking operations inside a future (like sleeping a thread).

[jtong11]

Yes, this is the nature of futures in Rust. Multiple futures can be handled on the same thread, since each usually yields when waiting on IO. You should not do blocking operations inside a future (like sleeping a thread).

Hi, @seanmonstar, in the example code, I just use the thread-sleep to mock the action which actually cost 11ms. It truly happened in my prod server and make our p95-time double.
We suspect the tokio's work-stealing thread-pool of this version, and found tokio-rs/tokio#1657 and https://tokio.rs/blog/2019-10-scheduler.
And we will update the hyper to the newest version, comment the result whether resolved.
Thanks.