Skip to content

Clock source mismatch between Go and Rust FFI causes incorrect commit latency metrics #1720

@Elvis339

Description

@Elvis339

The performance dashboard shows Rust FFI commit time consistently higher than Go commit time even though Go calls Rust synchronously via CGO (Go >= Rust, always).

This was surfaced without deferred persistence, where both sides register non-zero values and the impossible relationship is visible. With deferred persistence, commits drop below 1ms and Go's integer truncation records them as 0, hiding the mismatch entirely.

Root Cause

  1. Different clock sources where Rust uses coarsetime::Instant while Go uses time.Now()
  2. Go integer truncation: time.Since(start).Milliseconds() returns int64 any commit under 1ms records as 0.

Background

coarsetime was chosen to avoid syscall overhead from std::time. Brandon confirmed this isn't a concern std::time::Instant uses clock_gettime(CLOCK_MONOTONIC) via vDSO, resolving entirely in userspace on any modern Linux kernel.

Fix

Rust: Swap coarsetime to std::time::Instant in the #[histogram_timing] macro (after #1712 merges).

Go: Change .Milliseconds() to .Nanoseconds() in triedb.go (consistent with AvalancheGo conventions per Stephen), or use float seconds (Prometheus best practice). Same pattern exists in blockchain.go chain timers.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingobservabilitylogging, tracing and metrics

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions