[Log SDK] Cost associated with populating LogRecord::observed_timestamp

[lalitb]

In Log SDK, the LogRecord::observed_timestamp is populated as:

opentelemetry-rust/opentelemetry-sdk/src/logs/log_emitter.rs

Line 270 in 673c328

record.observed_timestamp = Some(SystemTime::now());

However, after all the optimizations, the cost associated with this call is visible considerably ~20%:

A quick test by commenting it out increases stress test throughout to ~48k. Not sure about the solution for now, raising this issue to track it.

[cijothomas]

You are right! Obtaining the timestamp is indeed quite expensive. Wondering if there are solutions like checking system Ticks since start and using that to populate timestamp.

[cijothomas]

The same challenge will exist for Exemplars too (when it arrives.), so any solution here would help Metric Exemplars too.

[lalitb]

Some old thread in rust community - https://users.rust-lang.org/t/fast-get-current-time/10381/2. It talks about using coarsetime or directly using libc.

like checking system Ticks since start and using that to populate timestamp.

Yes, need to see if there is platform/arch-independent way to achieve it.

[lalitb]

Some comparison between SystemTime::now() and directly using libc::clock_gettime():

fn get_libc_clock(tv: &mut timespec) { 
    unsafe {
        libc::clock_gettime(libc::CLOCK_MONOTONIC_COARSE, tv);
    }
}
fn benchmark_time_methods(c: &mut Criterion) {
    c.bench_function("SystemTime::now", |b| {
        b.iter(|| black_box(std::time::SystemTime::now()));
    });
    let mut tv = libc::timespec {
        tv_sec: 0,
        tv_nsec: 0,
    };
    c.bench_function("libc::clock_gettime", |b| {
        b.iter(|| black_box(get_libc_clock(&mut tv)));
    });
}

o/p is:

SystemTime::now         time:   [24.313 ns 24.881 ns 25.466 ns]
libc::clock_gettime     time:   [5.5160 ns 5.6096 ns 5.7068 ns]

So, libc is 4 times faster than SystemTime, however it needs unsafe keyword. Another option could be directly using coarsetime crate, which internally uses libc and so similar perf gains.

Also, if we don't want to use unsafe and external crate, a viable alternative could be to implement a dedicated thread that periodically updates a cached system time value (e.g., every ~100 ms). This cached time can be stored in an Atomic u64 data structure (representing time since epoch), allowing the log, trace, and metrics pipelines to access the time value efficiently and safely without directly calling system time functions.