#logging #blocking #user-interface #programmers #api #async #sink

carboncopy

A user (programmer) interface for asynchronous logging in Rust

6 releases

0.3.0 May 2, 2021
0.2.1 May 1, 2021
0.2.0 Apr 27, 2021
0.1.2 Apr 25, 2021

#405 in GUI


Used in carboncopy-tokio

MIT license

26KB
387 lines

CARBONCOPY

A user (programmer) interface for asynchronous logging in Rust that also offers blocking API.

docs.rs License: MIT

Non-features

  • Custom log format
  • Macro API
  • Colored output

Examples

Tokio Backend (Sink) Example: Blocking Mode

use carboncopy::{Entry, Level, Logger, SinkAcknowledgment, SinkMode, Tags};
use carboncopy_tokio::{BufSink, BufferOverflowThreshold, SinkOptions};
use serde::Serialize;
use std::sync::Arc;
use tokio::io::stdout;
use tokio::runtime::Runtime;

fn main() {
    // instantiate a tokio runtime and wrap it inside an Arc so we can pass it around
    let rt = Arc::new(Runtime::new().unwrap());

    // instantiate tokio sink with options
    let sink = BufSink::new(SinkOptions {
        // 1 KB buffer
        buffer: Some(BufferOverflowThreshold::new(1 * 1024).unwrap()),

        // 50 ms flush timeout
        flush_timeout_ms: 50,

        // pass tokio runtime so no new one needs to be created
        tokio_runtime: rt.clone(),

        // stdout log output
        output_writer: stdout(),
    });

    // instantiate Carboncopy's logging interface
    let logger = Logger::new(Level::INFO, Arc::new(sink));

    let dummy_entry = Entry::new(
        "some error just happened",                     // central log message
        true,                                           // whether or not to add timestamp
        Some(vec![13, 159, 11, 97, 68, 144, 211, 113]), // add a 64-bit span_id to associate it to a unique sequence of events
        Some(Tags::new(vec!["wakeup_sysadmin_at_3am".into(), "danger".into()]).unwrap()), // add some tags to categorize what the message is about
    );

    // async-blind logging
    let ack = logger.log(SinkMode::Blocking, Level::ERROR, dummy_entry.clone());

    // let's examine the content of ack
    match ack {
        SinkAcknowledgment::NotPerformed => panic!("logging should have been performed"),
        SinkAcknowledgment::Awaitable(_) => panic!("we specified blocking mode, not async"),
        SinkAcknowledgment::Completed(result) => {
            println!("The desired acknowledgment is returned");
            assert!(result.is_ok());
        }
    };

    // the message won't show up until it's flushed, so wait for timeout
    // additional 5 ms is margin to let mutexes resolve, etc
    // feel free to play around with flush_timeout_ms in SinkOptions
    // this feature is backend or sink specific, other implementations may not have it
    sleep(rt.clone(), 50 + 5);

    // ignored logging since TRACE is more verbose than INFO, this time using a shortcut method
    assert!(logger
        .log_blocking(Level::TRACE, dummy_entry.clone())
        .is_none());

    let mut dummy_var = 0;

    // log an entry obtained via expensive computation
    let result = logger.log_expensive_blocking(Level::ERROR, || {
        dummy_var += 1; // a very expensive operation
        Entry::new(format!("dummy var is {}", dummy_var), true, None, None)
    });
    assert!(result.is_some());
    assert!(result.unwrap().is_ok());

    // updated dummy_var indicates that the lambda was executed
    assert_eq!(dummy_var, 1);

    // this time, the expensive computation to obtain the entry will be discarded
    // due to the higher verbosity level than the maximum we care to log
    assert!(logger
        .log_expensive_blocking(Level::TRACE, || {
            dummy_var *= 2; // another very expensive operation
            Entry::new(format!("dummy var is {}", dummy_var), true, None, None)
        })
        .is_none());

    // unupdated dummy_var indicates that the lambda was *not* executed
    assert_eq!(dummy_var, 1);

    // another flush timeout:
    sleep(rt.clone(), 50 + 5);

    // Entry can be constructed from any json serializable data
    #[derive(Serialize)]
    struct Person {
        name: &'static str,
        age: usize,
    }
    let _ = logger.log_blocking(
        Level::INFO,
        Entry::new(
            &Person {
                name: "Donald Trump",
                age: 10,
            },
            true,
            None,
            None,
        ),
    );

    // now let's simulate a buffer overflow (again, this is backend specific implementation)
    let many_zeroes = Entry::new(
        format!(
            "it's raining zeroes, hallelujah! {}",
            vec!['0'; 1000].iter().collect::<String>()
        ),
        true,
        None,
        None,
    );

    let _ = logger.log_blocking(Level::INFO, many_zeroes.clone());

    println!("at this point, the last entry won't show up on stdout yet");
    println!("this is because the buffer has neither overflowed nor timed out");

    // now trigger the buffer overflow
    let _ = logger.log_blocking(Level::INFO, many_zeroes.clone());

    // there is no need to wait for flush timeout because an overflow triggers a flush
    // but synchronization mechanisms need time to resolve, so let's wait 5 ms
    sleep(rt.clone(), 5);
}

/// naive sleep function
fn sleep(rt: Arc<Runtime>, ms: u64) {
    rt.block_on(async {
        tokio::time::sleep(std::time::Duration::from_millis(ms)).await;
    });
}

Tokio Backend (Sink) Example: Async Mode

use carboncopy::{Entry, Level, Logger};
use carboncopy_tokio::{BufSink, SinkOptions};
use futures::future::join_all;
use std::sync::Arc;

fn main() {
    let opts = SinkOptions::default();
    let rt = opts.tokio_runtime.clone();
    let sink = Arc::new(BufSink::new(opts));
    let logger = Arc::new(Logger::new(Level::INFO, sink.clone()));

    let mut futures = Vec::new();
    for i in 0..10 {
        let logger_clone = logger.clone();
        futures.push(rt.spawn(async move {
            assert!(logger_clone
                .log_async(
                    Level::ERROR,
                    Entry::new(format!("Hello world #{}", i), false, None, None),
                )
                .unwrap()
                .await
                .is_ok());
        }));
    }

    // join all spawned futures and execute them in random order
    rt.block_on(join_all(futures));

    // manually flush to see output before exiting
    assert!(rt.block_on(sink.flush()).is_ok());
}

Dependencies

~2.3–3.5MB
~67K SLoC