Too long network exchange

1

Hello!

I have small client - server example. I run in at local computer and send "hello world" between client-server-client and back.
Why does it take too long to exchange a phrase (40-60 ms)?

Time hist:
client to server: 1753091773111 ms
get on server: 1753091773188 ms
send from server to client: 1753091773189 ms
get on client: 1753091773190 ms

Example:

use std::time::{SystemTime, UNIX_EPOCH};

use tokio::net::{TcpListener, TcpStream};
use tokio::io::{AsyncReadExt, AsyncWriteExt, BufWriter};

#[tokio::main]
async fn main() -> Result<(), Box<dyn std::error::Error>> {
    println!("Start server!");
    let listener = TcpListener::bind("127.0.0.1:8080").await?;
    loop {
        let (mut stream, _) = listener.accept().await?;
        stream.set_nodelay(true)?;
        
        let mut buf = [0; 1024];
        let n = stream.read(&mut buf).await?;
        println!("Read time: {:?}", SystemTime::now().duration_since(UNIX_EPOCH).unwrap().as_millis());
        let start_time = SystemTime::now();
        //println!("Get data from client: {:?}", buf);
        let mut writer = BufWriter::new(stream);
        writer.write_all(&buf[..n]).await?;
        writer.flush().await?;
        println!("Elapsed write time: {:?}", start_time.elapsed());
        println!("Send time: {:?}", SystemTime::now().duration_since(UNIX_EPOCH).unwrap().as_millis());
    }
}


#[cfg(test)]
mod tests {
    use std::time::{SystemTime, UNIX_EPOCH};

    use tokio::{io::{AsyncReadExt, AsyncWriteExt}, net::TcpStream};

    #[tokio::test]
    async fn test_echo_server() {
        let mut stream = TcpStream::connect("127.0.0.1:8080").await.unwrap();
        let _ = stream.set_nodelay(true);
        let test_data = b"hello world";
        
        let start_time = SystemTime::now();
        stream.write_all(test_data).await.unwrap();
        println!("Write time: {:?}", SystemTime::now().duration_since(UNIX_EPOCH).unwrap().as_millis());
        println!("Elapsed write time: {:?}", start_time.elapsed());
        
        let mut buf = [0; 1024];
        let n = stream.read(&mut buf).await.unwrap();
        println!("Read time: {:?}", SystemTime::now().duration_since(UNIX_EPOCH).unwrap().as_millis());
        println!("Elapsed all time: {:?}", start_time.elapsed());
        
        assert_eq!(&buf[..n], test_data);
    }
}
1 Like
2

You could use a profiling tool like flamegraph to find out where the bottlenecks are. I don't immediately see anything wrong with your code, my guess would be that 99% of the wall-clock time you are measuring is IO latency.

3 Likes
3

You can try stream.set_quickack(true) instead of (or in addition to) stream.set_nodelay(true). set_quickack disables delayed acknowledgement while set_nodelay disables Nagle's algorithm. It is the combination of delayed acknowledgement and Nagle's algorithm that generally causes the 50ms delay, but it can't hurt trying to disable both I guess.

3 Likes
4

tokio stream doesn't have stream.set_quickack(true)

5

Right. It does have methods to convert to and from std::net::TcpStream though.

6

I tried running your code from the first post. If I understand the output correctly, I see no delay (0 ms) in the transfers.

I run the server with cargo run --release and the client with cargo test --release -- --no-capture in two separate terminals. Here's the output:

# CLIENT
Write time: 1753180841126
Elapsed write time: Ok(18.939µs)
Read time: 1753180841126
Elapsed all time: Ok(103.502µs)

# SERVER
Start server!
Read time: 1753180841126
Elapsed write time: Ok(19.671µs)
Send time: 1753180841126

I'm running on target x86_64-unknown-linux-gnu (Arch Linux), using Rust v1.88.0 and tokio v1.46.1 with full feature.

1 Like
7

This topic was automatically closed 90 days after the last reply. We invite you to open a new topic if you have further questions or comments.