Watch channel with many subscribers has sub-optimal multithreaded performance

[tijsvd]

Version

tokio v1.24.2

Platform

Linux x1 5.15.0-58-generic #64~20.04.1-Ubuntu SMP Fri Jan 6 16:42:31 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Description

Hi,

I encountered a performance issue in tokio::sync::watch. The usage pattern is something like:

• there is a large number of networked subscribers
• something happens centrally (reception of message from upstream)
• that something is broadcast around using a watch channel
• every subscriber has a little task running, which waits for changes on the channel, takes the latest value, does some subscriber-specific processing, sends out a message, and goes back to waiting

We use watch here instead of broadcast because we care only about the latest value, and this is an elegant way to deal with slow clients. I would think is a fairly typical use case for watch channel.

While doing some benchmarking, I saw a massive decay in throughput (actually received messages) moving from flavor="current_thread" to multi-thread. Also, I expected high CPU usage due to parallel per-subscriber processing. Instead, CPU stayed around 130-180% on a 8-vcore machine.

I have sort of reduced it to this example program:

use std::time::Duration;                                                                                           
use tokio::sync::watch;                                                                                            
use tokio::time::sleep;                                                                                            
                                                                                                                   
#[tokio::main]                                                                                                     
async fn main() {                                                                                                  
    let (snd, _) = watch::channel(0i32);                                                                           
    for _ in 0..1000 {                                                                                             
        let mut rcv = snd.subscribe();                                                                             
        tokio::spawn(async move {                                                                                  
            loop {                                                                                                 
                if rcv.changed().await.is_err() {                                                                  
                    break;                                                                                         
                }                                                                                                  
                // read lock                                                                                       
                let _ = *rcv.borrow();                                                                             
            }                                                                                                      
        });                                                                                                        
    }                                                                                                              
    for i in 0..1000 {                                                                                             
        sleep(Duration::from_millis(1)).await;                                                                     
        let _ = snd.send(i);                                                                                       
    }                                                                                                              
}                                                                                                                  

Not much happens here, yet running this reports almost 6 seconds of CPU time used, of which 1.6 system time. Changing to #[tokio::main(flavor="current_thread")] changes that to hardly anything (0.35s user time, 0.05s system). Also, running with strace shows a lot of futex calls.

So apparently there's a lot of lock contention. Digging into it, I think (well, reasonably sure) that the following happens.

• calling send on the watch::Sender translates to Notify::notify_waiters; this by itself is fine, it sets all waiting tasks as runnable without locks held
• tasks start running, and worker threads start stealing some
• multiple threads are now processing the subscription tasks, and since they're fairly short, many end around the same time
• at the end of the task loop, the tasks will go back to waiting on the same channel, which requires re-registering with the Notify
• the waiter list inside the Notify is behind a mutex, and this is where the contention is.

If we accept that this is indeed a fairly typical use case, then it could, I think, be solved by making a different trade-off between send/receive performance and clone/subscribe/drop overhead:

• give each receiver a unique 64-bit ID, allocated from an AtomicU64 in the shared state;
• each receiver also has a Arc<AtomicWaker>;
• inside shared state, instead of a notifier, maintain a Mutex<HashMap<u64, Arc<AtomicWaker>>>, which is accessed in Sender::send, Sender::subscribe, Receiver::clone and Receiver::drop only, so not in Receiver::changed.

Sender code is then something like:

... // update value
... // update version
let wakers = inner
  .subscriptions
  .lock()
  .values()
  .filter_map(|w| w.take())
  .collect::<Vec<_>>(); // FIXME reuse vector capacity
for waker in wakers {
  waker.wake();
}

Changing my example case above to something like this, reduces the CPU overhead to ~1sec, all of which user time. There is still non-negligible overhead (contention on the rwlock cache line), but no thread stalls.

I did something like this in my production code, which solved the problem. I actually created a special type of notifier, which is another consideration, but the use cases for Notify are probably more diverse than watch.

[gustav3d]

I also had to implemented a specialized notifier due to how horrible the default one is vs whats optimal for some cases.

[carllerche]

@gustav3d We are always happy to hear proposals (and eventually PRs) to improve performance. Please share your strategy.

[carllerche]

@tijsvd Try updating your benchmark to the following and run again:

#[tokio::main]                                                                                                     
async fn main() {
    tokio::spawn(async {
            let (snd, _) = watch::channel(0i32);                                                                           
            for _ in 0..1000 {                                                                                             
                let mut rcv = snd.subscribe();                                                                             
                tokio::spawn(async move {                                                                                  
                    loop {                                                                                                 
                        if rcv.changed().await.is_err() {                                                                  
                            break;                                                                                         
                        }                                                                                                  
                        // read lock                                                                                       
                        let _ = *rcv.borrow();                                                                             
                    }                                                                                                      
                });                                                                                                        
            }                                                                                                              
            for i in 0..1000 {                                                                                             
                sleep(Duration::from_millis(1)).await;                                                                     
                let _ = snd.send(i);                                                                                       
            } 
    }).await.unwrap();                                                                                                
}  

[tijsvd]

Try updating your benchmark to the following and run again

I did, it improves the benchmark performance a lot. There is still considerable overhead compared to single-thread or mutex-free notification.

However, strace shows nothing at all now during the processing, which would indicate that no threads are being parked / unparked? I find this behaviour weird. Cpu does seem to be spread over the worker threads. Could it be that all workers wait for the sleep (no syscall?), one wins, the others go back to sleep, and the one worker just executes all the futures with no work stealing? I would expect that if any worker wakes up 1000 tasks, it should post some notification? Or does it, but that doesn't show up as a traceable syscall?

I'll dig into this a bit more tomorrow. I could not find a good description of how the scheduler / work stealing is actually supposed to work. I noticed that the original main thread does not actually participate in the scheduler, it runs only the join handle? Do the worker threads all run epoll, or would all incoming I/O then come from the main thread, and would all futures awoken by I/O also run on the main thread? (In which case the improvement of the benchmark is moot, as events would be caused by incoming network messages.)

Edit: never mind about strace, I was running it incorrectly (without -f). @carllerche can you explain why this change should make a large difference?

[tijsvd]

can you explain why this change should make a large difference?

To answer my own question: if the main thread only runs the "main" task, and all spawned tasks are run only on worker threads, then if the main task causes all events, the worker threads are awoken at the same time, so mutex contention is heaviest. If one of the worker threads causes the events, it should be able to process a significant chunk of the waiters before the other threads are even ready to steal the work.

But that is then mostly an artifact of the (admittedly far from perfect) benchmark -- the receiver tasks don't do any real work. Where I observed this in pre-production testing, the event source was a spawned task, but the receivers did more work per event, so the division of work across threads would have been more even.

[tijsvd]

I put together a more detailed benchmark here: https://github.com/tijsvd/tokio-watch-benchmark

It performs some actual work in each receiver, and instead of looking at CPU, it measures the latency from send until the last receiver has finished its work. I also put together a quick-and-dirty watch channel as proposed, and it's measured as well.

Output on my laptop (8 threads):

TOKIO WATCH
running single thread
avg=2.649624ms  <2.476153ms [ 2.649857ms 2.666352ms 2.68224ms ] 2.836277ms>
running multi thread with main thread sender
avg=1.286592ms  <1.079605ms [ 1.203281ms 1.276133ms 1.373721ms ] 1.505286ms>
running multi thread with spawned sender
avg=1.29789ms  <1.184666ms [ 1.255816ms 1.291815ms 1.337994ms ] 1.425623ms>
CUSTOM WATCH
running single thread
avg=2.695562ms  <2.645752ms [ 2.694761ms 2.707446ms 2.714412ms ] 2.748192ms>
running multi thread with main thread sender
avg=1.036344ms  <983.935µs [ 1.007991ms 1.026612ms 1.058813ms ] 1.123364ms>
running multi thread with spawned sender
avg=960.654µs  <901.185µs [ 952.338µs 963.354µs 974.377µs ] 993.665µs>

[carllerche]

More info here: #5446

[tijsvd]

More info here

Right, that issue is about having to cross a thread boundary. In this case, we're actually looking to cross a thread boundary, in order to spread the work in the multiple receivers. I think the more real-world benchmark above shows that it doesn't really matter much.

If there is broader consensus that send/receive performance for watch channels is more important than subscribe/drop, then I'd be happy to volunteer a PR. In that case I'd like some feedback on the best setup:

• a change local to the watch module, or
• use of an internal new notify construct that may be used for other cases, if we can identify them, or
• a new public construct like Notify -- but it'd be hard to explain the difference, and a watch::channel(()) is probably more ergonomic for most use cases.

[Darksonn]

Before you start working a PR, I would like to hear a description of the idea behind your solution. I note that the current implementation does not allocate memory in changed or when creating a new receiver.

[tijsvd]

The idea is to trade the mutex that protects the list of waiters, against a pre-registration of waker slots.

That means a new receiver would allocate memory. No need to allocate in changed, that would remain mostly the same (except currently it's spread between Receiver::changed and Notify::notified).

The allocation for the receiver could be avoided by using some kind of custom allocator and a block of atomic wakers in the shared state, but that would likely have a negative performance effect on changed due to false sharing of cache lines.

Note that currently there may also be some mutex contention between send and changed, if more than 32 subscribers, due to the outer loop in Notify::notify_waiters. I don't know if that is relevant; likely not in an otherwise quiet situation, but perhaps more important if worker threads are awake and able to immediately react on the task wakeup. Trading a mutex on waiters with a mutex on subscriptions would also restrict this kind of contention to a situation where receiving tasks drop the receiver in reaction to the changed value.

Prototype (not otherwise optimised) here: https://github.com/tijsvd/tokio-watch-benchmark/blob/master/src/mywatch.rs

If all this sounds scary because of the larger overhead of Receiver::clone() / Receiver::drop(), then feel free to close -- again, I'm just signalling that this was a problem in my use case, but that doesn't mean it's the same for everyone.

I notice that broadcast channel uses a similar mutex-protected waitlist, so it might run into the same issue.

The issue as I see it is mostly about stalling worker threads on an OS-level lock, leading to insufficient speedup of the total work to be done on the number of cores available. Other "solutions" are available as well, but may be less generally good:

• start more worker threads than cores, and let the OS care about utilisation
• use a spinlock for these known-very-short-duration locks, in Notify and broadcast channel.

Edit: one more downside of what I propose, the sender will always iterate through the entire set of receivers; the assumption then is that most receivers would normally be waiting.

[Darksonn]

Okay, so it uses an Mutex<HashMap<u64, Arc<AtomicWaker>>> so it can give each receiver an Arc<AtomicWaker>. Creating the Arc<AtomicWaker> objects does involve many allocations that would be preferable to avoid if possible.

If all this sounds scary because of the larger overhead of Receiver::clone() / Receiver::drop(), then feel free to close.

Regardless of how much I like your suggested solution, the problem definitely sounds like a real problem, and it would be good to find a solution.