Request is handled always by the same worker thread

[brunneng]

Description

In rocker 0.5.0-rc.2 all calls to endpoint are handled by the same worker thread. I have 16 worker threads by default.
If I put thread sleep 5 seconds in the request handler then the second concurrent call is not handled until the first call is finished.
I expected that different workers should handle calls.

To Reproduce
Here is my test program:

#[macro_use] extern crate rocket;

use std::thread;
use thread_id;
use std::time::Duration;
use rocket::{Build, Rocket};
use rocket::tokio::time::sleep;

#[get("/aaa")]
fn aaa() -> &'static str {
    println!("Before sleep in thread: {}", thread_id::get());
    thread::sleep(Duration::from_secs(5));
    println!("After sleep in thread: {};", thread_id::get());
    "Hello, from aaa!"
}

#[get("/bbb")]
async fn bbb() -> &'static str {
    println!("Before sleep in thread: {}", thread_id::get());
    sleep(Duration::from_secs(5)).await;
    println!("After sleep in thread: {};", thread_id::get());

    "Hello, from bbb!"
}

#[launch]
fn rocket() -> Rocket<Build> {
    rocket::build().mount("/", routes![aaa, bbb])
}

Cargo.toml:

[package]
name = "rocket-test"
version = "0.1.0"
edition = "2021"

# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html

[dependencies]
thread-id= "4.0.0"
rocket = "0.5.0-rc.2"

On startup it prints:

Configured for debug.
   >> address: 127.0.0.1
   >> port: 8000
   >> workers: 16
   >> ident: Rocket
   >> limits: bytes = 8KiB, data-form = 2MiB, file = 1MiB, form = 32KiB, json = 1MiB, msgpack = 1MiB, string = 8KiB
   >> temp dir: C:\Users\brunn\AppData\Local\Temp\
   >> http/2: true
   >> keep-alive: 5s
   >> tls: disabled
   >> shutdown: ctrlc = true, force = true, grace = 2s, mercy = 3s
   >> log level: normal
   >> cli colors: true

Note: workers: 16.
Now we can call endpoint aaa. For this quickly refresh two open tabs in browser with line: http://127.0.0.1:8000/aaa
In logs we can see:

GET /aaa text/html:
   >> Matched: (aaa) GET /aaa
Before sleep in thread: 28948
After sleep in thread: 28948;
   >> Outcome: Success
   >> Response succeeded.
GET /aaa text/html:
   >> Matched: (aaa) GET /aaa
Before sleep in thread: 28948
After sleep in thread: 28948;
   >> Outcome: Success
   >> Response succeeded.

As you can see thread id is the same. The second request takes ~ 10 seconds to execute because of sequential execution but should be 5.

The same situation if we try to use async endpoint /bbb.

Expected Behavior

Requests should execute independently by random workers.

Environment:

• OS Windows 11
• Rocket Version: 0.5.0-rc.2

Additional Context

If I run requests using curl from 2 cmd windows everything seems fine - different threads are picked for each request. But I don't understand why.
I also can reproduce the issue with postman.

[SergioBenitez]

This is your browser serializing requests, not Rocket. Try using two different browsers to issue the two requests.

[brunneng]

Ok. I tried edge (1st tab) + chrome (2nd tab) - the same.

[SergioBenitez]

It's possible that these are using the same engine underneath in some way, or that there's something else going on on Windows. Are you sure you have more than one available worker? I can't reproduce this on Linux using Chrome and Firefox, nor on MacOS. If you have no issue using two curl sessions, then there shouldn't be an issue using two different browsers. Rocket doesn't distinguish or handle requests differently based on the client.

I would try 1) two browsers based on different engines, say Chrome and Firefox, or Edge and Firefox, 2) try a different server and see if it reacts in the same manner.

[SergioBenitez]

@brunneng In your GIF, you make a request to /aaa, not /bbb; does the same issue occur with /bbb? If not, either what I mentioned above could be the case, or this could be a known bug in tokio (tokio-rs/tokio#4730). See also #2239.

[brunneng]

For aaa endpoint reproduced on chrome + firefox. See gif:

[brunneng]

For bbb endpoint situation is better, the request is handled concurrently, but still by the same thread.

[brunneng]

And I can't reproduce it in a very similar app on spring boot (tomcat server):

[SergioBenitez]

the request is handled concurrently, but still by the same thread.

That's fine. This isn't a problem since the thread is free. We would only expect another thread to be used with certainty if parallelism is required. That is, if the thread were busy.

Given what we're seeing, I'm leaning towards saying that this is an issue with tokio (tokio-rs/tokio#4730). To confirm, could you run this modified example (modified from tokio-rs/tokio#4730 (comment))? If this is an issue with tokio, we would expect the blocked scheduler to be unblocked at most 1 second after the second request. That is, if you make a request from two browsers, a second thread should handle the second request at most one second after it is made:

#[macro_use] extern crate rocket;

use std::time::Duration;

#[get("/")]
fn index() -> &'static str {
    println!("Before sleep in thread: {}", thread_id::get());
    std::thread::sleep(Duration::from_secs(5));
    println!("After sleep in thread: {}", thread_id::get());
    "Hello, from aaa!"
}

#[launch]
fn rocket() -> _ {
    let rt_handle = rocket::tokio::runtime::Handle::current();
    std::thread::spawn(move || {
        loop {
            std::thread::sleep(Duration::from_secs(1));
            rt_handle.spawn(std::future::ready(()));
        }
    });

    rocket::build().mount("/", routes![index])
}

If this works, comment out lines 15 through 21 and confirm that the code still exhibits the erroneous behavior. If it does, we've found tokio to be the culprit, unfortunately.

And I can't reproduce it in a very similar app on spring boot (tomcat server):

Good. This means there's definitely no serialization going on from the browser side.

[brunneng]

Seems helped. However, I set the delay to 3 seconds, to see it better.

After removing lines 15-21 - the issue reproduced again.

[SergioBenitez]

Thanks for running that. Unfortunately this confirms that this is an issue with tokio, specifically tokio-rs/tokio#4730. I would recommend you follow-up there. Short of abandoning tokio, there isn't much we can do.