Follow-up to #100 (closed without landing this half).
simple_engine/ (mod.rs, promql.rs, sql.rs, elastic.rs) has 13 spots doing:
let start = Instant::now();
// ... logic ...
debug!("[LATENCY] Foo: {:.2}ms", start.elapsed().as_secs_f64() * 1000.0);
This interleaves timing bookkeeping into business logic and requires hand-pairing a named Instant var with a matching debug! call elsewhere in the function — nothing stops them drifting apart on edit.
Fix: replace each with tracing::debug_span!(...).entered(), matching the pattern already used in precompute_engine/worker.rs and output_sink.rs. Only the timer + [LATENCY] debug! pairs get removed — unrelated debug!/warn! calls in the same functions stay as-is.
Prerequisite: asap-query-engine/src/main.rs's setup_logging doesn't set .with_span_events(FmtSpan::CLOSE) (unlike precompute_engine.rs's binary setup), so spans would currently log no timing at all under the real server binary. Add that one line first.
Verified locally with a scratch cargo run -p query_engine_rust --bin tracing_demo comparing both subscriber configs.
Follow-up to #100 (closed without landing this half).
simple_engine/(mod.rs, promql.rs, sql.rs, elastic.rs) has 13 spots doing:This interleaves timing bookkeeping into business logic and requires hand-pairing a named
Instantvar with a matchingdebug!call elsewhere in the function — nothing stops them drifting apart on edit.Fix: replace each with
tracing::debug_span!(...).entered(), matching the pattern already used inprecompute_engine/worker.rsandoutput_sink.rs. Only the timer +[LATENCY]debug! pairs get removed — unrelateddebug!/warn!calls in the same functions stay as-is.Prerequisite:
asap-query-engine/src/main.rs'ssetup_loggingdoesn't set.with_span_events(FmtSpan::CLOSE)(unlikeprecompute_engine.rs's binary setup), so spans would currently log no timing at all under the real server binary. Add that one line first.Verified locally with a scratch
cargo run -p query_engine_rust --bin tracing_democomparing both subscriber configs.