Search code examples
rustconcurrencyrequest

requests are 95% faster just for commenting a print statement?


main-reference rust book

the modified code for above program listed is


fn main() {
    let (tx1, rx) = mpsc::channel();

    thread::spawn(move || {
        tx1.send("hi2").unwrap();
    });

    let mut count = 0;

    loop {
        match rx.try_recv() {
            Ok(msg) => {
                println!("{:?}", msg);
                break;
            }
            Err(_) => {
                // println!("not yet");
                count += 1;
            }
        }
    }
    print!("{:?}", count)
}

if i commented out the println statement the count is approx above 1646 as its varying everytime but it is around 10-20 if its not commented out can someone please explain why

update1: as per the comments i tried replacing println with std::io::stdout().write(b"not yet").unwrap(); and the count is around 350-380 and if im using this instead let mut buffer = std::io::BufWriter::new(std::io::stdout()); buffer.write(b"not yet").unwrap(); the count is around 82 so my final question is does it matter like the number of requests per second


Solution

  • I think there is a bit of a conceptual misunderstanding here, your count code isn't measuring what you think it is measuring. Naturally, printing out to the console is more expensive than incrementing a variable, but it doesn't make a big difference in the actual execution time of your program.

    It appears you are trying to measure how much time your main thread is waiting in the loop to receive a message from the second thread that you spawn. Let's say that it takes N microseconds on average for your second thread start up after you've spawned it and send a message (there's actually the potential for a lot of variance here, as it depends on operating system scheduling and system loading). Does it really matter what your main thread is doing during those N microseconds you are waiting for a message? You're either printing to the console and/or incrementing your counter, but either way, your main thread is waiting until it receives the message.

    To show this, you can measure time elapsed like so:

    use std::sync::mpsc;
    
    fn main() {
        let (tx1, rx) = mpsc::channel();
    
        std::thread::spawn(move || {
            tx1.send("hi2").unwrap();
        });
    
        let mut count = 0;
    
        let t1 = std::time::Instant::now();
        loop {
            match rx.try_recv() {
                Ok(msg) => {
                    println!("got message: {:?}", msg);
                    break;
                }
                Err(_) => {
                    // delta doesn't change much if this print is commented out
                    println!("not yet"); 
                    count += 1;
                }
            }
        }
        let t2 = std::time::Instant::now();
        let delta = t2-t1;
        
        println!("time: {}", delta.as_micros());
        println!("count {}", count)
    }
    

    If you run this code multiple times with and without the println!() in the loop commented out, you will see that although count's value will differ, the delta time will not differ very much.