metrics-rs / quanta

high-speed timing library in Rust
MIT License
288 stars 29 forks source link

Drift from system time #99

Open waynerobinson opened 4 months ago

waynerobinson commented 4 months ago

My solution requires a high-performance timestamp (as unix epoch) with the precision of 10µs.

I recognise that it's probably me trying to solve this wrong, but it seems like Quanta continues to drift away from the system clock.

The below code creates both a t0 starting point from Quanta and a t0_sys starting point from SystemTime and attempts to calculate the current system time based on those starting points, but it appears that the Quanta clock keeps drifting further away from the system time.

Is this a Quanta calibration issue, or is my solution just too naive?

use std::{thread, time::{Duration, SystemTime}};
use quanta::Clock;

fn main() {
    let clock = Clock::new();

    let t0_sys = SystemTime::now();
    let t0 = clock.now();

    loop {
        let now_sys = SystemTime::now();
        let now = clock.now();

        let calc = t0_sys + now.duration_since(t0);

        println!(" now = {:?}", now_sys);

        let drift = if calc < now_sys { now_sys.duration_since(calc).unwrap() } else { calc.duration_since(now_sys).unwrap() };
        println!("calc = {:?}  drift = {:?}  total elapsed = {:?}\n", calc, drift, t0.elapsed());

        thread::sleep(Duration::from_secs(5));
    }
}

Output (for 9 minutes):

 now = SystemTime { tv_sec: 1707962551, tv_nsec: 719348623 }
calc = SystemTime { tv_sec: 1707962551, tv_nsec: 719348610 }  drift = 13ns  total elapsed = 13.161µs

 now = SystemTime { tv_sec: 1707962556, tv_nsec: 719427601 }
calc = SystemTime { tv_sec: 1707962556, tv_nsec: 719843572 }  drift = 415.971µs  total elapsed = 5.000506946s

 now = SystemTime { tv_sec: 1707962561, tv_nsec: 719520138 }
calc = SystemTime { tv_sec: 1707962561, tv_nsec: 720352061 }  drift = 831.923µs  total elapsed = 10.001013009s

 now = SystemTime { tv_sec: 1707962566, tv_nsec: 719617435 }
calc = SystemTime { tv_sec: 1707962566, tv_nsec: 720865172 }  drift = 1.247737ms  total elapsed = 15.001527575s

 now = SystemTime { tv_sec: 1707962571, tv_nsec: 719717931 }
calc = SystemTime { tv_sec: 1707962571, tv_nsec: 721381604 }  drift = 1.663673ms  total elapsed = 20.002040832s

 now = SystemTime { tv_sec: 1707962576, tv_nsec: 719810160 }
calc = SystemTime { tv_sec: 1707962576, tv_nsec: 721889714 }  drift = 2.079554ms  total elapsed = 25.002547581s

 now = SystemTime { tv_sec: 1707962581, tv_nsec: 719881768 }
calc = SystemTime { tv_sec: 1707962581, tv_nsec: 722377122 }  drift = 2.495354ms  total elapsed = 30.003041242s

 now = SystemTime { tv_sec: 1707962586, tv_nsec: 719979596 }
calc = SystemTime { tv_sec: 1707962586, tv_nsec: 722890534 }  drift = 2.910938ms  total elapsed = 35.003548131s

 now = SystemTime { tv_sec: 1707962591, tv_nsec: 720072435 }
calc = SystemTime { tv_sec: 1707962591, tv_nsec: 723399050 }  drift = 3.326615ms  total elapsed = 40.00405675s

 now = SystemTime { tv_sec: 1707962596, tv_nsec: 720163419 }
calc = SystemTime { tv_sec: 1707962596, tv_nsec: 723905741 }  drift = 3.742322ms  total elapsed = 45.004564026s

 now = SystemTime { tv_sec: 1707962601, tv_nsec: 720250036 }
calc = SystemTime { tv_sec: 1707962601, tv_nsec: 724408080 }  drift = 4.158044ms  total elapsed = 50.00506554s

 now = SystemTime { tv_sec: 1707962606, tv_nsec: 720341067 }
calc = SystemTime { tv_sec: 1707962606, tv_nsec: 724914852 }  drift = 4.573785ms  total elapsed = 55.005572367s

 now = SystemTime { tv_sec: 1707962611, tv_nsec: 720431006 }
calc = SystemTime { tv_sec: 1707962611, tv_nsec: 725420448 }  drift = 4.989442ms  total elapsed = 60.006077376s

 now = SystemTime { tv_sec: 1707962616, tv_nsec: 720520919 }
calc = SystemTime { tv_sec: 1707962616, tv_nsec: 725925852 }  drift = 5.404933ms  total elapsed = 65.006585156s

 now = SystemTime { tv_sec: 1707962621, tv_nsec: 720608273 }
calc = SystemTime { tv_sec: 1707962621, tv_nsec: 726428696 }  drift = 5.820423ms  total elapsed = 70.007086931s

 now = SystemTime { tv_sec: 1707962626, tv_nsec: 720698650 }
calc = SystemTime { tv_sec: 1707962626, tv_nsec: 726934700 }  drift = 6.23605ms  total elapsed = 75.007591894s

 now = SystemTime { tv_sec: 1707962631, tv_nsec: 720787916 }
calc = SystemTime { tv_sec: 1707962631, tv_nsec: 727440931 }  drift = 6.653015ms  total elapsed = 80.008100868s

 now = SystemTime { tv_sec: 1707962636, tv_nsec: 720880483 }
calc = SystemTime { tv_sec: 1707962636, tv_nsec: 727950531 }  drift = 7.070048ms  total elapsed = 85.008609345s

 now = SystemTime { tv_sec: 1707962641, tv_nsec: 720966320 }
calc = SystemTime { tv_sec: 1707962641, tv_nsec: 728453200 }  drift = 7.48688ms  total elapsed = 90.009112827s

 now = SystemTime { tv_sec: 1707962646, tv_nsec: 721043183 }
calc = SystemTime { tv_sec: 1707962646, tv_nsec: 728946270 }  drift = 7.903087ms  total elapsed = 95.009604076s

 now = SystemTime { tv_sec: 1707962651, tv_nsec: 721138216 }
calc = SystemTime { tv_sec: 1707962651, tv_nsec: 729457356 }  drift = 8.31914ms  total elapsed = 100.010114365s

 now = SystemTime { tv_sec: 1707962656, tv_nsec: 721248755 }
calc = SystemTime { tv_sec: 1707962656, tv_nsec: 729983988 }  drift = 8.735233ms  total elapsed = 105.010641908s

 now = SystemTime { tv_sec: 1707962661, tv_nsec: 721338475 }
calc = SystemTime { tv_sec: 1707962661, tv_nsec: 730490203 }  drift = 9.151728ms  total elapsed = 110.01115683s

 now = SystemTime { tv_sec: 1707962666, tv_nsec: 721456914 }
calc = SystemTime { tv_sec: 1707962666, tv_nsec: 731024553 }  drift = 9.567639ms  total elapsed = 115.011682454s

 now = SystemTime { tv_sec: 1707962671, tv_nsec: 721551649 }
calc = SystemTime { tv_sec: 1707962671, tv_nsec: 731535516 }  drift = 9.983867ms  total elapsed = 120.01219395s

 now = SystemTime { tv_sec: 1707962676, tv_nsec: 721664798 }
calc = SystemTime { tv_sec: 1707962676, tv_nsec: 732064866 }  drift = 10.400068ms  total elapsed = 125.012722723s

 now = SystemTime { tv_sec: 1707962681, tv_nsec: 721752590 }
calc = SystemTime { tv_sec: 1707962681, tv_nsec: 732568835 }  drift = 10.816245ms  total elapsed = 130.013226457s

 now = SystemTime { tv_sec: 1707962686, tv_nsec: 721864067 }
calc = SystemTime { tv_sec: 1707962686, tv_nsec: 733096600 }  drift = 11.232533ms  total elapsed = 135.013758803s

 now = SystemTime { tv_sec: 1707962691, tv_nsec: 721962493 }
calc = SystemTime { tv_sec: 1707962691, tv_nsec: 733611001 }  drift = 11.648508ms  total elapsed = 140.014271895s

 now = SystemTime { tv_sec: 1707962696, tv_nsec: 722076686 }
calc = SystemTime { tv_sec: 1707962696, tv_nsec: 734141093 }  drift = 12.064407ms  total elapsed = 145.014801735s

 now = SystemTime { tv_sec: 1707962701, tv_nsec: 722164929 }
calc = SystemTime { tv_sec: 1707962701, tv_nsec: 734645171 }  drift = 12.480242ms  total elapsed = 150.015305174s

 now = SystemTime { tv_sec: 1707962706, tv_nsec: 722260082 }
calc = SystemTime { tv_sec: 1707962706, tv_nsec: 735156154 }  drift = 12.896072ms  total elapsed = 155.01581361s

 now = SystemTime { tv_sec: 1707962711, tv_nsec: 722352244 }
calc = SystemTime { tv_sec: 1707962711, tv_nsec: 735664343 }  drift = 13.312099ms  total elapsed = 160.01632217s

 now = SystemTime { tv_sec: 1707962716, tv_nsec: 722460704 }
calc = SystemTime { tv_sec: 1707962716, tv_nsec: 736188859 }  drift = 13.728155ms  total elapsed = 165.016848541s

 now = SystemTime { tv_sec: 1707962721, tv_nsec: 722546280 }
calc = SystemTime { tv_sec: 1707962721, tv_nsec: 736690460 }  drift = 14.14418ms  total elapsed = 170.017353324s

 now = SystemTime { tv_sec: 1707962726, tv_nsec: 722660744 }
calc = SystemTime { tv_sec: 1707962726, tv_nsec: 737220838 }  drift = 14.560094ms  total elapsed = 175.01788044s

 now = SystemTime { tv_sec: 1707962731, tv_nsec: 722753321 }
calc = SystemTime { tv_sec: 1707962731, tv_nsec: 737729302 }  drift = 14.975981ms  total elapsed = 180.018387307s

 now = SystemTime { tv_sec: 1707962736, tv_nsec: 722861646 }
calc = SystemTime { tv_sec: 1707962736, tv_nsec: 738253540 }  drift = 15.391894ms  total elapsed = 185.018912819s

 now = SystemTime { tv_sec: 1707962741, tv_nsec: 722947428 }
calc = SystemTime { tv_sec: 1707962741, tv_nsec: 738755227 }  drift = 15.807799ms  total elapsed = 190.019413896s

 now = SystemTime { tv_sec: 1707962746, tv_nsec: 723055532 }
calc = SystemTime { tv_sec: 1707962746, tv_nsec: 739279228 }  drift = 16.223696ms  total elapsed = 195.019936533s

 now = SystemTime { tv_sec: 1707962751, tv_nsec: 723162098 }
calc = SystemTime { tv_sec: 1707962751, tv_nsec: 739801828 }  drift = 16.63973ms  total elapsed = 200.020462181s

 now = SystemTime { tv_sec: 1707962756, tv_nsec: 723247690 }
calc = SystemTime { tv_sec: 1707962756, tv_nsec: 740303255 }  drift = 17.055565ms  total elapsed = 205.02096349s

 now = SystemTime { tv_sec: 1707962761, tv_nsec: 723335215 }
calc = SystemTime { tv_sec: 1707962761, tv_nsec: 740806776 }  drift = 17.471561ms  total elapsed = 210.021466438s

 now = SystemTime { tv_sec: 1707962766, tv_nsec: 723443518 }
calc = SystemTime { tv_sec: 1707962766, tv_nsec: 741331079 }  drift = 17.887561ms  total elapsed = 215.021989661s

 now = SystemTime { tv_sec: 1707962771, tv_nsec: 723549737 }
calc = SystemTime { tv_sec: 1707962771, tv_nsec: 741853312 }  drift = 18.303575ms  total elapsed = 220.022510808s

 now = SystemTime { tv_sec: 1707962776, tv_nsec: 723631714 }
calc = SystemTime { tv_sec: 1707962776, tv_nsec: 742351272 }  drift = 18.719558ms  total elapsed = 225.023009199s

 now = SystemTime { tv_sec: 1707962781, tv_nsec: 723719892 }
calc = SystemTime { tv_sec: 1707962781, tv_nsec: 742855697 }  drift = 19.135805ms  total elapsed = 230.023520487s

 now = SystemTime { tv_sec: 1707962786, tv_nsec: 723833750 }
calc = SystemTime { tv_sec: 1707962786, tv_nsec: 743385329 }  drift = 19.551579ms  total elapsed = 235.024042784s

 now = SystemTime { tv_sec: 1707962791, tv_nsec: 723939491 }
calc = SystemTime { tv_sec: 1707962791, tv_nsec: 743907064 }  drift = 19.967573ms  total elapsed = 240.024565823s

 now = SystemTime { tv_sec: 1707962796, tv_nsec: 724045277 }
calc = SystemTime { tv_sec: 1707962796, tv_nsec: 744428766 }  drift = 20.383489ms  total elapsed = 245.025087785s

 now = SystemTime { tv_sec: 1707962801, tv_nsec: 724131037 }
calc = SystemTime { tv_sec: 1707962801, tv_nsec: 744930446 }  drift = 20.799409ms  total elapsed = 250.025587826s

 now = SystemTime { tv_sec: 1707962806, tv_nsec: 724235352 }
calc = SystemTime { tv_sec: 1707962806, tv_nsec: 745450690 }  drift = 21.215338ms  total elapsed = 255.026108662s

 now = SystemTime { tv_sec: 1707962811, tv_nsec: 724339538 }
calc = SystemTime { tv_sec: 1707962811, tv_nsec: 745970845 }  drift = 21.631307ms  total elapsed = 260.026630324s

 now = SystemTime { tv_sec: 1707962816, tv_nsec: 724445564 }
calc = SystemTime { tv_sec: 1707962816, tv_nsec: 746492833 }  drift = 22.047269ms  total elapsed = 265.027150946s

 now = SystemTime { tv_sec: 1707962821, tv_nsec: 724531230 }
calc = SystemTime { tv_sec: 1707962821, tv_nsec: 746994508 }  drift = 22.463278ms  total elapsed = 270.027653986s

 now = SystemTime { tv_sec: 1707962826, tv_nsec: 724636581 }
calc = SystemTime { tv_sec: 1707962826, tv_nsec: 747515816 }  drift = 22.879235ms  total elapsed = 275.02817344s

 now = SystemTime { tv_sec: 1707962831, tv_nsec: 724739638 }
calc = SystemTime { tv_sec: 1707962831, tv_nsec: 748034862 }  drift = 23.295224ms  total elapsed = 280.028693258s

 now = SystemTime { tv_sec: 1707962836, tv_nsec: 724844064 }
calc = SystemTime { tv_sec: 1707962836, tv_nsec: 748555303 }  drift = 23.711239ms  total elapsed = 285.029214313s

 now = SystemTime { tv_sec: 1707962841, tv_nsec: 724932917 }
calc = SystemTime { tv_sec: 1707962841, tv_nsec: 749060269 }  drift = 24.127352ms  total elapsed = 290.029724703s

 now = SystemTime { tv_sec: 1707962846, tv_nsec: 725048188 }
calc = SystemTime { tv_sec: 1707962846, tv_nsec: 749591523 }  drift = 24.543335ms  total elapsed = 295.030253565s

 now = SystemTime { tv_sec: 1707962851, tv_nsec: 725161208 }
calc = SystemTime { tv_sec: 1707962851, tv_nsec: 750120569 }  drift = 24.959361ms  total elapsed = 300.030786318s

 now = SystemTime { tv_sec: 1707962856, tv_nsec: 725277412 }
calc = SystemTime { tv_sec: 1707962856, tv_nsec: 750652741 }  drift = 25.375329ms  total elapsed = 305.031315749s

 now = SystemTime { tv_sec: 1707962861, tv_nsec: 725372624 }
calc = SystemTime { tv_sec: 1707962861, tv_nsec: 751163943 }  drift = 25.791319ms  total elapsed = 310.031826795s

 now = SystemTime { tv_sec: 1707962866, tv_nsec: 725482145 }
calc = SystemTime { tv_sec: 1707962866, tv_nsec: 751689248 }  drift = 26.207103ms  total elapsed = 315.032347362s

 now = SystemTime { tv_sec: 1707962871, tv_nsec: 725584724 }
calc = SystemTime { tv_sec: 1707962871, tv_nsec: 752207880 }  drift = 26.623156ms  total elapsed = 320.032868903s

 now = SystemTime { tv_sec: 1707962876, tv_nsec: 725671064 }
calc = SystemTime { tv_sec: 1707962876, tv_nsec: 752710589 }  drift = 27.039525ms  total elapsed = 325.033372152s

 now = SystemTime { tv_sec: 1707962881, tv_nsec: 725764340 }
calc = SystemTime { tv_sec: 1707962881, tv_nsec: 753219758 }  drift = 27.455418ms  total elapsed = 330.033881672s

 now = SystemTime { tv_sec: 1707962886, tv_nsec: 725871355 }
calc = SystemTime { tv_sec: 1707962886, tv_nsec: 753743370 }  drift = 27.872015ms  total elapsed = 335.034403578s

 now = SystemTime { tv_sec: 1707962891, tv_nsec: 725946554 }
calc = SystemTime { tv_sec: 1707962891, tv_nsec: 754238903 }  drift = 28.292349ms  total elapsed = 340.034901387s

 now = SystemTime { tv_sec: 1707962896, tv_nsec: 726057245 }
calc = SystemTime { tv_sec: 1707962896, tv_nsec: 754768739 }  drift = 28.711494ms  total elapsed = 345.035432365s

 now = SystemTime { tv_sec: 1707962901, tv_nsec: 726150524 }
calc = SystemTime { tv_sec: 1707962901, tv_nsec: 755277930 }  drift = 29.127406ms  total elapsed = 350.035937817s

 now = SystemTime { tv_sec: 1707962906, tv_nsec: 726255630 }
calc = SystemTime { tv_sec: 1707962906, tv_nsec: 755799281 }  drift = 29.543651ms  total elapsed = 355.036461513s

 now = SystemTime { tv_sec: 1707962911, tv_nsec: 726364243 }
calc = SystemTime { tv_sec: 1707962911, tv_nsec: 756324124 }  drift = 29.959881ms  total elapsed = 360.036984313s

 now = SystemTime { tv_sec: 1707962916, tv_nsec: 726441390 }
calc = SystemTime { tv_sec: 1707962916, tv_nsec: 756817667 }  drift = 30.376277ms  total elapsed = 365.037481449s

 now = SystemTime { tv_sec: 1707962921, tv_nsec: 726523866 }
calc = SystemTime { tv_sec: 1707962921, tv_nsec: 757316302 }  drift = 30.792436ms  total elapsed = 370.037977773s

 now = SystemTime { tv_sec: 1707962926, tv_nsec: 726611141 }
calc = SystemTime { tv_sec: 1707962926, tv_nsec: 757819806 }  drift = 31.208665ms  total elapsed = 375.038480758s

 now = SystemTime { tv_sec: 1707962931, tv_nsec: 726717065 }
calc = SystemTime { tv_sec: 1707962931, tv_nsec: 758342011 }  drift = 31.624946ms  total elapsed = 380.039003595s

 now = SystemTime { tv_sec: 1707962936, tv_nsec: 726826375 }
calc = SystemTime { tv_sec: 1707962936, tv_nsec: 758867631 }  drift = 32.041256ms  total elapsed = 385.039530785s

 now = SystemTime { tv_sec: 1707962941, tv_nsec: 726914121 }
calc = SystemTime { tv_sec: 1707962941, tv_nsec: 759371518 }  drift = 32.457397ms  total elapsed = 390.040032136s

 now = SystemTime { tv_sec: 1707962946, tv_nsec: 727016646 }
calc = SystemTime { tv_sec: 1707962946, tv_nsec: 759890241 }  drift = 32.873595ms  total elapsed = 395.0405477s

 now = SystemTime { tv_sec: 1707962951, tv_nsec: 727095395 }
calc = SystemTime { tv_sec: 1707962951, tv_nsec: 760385210 }  drift = 33.289815ms  total elapsed = 400.041043593s

 now = SystemTime { tv_sec: 1707962956, tv_nsec: 727196072 }
calc = SystemTime { tv_sec: 1707962956, tv_nsec: 760902134 }  drift = 33.706062ms  total elapsed = 405.041563365s

 now = SystemTime { tv_sec: 1707962961, tv_nsec: 727282692 }
calc = SystemTime { tv_sec: 1707962961, tv_nsec: 761405032 }  drift = 34.12234ms  total elapsed = 410.042068703s

 now = SystemTime { tv_sec: 1707962966, tv_nsec: 727364747 }
calc = SystemTime { tv_sec: 1707962966, tv_nsec: 761903292 }  drift = 34.538545ms  total elapsed = 415.04256442s

 now = SystemTime { tv_sec: 1707962971, tv_nsec: 727447152 }
calc = SystemTime { tv_sec: 1707962971, tv_nsec: 762401816 }  drift = 34.954664ms  total elapsed = 420.043060108s

 now = SystemTime { tv_sec: 1707962976, tv_nsec: 727542869 }
calc = SystemTime { tv_sec: 1707962976, tv_nsec: 762913801 }  drift = 35.370932ms  total elapsed = 425.043576301s

 now = SystemTime { tv_sec: 1707962981, tv_nsec: 727629679 }
calc = SystemTime { tv_sec: 1707962981, tv_nsec: 763416689 }  drift = 35.78701ms  total elapsed = 430.044077332s

 now = SystemTime { tv_sec: 1707962986, tv_nsec: 727704420 }
calc = SystemTime { tv_sec: 1707962986, tv_nsec: 763907663 }  drift = 36.203243ms  total elapsed = 435.044568185s

 now = SystemTime { tv_sec: 1707962991, tv_nsec: 727787001 }
calc = SystemTime { tv_sec: 1707962991, tv_nsec: 764406485 }  drift = 36.619484ms  total elapsed = 440.045068706s

 now = SystemTime { tv_sec: 1707962996, tv_nsec: 727894123 }
calc = SystemTime { tv_sec: 1707962996, tv_nsec: 764929873 }  drift = 37.03575ms  total elapsed = 445.045593969s

 now = SystemTime { tv_sec: 1707963001, tv_nsec: 727980439 }
calc = SystemTime { tv_sec: 1707963001, tv_nsec: 765432400 }  drift = 37.451961ms  total elapsed = 450.046092337s

 now = SystemTime { tv_sec: 1707963006, tv_nsec: 728080601 }
calc = SystemTime { tv_sec: 1707963006, tv_nsec: 765948898 }  drift = 37.868297ms  total elapsed = 455.046609879s

 now = SystemTime { tv_sec: 1707963011, tv_nsec: 728163762 }
calc = SystemTime { tv_sec: 1707963011, tv_nsec: 766448113 }  drift = 38.284351ms  total elapsed = 460.047105949s

 now = SystemTime { tv_sec: 1707963016, tv_nsec: 728265499 }
calc = SystemTime { tv_sec: 1707963016, tv_nsec: 766966179 }  drift = 38.70068ms  total elapsed = 465.04762976s

 now = SystemTime { tv_sec: 1707963021, tv_nsec: 728349028 }
calc = SystemTime { tv_sec: 1707963021, tv_nsec: 767465873 }  drift = 39.116845ms  total elapsed = 470.048124905s

 now = SystemTime { tv_sec: 1707963026, tv_nsec: 728431554 }
calc = SystemTime { tv_sec: 1707963026, tv_nsec: 767964685 }  drift = 39.533131ms  total elapsed = 475.048627962s

 now = SystemTime { tv_sec: 1707963031, tv_nsec: 728519357 }
calc = SystemTime { tv_sec: 1707963031, tv_nsec: 768468693 }  drift = 39.949336ms  total elapsed = 480.049127778s

 now = SystemTime { tv_sec: 1707963036, tv_nsec: 728617802 }
calc = SystemTime { tv_sec: 1707963036, tv_nsec: 768983387 }  drift = 40.365585ms  total elapsed = 485.049645546s

 now = SystemTime { tv_sec: 1707963041, tv_nsec: 728700575 }
calc = SystemTime { tv_sec: 1707963041, tv_nsec: 769482394 }  drift = 40.781819ms  total elapsed = 490.050143427s

 now = SystemTime { tv_sec: 1707963046, tv_nsec: 728785953 }
calc = SystemTime { tv_sec: 1707963046, tv_nsec: 769983997 }  drift = 41.198044ms  total elapsed = 495.050645064s

 now = SystemTime { tv_sec: 1707963051, tv_nsec: 728867235 }
calc = SystemTime { tv_sec: 1707963051, tv_nsec: 770481686 }  drift = 41.614451ms  total elapsed = 500.051142864s

 now = SystemTime { tv_sec: 1707963056, tv_nsec: 728969667 }
calc = SystemTime { tv_sec: 1707963056, tv_nsec: 771000717 }  drift = 42.03105ms  total elapsed = 505.051662541s

 now = SystemTime { tv_sec: 1707963061, tv_nsec: 729050049 }
calc = SystemTime { tv_sec: 1707963061, tv_nsec: 771497556 }  drift = 42.447507ms  total elapsed = 510.052158226s

 now = SystemTime { tv_sec: 1707963066, tv_nsec: 729146029 }
calc = SystemTime { tv_sec: 1707963066, tv_nsec: 772009898 }  drift = 42.863869ms  total elapsed = 515.052667822s

 now = SystemTime { tv_sec: 1707963071, tv_nsec: 729220911 }
calc = SystemTime { tv_sec: 1707963071, tv_nsec: 772501025 }  drift = 43.280114ms  total elapsed = 520.053158718s

 now = SystemTime { tv_sec: 1707963076, tv_nsec: 729314811 }
calc = SystemTime { tv_sec: 1707963076, tv_nsec: 773011208 }  drift = 43.696397ms  total elapsed = 525.053672783s

 now = SystemTime { tv_sec: 1707963081, tv_nsec: 729396483 }
calc = SystemTime { tv_sec: 1707963081, tv_nsec: 773509236 }  drift = 44.112753ms  total elapsed = 530.054172296s

 now = SystemTime { tv_sec: 1707963086, tv_nsec: 729481277 }
calc = SystemTime { tv_sec: 1707963086, tv_nsec: 774010302 }  drift = 44.529025ms  total elapsed = 535.054669551s

 now = SystemTime { tv_sec: 1707963091, tv_nsec: 729557816 }
calc = SystemTime { tv_sec: 1707963091, tv_nsec: 774503205 }  drift = 44.945389ms  total elapsed = 540.055163203s
tobz commented 3 months ago

Apologies for the delay in response here. I saw this issue when you filed it, immediately looked it over, did some calculations, and then.... forgot to respond. 😭

It does indeed appear like there is potentially a calibration issue here, or that we're simply hitting the limits of what the calibration loop can provide. Calibration cannot cope with changes to system time through mechanisms like NTP, which may skew time forwards or backwards at a rate faster or slower than the actual local passage of time.

All of that said, I'd say your test case is reasonable. Running it locally, I can observe the same slow drift over time, in which the degree that it drifts changes between runs. I had also observed a few runs where the drift was sinusoidal, likely related to legitimate NTP adjustment/tracking.

Replacing quanta with simple calls to Instant::now all but eliminates the drift, locking it tightly to a few hundred nanoseconds plus or minus over the course of a few minutes. This is not surprising, as Instant::now is based on CLOCK_MONOTONIC for unix-y platforms, where it will be subject to NTP adjustments (but simply ensured to at least only change monotonically), and so is likely to stay much closer to SystemTime which is similarly disciplined by NTP.

This definitely has me thinking about re-examining the use of TSC overall, but I would suggest just utilizing SystemTime/Instant for the time being since that should be accurate enough if you have a strict need to present a timestamp that is wall clock-referenced.