Performance regression (compared to `0.24.0`) when reading large (100 MB+) messages in `0.25.0+`

[ResuBaka]

With version 0.24 there where no problems in getting responses which where 50mb and bigger in the range of 900mb+ .

My question is how I can best debug or check which part could cause the problem that, it startet to make problems.
Before it could download with ~33mb/s from the websocket connection and now it looks like it does nothing.

Where could I best start to look which part could be the problematic part.

I have tested it with two different creates https://github.com/gbaranski/ezsockets and https://github.com/jgraef/reqwest-websocket/ which both work if I use version 0.24 but both stop working if I go to the newest version.

When you want I can also test it directly with https://github.com/snapview/tokio-tungstenite if there the problem is also if needed.

[daniel-abramov]

Ideally, you would need to minimize it to a small test (or benchmark, if you will) so that the behavior is reproducible. Once there, it would be easy to tell what's going on (and we would also be able to look deeper into a problem).

Meanwhile, can you test that the issue is not caused by these changes: #480? (that's the only significant change that was released in 0.25).

[ResuBaka]

Thanks for the feedback.

I'm going to see if I have time this week and create an example repository for testing the issue.

[ResuBaka]

I have now a poc of the slow down. https://github.com/ResuBaka/poc-tungstenite-speed-slowdown

For it looks like this in release mode for all three. I hope this can help to figure out where maybe the problem is. Even if I set the read buffer to like 4096 or 1024 or 1024 * 1024 it does not really change that much in the over all picture the speed of the message rev.

When you want to I can also make it easier to so the time diffs from shortly before the server starts to send and the client got the huge bytes message, when it makes it easier to debug. But just for having a code base to show it was fine for me to just have the log message timestamps to check.

0.26.2

2025-05-12T17:21:45.049555Z  INFO client_0_26_2: >>> 0 got str: Utf8Bytes(b"Sending message with size 10485760")
2025-05-12T17:21:45.069205Z  INFO client_0_26_2: >>> 0 got 10485760 bytes since last text message 19.60365ms
2025-05-12T17:21:45.460546Z  INFO client_0_26_2: >>> 0 got str: Utf8Bytes(b"Sending message with size 104857600")
2025-05-12T17:21:46.141720Z  INFO client_0_26_2: >>> 0 got 104857600 bytes since last text message 681.131114ms
2025-05-12T17:21:46.653036Z  INFO client_0_26_2: >>> 0 got str: Utf8Bytes(b"Sending message with size 1048576000")
2025-05-12T17:22:27.269929Z  INFO client_0_26_2: >>> 0 got 1048576000 bytes since last text message 40.616858696s
2025-05-12T17:22:27.569615Z  INFO client_0_26_2: >>> 0 got close with code 1000 and reason `Goodbye`
2025-05-12T17:22:27.587011Z  INFO client_0_26_2: Total time taken 43.030970228s with 1 concurrent clients, should be about 40 seconds.

0.25.0

>>> 1.0 MB took ~1.945538ms with speed ~514.0 MB/s
>>> 3.0 MB took ~4.07349ms with speed ~736.5 MB/s
>>> 6.0 MB took ~9.207506ms with speed ~651.6 MB/s
>>> 10.0 MB took ~10.794636ms with speed ~926.4 MB/s
>>> 20.0 MB took ~35.933194ms with speed ~556.6 MB/s
>>> 30.0 MB took ~63.478259ms with speed ~472.6 MB/s
>>> 40.0 MB took ~86.221869ms with speed ~463.9 MB/s
>>> 50.0 MB took ~122.983299ms with speed ~406.6 MB/s
>>> 60.0 MB took ~176.25438ms with speed ~340.4 MB/s
>>> 100.0 MB took ~402.728511ms with speed ~248.3 MB/s
>>> 1000.0 MB took ~30.959573234s with speed ~32.3 MB/s

0.24.0

>>> 1.0 MB took ~3.164009ms with speed ~316.1 MB/s
>>> 3.0 MB took ~10.006822ms with speed ~299.8 MB/s
>>> 6.0 MB took ~13.40817ms with speed ~447.5 MB/s
>>> 10.0 MB took ~16.4573ms with speed ~607.6 MB/s
>>> 20.0 MB took ~32.174915ms with speed ~621.6 MB/s
>>> 30.0 MB took ~50.774965ms with speed ~590.8 MB/s
>>> 40.0 MB took ~60.193908ms with speed ~664.5 MB/s
>>> 50.0 MB took ~73.569492ms with speed ~679.6 MB/s
>>> 60.0 MB took ~70.534721ms with speed ~850.6 MB/s
>>> 100.0 MB took ~132.966681ms with speed ~752.1 MB/s
>>> 1000.0 MB took ~4.574680947s with speed ~218.6 MB/s

Size	0.24.0	0.25.0	0.26.2
1.0 MB	~316.1 MB/s	~514.0 MB/s	~571.3 MB/s
3.0 MB	~299.8 MB/s	~736.5 MB/s	~1.3 GB/s
6.0 MB	~447.5 MB/s	~651.6 MB/s	~611.2 MB/s
10.0 MB	~607.6 MB/s	~926.4 MB/s	~762.9 MB/s
20.0 MB	~621.6 MB/s	~556.6 MB/s	~446.4 MB/s
30.0 MB	~590.8 MB/s	~472.6 MB/s	~395.8 MB/s
40.0 MB	~664.5 MB/s	~463.9 MB/s	~415.1 MB/s
50.0 MB	~679.6 MB/s	~406.6 MB/s	~290.2 MB/s
60.0 MB	~850.6 MB/s	~340.4 MB/s	~285.1 MB/s
100.0 MB	~752.1 MB/s	~248.3 MB/s	~195.7 MB/s
1000.0 MB	~218.6 MB/s	~32.3 MB/s	~24.4 MB/s

Size	0.24.0	0.25.0	0.26.2
1.0 MB	~3.164009ms	~1.945538ms	~1.750265ms
3.0 MB	~10.006822ms	~4.07349ms	~2.203095ms
6.0 MB	~13.40817ms	~9.207506ms	~9.817493ms
10.0 MB	~16.4573ms	~10.794636ms	~13.108573ms
20.0 MB	~32.174915ms	~35.933194ms	~44.802403ms
30.0 MB	~50.774965ms	~63.478259ms	~75.792776ms
40.0 MB	~60.193908ms	~86.221869ms	~96.3551ms
50.0 MB	~73.569492ms	~122.983299ms	~172.320872ms
60.0 MB	~70.534721ms	~176.25438ms	~210.429257ms
100.0 MB	~132.966681ms	~402.728511ms	~511.087715ms
1000.0 MB	~4.574680947s	~30.959573234s	~40.951381648s

[daniel-abramov]

Thanks for conducting multiple tests. I ran the early version of your tests on my machine without digging too much into the code.

Preliminary results on my machine with adjusted WebSocket configuration to have a fair starting point (changed read buffer settings):

• 0.25.0 performs slightly better than 0.24.0 on 10 MiB and 100 MiB messages, but much worse (~100% difference) on a 1000 MiB message.
• 0.26.0 performs slightly better than 0.24.0 on a 10 MiB message, a bit worse on 100 MiB messages (~10% difference), and it fails to complete the test on 1000 MiB messages (fails with an I/O error, which is very odd - to be investigated).

In the next step, I'd probably need to simplify the examples (there is a lot of unnecessary boilerplate, axum dependencies, unnecessary tokio tasks, etc) to ensure that the conditions are identical and then investigate what's going on.

[daniel-abramov]

@ResuBaka, just in case you're interested, our benchmarks for reading performance have so far been placed there: https://github.com/snapview/tungstenite-rs/blob/master/benches/read.rs If you want to eliminate third-party dependencies and other contributing factors, you might be interested in adding benchmarks that reflect your use case - that would allow us to see a more complete picture and have a reference point when comparing performance (it should be pretty straightforward to cover your use case, i.e. probably around 50 LOC).

[ResuBaka]

@daniel-abramov you mean something like this.

There is probably some things there could be improved. But does it go in the direction you meant with having a benchmark for message size?

//! Benchmarks for read performance.
use criterion::{BatchSize, BenchmarkId, Criterion, Throughput};
use std::{io::{self, Read, Write}, sync::{Arc, Mutex}};
use std::time::Duration;
use bytes::Bytes;
use rand::{rng, RngCore};
use tungstenite::{protocol::Role, Message, WebSocket};
use tungstenite::protocol::WebSocketConfig;

/// Mock stream with no artificial delays.
#[derive(Default, Clone)]
struct MockIo(Arc<Mutex<Vec<u8>>>);

impl Read for MockIo {
    fn read(&mut self, to: &mut [u8]) -> io::Result<usize> {
        let mut data = self.0.lock().unwrap();
        if data.is_empty() {
            return Err(io::Error::new(io::ErrorKind::WouldBlock, "not ready"));
        }
        let len = data.len().min(to.len());
        to[..len].copy_from_slice(data.drain(..len).as_slice());
        Ok(len)
    }
}

impl Write for MockIo {
    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
        self.0.lock().unwrap().write(buf)
    }
    fn flush(&mut self) -> io::Result<()> {
        Ok(())
    }
}

fn benchmark(c: &mut Criterion) {
    /// Benchmark reading 100k mix of binary & text messages.
    fn read_100k(role: Role, b: &mut criterion::Bencher<'_>) {
        let io = MockIo::default();
        let mut writer = WebSocket::from_raw_socket(
            io.clone(),
            match role {
                Role::Client => Role::Server,
                Role::Server => Role::Client,
            },
            None,
        );
        let mut ws = WebSocket::from_raw_socket(io, role, None);

        b.iter_batched(
            || {
                let mut sum = 0;
                for i in 0_u64..100_000 {
                    writer
                        .send(match i {
                            _ if i % 3 == 0 => Message::binary(i.to_le_bytes().to_vec()),
                            _ => Message::text(format!("{{\"id\":{i}}}")),
                        })
                        .unwrap();
                    sum += i;
                }
                sum
            },
            |expected_sum| {
                let mut sum = 0;
                while sum != expected_sum {
                    match ws.read().unwrap() {
                        Message::Binary(v) => {
                            let a: &[u8; 8] = v.as_ref().try_into().unwrap();
                            sum += u64::from_le_bytes(*a);
                        }
                        Message::Text(msg) => {
                            let i: u64 = msg.as_str()[6..msg.len() - 1].parse().unwrap();
                            sum += i;
                        }
                        m => panic!("Unexpected {m}"),
                    }
                }
            },
            BatchSize::SmallInput,
        );
    }

    c.bench_function("read+unmask 100k small messages (server)", |b| {
        read_100k(Role::Server, b);
    });

    c.bench_function("read 100k small messages (client)", |b| {
        read_100k(Role::Client, b);
    });

    /// Benchmark reading 100k mix of binary & text messages.
    fn read_big_messages_10(role: Role, b: &mut criterion::Bencher<'_>, message: Bytes, iterations: usize, web_socket_config: Option<WebSocketConfig>) {
        let mut io = MockIo::default();
        let mut writer = WebSocket::from_raw_socket(
            io.clone(),
            match role {
                Role::Client => Role::Server,
                Role::Server => Role::Client,
            },
            None,
        );
        let mut ws = WebSocket::from_raw_socket(io, role, web_socket_config);

        b.iter_batched(
            || {
                let mut sum = 0;
                for _i in 0..iterations {
                    writer
                        .send(Message::Binary(message.clone()))
                        .unwrap();
                    sum += message.len();
                }
                sum
            },
            |expected_sum| {
                let mut sum = 0;
                while sum != expected_sum {
                    match ws.read().unwrap() {
                        Message::Binary(v) => {
                            sum += v.len();
                        }
                        m => panic!("Unexpected {m}"),
                    }
                }
            },
            BatchSize::SmallInput,
        );
    }

    static KB: usize = 1024;
    static MB: usize = 1024 * 1024;

    let mut group = c.benchmark_group("message_size_small");
    for size in [12, KB, 2 * KB, 4 * KB, 8 * KB, 16 * KB].iter() {
        for read_buffer_size in [None, Some(64 * KB), Some(256 * KB), Some(512 * KB), Some(MB)].iter() {
            let (websocket_config, name) = if let Some(read_buffer_size) = read_buffer_size {
                (Some(WebSocketConfig::default().read_buffer_size(*read_buffer_size)), format!("{size} {read_buffer_size}"))
            } else {
                (None, format!("{size} Default"))
            };
            let iterations = 1_000;

            group.throughput(Throughput::Bytes(*size as u64 * iterations));
            group.bench_with_input(BenchmarkId::from_parameter(name), size, |b, &size| {
                read_big_messages_10(Role::Client, b, generate_repeated_random_bytes(size), iterations as usize, websocket_config);
            });
        }
    }
    group.finish();

    let mut group = c.benchmark_group("message_size_middle");
    for size in [64 * KB, 256 * KB, 512 * KB, MB, 2 * MB, 4 * MB, 8 * MB].iter() {
        for read_buffer_size in [None, Some(64 * KB), Some(256 * KB), Some(512 * KB), Some(MB)].iter() {
            let (websocket_config, name) = if let Some(read_buffer_size) = read_buffer_size {
                (Some(WebSocketConfig::default().read_buffer_size(*read_buffer_size)), format!("{size} {read_buffer_size}"))
            } else {
                (None, format!("{size} Default"))
            };
            let iterations = 100;

            group.throughput(Throughput::Bytes(*size as u64 * iterations));
            group.measurement_time(Duration::from_secs(15));
            group.bench_with_input(BenchmarkId::from_parameter(name), size, |b, &size| {
                read_big_messages_10(Role::Client, b, generate_repeated_random_bytes(size), iterations as usize, websocket_config);
            });
        }
    }
    group.finish();

    let mut group = c.benchmark_group("message_size_big");
    for size in [16 * MB, 32 * MB, 48 * MB, 64 * MB, 128 * MB].iter() {
        for read_buffer_size in [None, Some(64 * KB), Some(256 * KB), Some(512 * KB), Some(MB)].iter() {
            let (websocket_config, name) = if let Some(read_buffer_size) = read_buffer_size {
                (Some(WebSocketConfig::default().read_buffer_size(*read_buffer_size)), format!("{size} {read_buffer_size}"))
            } else {
                (None, format!("{size} Default"))
            };
            let iterations = 100;

            group.throughput(Throughput::Bytes(*size as u64 * iterations));
            group.sample_size(30);
            group.bench_with_input(BenchmarkId::from_parameter(name), size, |b, &size| {
                read_big_messages_10(Role::Client, b, generate_repeated_random_bytes(size), iterations as usize, websocket_config);
            });
        }
    }
    group.finish();


    let mut group = c.benchmark_group("message_size_huge");
    for size in [256 * MB, 512 * MB, 1024 * MB].iter() {
        for read_buffer_size in [None, Some(64 * KB), Some(256 * KB), Some(512 * KB), Some(MB)].iter() {
            let (websocket_config, name) = if let Some(read_buffer_size) = read_buffer_size {
                (Some(WebSocketConfig::default().read_buffer_size(*read_buffer_size).max_frame_size(None).max_message_size(None)), format!("{size} {read_buffer_size}"))
            } else {
                (Some(WebSocketConfig::default().max_frame_size(None).max_message_size(None)), format!("{size} Default"))
            };
            let iterations = 100;

            group.throughput(Throughput::Bytes(*size as u64 * iterations));
            group.sample_size(10);
            group.bench_with_input(BenchmarkId::from_parameter(name), size, |b, &size| {
                read_big_messages_10(Role::Client, b, generate_repeated_random_bytes(size), iterations as usize, websocket_config);
            });
        }
    }
    group.finish();
}

fn generate_repeated_random_bytes(size: usize) -> Bytes {
    if size == 0 {
        return Bytes::new();
    }

    const INITIAL_BUFFER_SIZE: usize = 256 * 1024; // 1KB
    let mut initial_buffer = vec![0u8; INITIAL_BUFFER_SIZE];
    rng().fill_bytes(&mut initial_buffer);
    let initial_bytes = Bytes::from(initial_buffer);

    let mut final_buffer = Vec::with_capacity(size);
    let mut remaining_size = size;

    while remaining_size > 0 {
        let bytes_to_copy = std::cmp::min(remaining_size, initial_bytes.len());
        final_buffer.extend_from_slice(&initial_bytes[..bytes_to_copy]);
        remaining_size -= bytes_to_copy;
    }

    Bytes::from(final_buffer)
}

criterion::criterion_group!(
    name = read_benches;
    config = Criterion::default();
    targets = benchmark
);
criterion::criterion_main!(read_benches);

[ResuBaka]

I have updated the benchmark script so it runs with a matrix of messages size and read_buffer_size.

Starting with the benchmark group message_size_middle/262144 it is the first that is more or less slow over all read sizes. As I'm not really my expertise I can not really understand directly from the code why it is slows so much done when reading chunks of memory or where the overhead in the small amount of code before hand comes directly.

I hope these benchmarks help to see/find where maybe the bottleneck is in the read path.

message_size_middle/262144 Default
                        time:   [134.36 ms 134.55 ms 134.77 ms]
                        thrpt:  [185.51 MiB/s 185.80 MiB/s 186.07 MiB/s]
Found 2 outliers among 100 measurements (2.00%)
  2 (2.00%) high mild
Benchmarking message_size_middle/262144 65536: Warming up for 3.0000 s
Warning: Unable to complete 100 samples in 15.0s. You may wish to increase target time to 21.6s, or reduce sample count to 60.
message_size_middle/262144 65536
                        time:   [135.12 ms 136.92 ms 139.24 ms]
                        thrpt:  [179.55 MiB/s 182.59 MiB/s 185.02 MiB/s]
Found 6 outliers among 100 measurements (6.00%)
  2 (2.00%) high mild
  4 (4.00%) high severe
Benchmarking message_size_middle/262144 262144: Warming up for 3.0000 s
Warning: Unable to complete 100 samples in 15.0s. You may wish to increase target time to 21.1s, or reduce sample count to 70.
message_size_middle/262144 262144
                        time:   [133.55 ms 134.49 ms 135.55 ms]
                        thrpt:  [184.43 MiB/s 185.89 MiB/s 187.19 MiB/s]
Found 15 outliers among 100 measurements (15.00%)
  6 (6.00%) high mild
  9 (9.00%) high severe
Benchmarking message_size_middle/262144 524288: Warming up for 3.0000 s
Warning: Unable to complete 100 samples in 15.0s. You may wish to increase target time to 22.2s, or reduce sample count to 60.
message_size_middle/262144 524288
                        time:   [133.20 ms 133.43 ms 133.65 ms]
                        thrpt:  [187.05 MiB/s 187.36 MiB/s 187.68 MiB/s]
Found 11 outliers among 100 measurements (11.00%)
  11 (11.00%) low mild
message_size_middle/262144 1048576
                        time:   [46.062 ms 46.507 ms 47.021 ms]
                        thrpt:  [531.67 MiB/s 537.55 MiB/s 542.74 MiB/s]
Found 15 outliers among 100 measurements (15.00%)
  5 (5.00%) high mild
  10 (10.00%) high severe

[alexheretic]

I'd guess this is due to the newer versions providing a read buffer the full size of the message, and with the message being very large this is less efficient than reading in chunks for the Read impl being used.

If so we can optimise with some max read chunk size. I can probably take a look at this.

I think it would make sense to have new benchmarks for single message perf across a range of sizes but using a more realistic Read impl.

[alexheretic]

My ^ 3:30AM guess seems to be correct 😄