Performance regression between 2.3.0 and 2.5.0 - crossbeam-channel?

[njam]

I've observed a performance regression in an application after upgrading slog-async from 2.3.0 to 2.5.0. I guess it's due to the switch from mpsc-channel to crossbeam-channel.

The application is performing ~500 operations per second, each usually taking less than 0.5ms (99th percentile). After upgrading to slog-async 2.5.0 the average duration didn't change, but there are clearly more outliers. The 99th percentile is now 2-3ms.

I've reproduced the issue on 4 cloud VMs, 2x slog-async 2.3.0 and 2x slog-async 2.5.0, otherwise identical.

I have two theories:

• A: Adding an item to the crossbeam-channel sender is sometimes (rarely) slow
• B: Using crossbeam-channel saturates CPU resources stronger than mpsc for some reason (maybe also on the receiver side?)

Notes about the application setup:

• Logging approx. 30 messages per second, some messages with rather large payloads.
• Overflow strategy "DropAndReport"
• Channel size 100'000
• Rust 1.46.0

Do you have any thoughts on what could be causing this?
I'm mainly opening this ticket in case somebody else is experiencing similar issues. Not expecting any action, feel free to close the ticket again :)

[dpc]

That's quite possibly the root cause. Can't think of anything else. You could confirm by just running your test with pre-crossbeam version, or just revert that one change locally.

crossbeam-channel was supposed to be "faster on average", but I don't remember any claims about tail latency.

[vorner]

If I was to make an educated guess, then crossbeam-channel would be probably faster when there's some contention, while there would probably be little to no difference if it is mostly idle. However, it has kind of a GC thing that needs to run from time to time, so it could bring some tail latencies. Nevertheless, that 2-3ms looks like a really long time.

[njam]

Thanks for your feedback!
For now I've downgraded to slog-async 2.3.0 and it works fine. I will close this ticket now.

I will do some benchmarks comparing the tail latencies of crossbeam vs. mpsc. I will report the results back here.

[njam]

With @zazabe with did some benchmarks, comparing the performance of the send() function of three different channel libraries, here's the results:

• crossbeam::unbounded: average: 4.9µs, 99.99% quantile: 4.9ms
• std::sync::mpsc: average: 3.9µs, 99.9% quantile: 20.8µs
• flume::unbounded: average: 3.9µs, 99.9% quantile: 32.4µs

In this test we were using 4 CPU cores, and put a base load of 30% on all of them during the test (stress-ng -c 0 -l 30). The channel had 5 producers and 1 consumer, and each producer was sending 50_000 messages per second.

It seems that the mpsc tail latency for send() is better than crossbeam's.

[njam]

I guess the problem with crossbeam is that it runs kind of GC thing from time to time, which takes time on one of the CPUs.

@vorner in #23 (comment) you mention crossbeam's GC. Could you share a link to crossbeam's code where this is happening?

[vorner]

I think it would be this place: https://github.com/crossbeam-rs/crossbeam/blob/master/crossbeam-epoch/src/internal.rs#L278.

[njam]

I can't find any reference from "crossbeam-channel" to "crossbeam-epoch". The Cargo.toml also doesn't list it as a dependency. Are you sure it's used?

[vorner]

🤔 I'd have sworn it was used some years ago and haven't checked since then, but possibly it is not used any more.

[njam]

One theory we came up with is that this is happening due to the loops in the channel's start_send() and start_recv(), that might have more iteration under high load.