the `time::WallClock::fastNowInSec()` is getting more and more ahead

[UndefinedSy]

Describe the bug (required) the deviation of the time::WallClock::fastNowInSec() is unpredictable.

I've noticed that on my different machines, the timepoint generated by fastNowInSec is unpredictable. some of the results show that the fastNowInSec is always consistent with the slowNowInSec, the others show that the differences between the two continue to widen. I'm not sure if this will lead to a buggy behavior on the scenario that requires two timepoints to cal the duration. (like TTL or something)

Your Environments (required)

• OS: uname -a

  Linux my-test-16 5.4.119-19-0009.11 #1 SMP Wed Oct 5 18:41:07 CST 2022 x86_64 x86_64 x86_64 GNU/Linux

• Compiler: g++ --version or clang++ --version

  g++ (GCC) 8.5.0 20210514 (Red Hat 8.5.0-4)

• CPU: lscpu

  Architecture:        x86_64
  CPU op-mode(s):      32-bit, 64-bit
  Byte Order:          Little Endian
  CPU(s):              16
  On-line CPU(s) list: 0-15
  Thread(s) per core:  1
  Core(s) per socket:  16
  Socket(s):           1
  NUMA node(s):        1
  Vendor ID:           GenuineIntel
  CPU family:          6
  Model:               94
  Model name:          Intel(R) Xeon(R) Gold 6133 CPU @ 2.50GHz
  Stepping:            3
  CPU MHz:             2499.998
  BogoMIPS:            4999.99
  Hypervisor vendor:   KVM
  Virtualization type: full
  L1d cache:           32K
  L1i cache:           32K
  L2 cache:            4096K
  L3 cache:            28160K
  NUMA node0 CPU(s):   0-15
  Flags:               fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single pti fsgsbase bmi1 hle avx2 smep bmi2 erms invpcid rtm mpx rdseed adx smap clflushopt xsaveopt xsavec xgetbv1 arat

• Commit id (e.g. a3ffc7d8)
• latest

How To Reproduce(required)

Steps to reproduce the behavior:

#include <chrono>
#include <ctime>
#include <iostream>
#include <sstream>

#include "common/time/WallClock.h"

int main(int argc, char *argv[]) {
  // test std::chrono::system_clock
  auto std_system_now1 = std::chrono::system_clock::now();
  // test std::chrono::steady_clock
  auto std_steady_now1 = std::chrono::steady_clock::now();
  // test nebula::time::WallClock::slowNowInSec
  auto nebula_slow_now1 = nebula::time::WallClock::slowNowInSec();
  // test nebula::time::WallClock::fastNowInSec
  auto nebula_fast_now1 = nebula::time::WallClock::fastNowInSec();
  // output current date with format "YYYY-MM-DD HH:MM:SS"
  auto system_wallclock_datetime = std::chrono::system_clock::to_time_t(std_system_now1);
  std::stringstream ss;
  ss << std::put_time(std::localtime(&system_wallclock_datetime), "%Y-%m-%d %X");
  std::cout << "Current DataTime(system wallclock): "
            << ss.str() << std::endl;
  std::cout << "\tstd::chrono::system_clock::now(): "
            << std::chrono::duration_cast<std::chrono::seconds>(std_system_now1.time_since_epoch()).count() << std::endl;
  std::cout << "\tstd::chrono::steady_clock::now(): "
            << std::chrono::duration_cast<std::chrono::seconds>(std_steady_now1.time_since_epoch()).count() << std::endl;
  std::cout << "\tnebula::time::WallClock::slowNowInSec(): "
            << nebula_slow_now1 << std::endl;
  std::cout << "\tnebula::time::WallClock::fastNowInSec(): "
            << nebula_fast_now1 << std::endl;

  while (1) {
    // wait for 10s and re-genereate the time
    std::cout << "Wait for 10s..." << std::endl;
    std::this_thread::sleep_for(std::chrono::seconds(10));

    // test std::chrono::system_clock
    auto std_system_now2 = std::chrono::system_clock::now();
    // test std::chrono::steady_clock
    auto std_steady_now2 = std::chrono::steady_clock::now();
    // test nebula::time::WallClock::slowNowInSec
    auto nebula_slow_now2 = nebula::time::WallClock::slowNowInSec();
    // test nebula::time::WallClock::fastNowInSec
    auto nebula_fast_now2 = nebula::time::WallClock::fastNowInSec();
    // output current date with format "YYYY-MM-DD HH:MM:SS"
    system_wallclock_datetime = std::chrono::system_clock::to_time_t(std_system_now2);
    ss.str("");
    ss << std::put_time(std::localtime(&system_wallclock_datetime), "%Y-%m-%d %X");
    std::cout << "Current DataTime(system wallclock): "
              << ss.str() << std::endl;
    std::cout << "\tstd::chrono::system_clock::now(): "
              << std::chrono::duration_cast<std::chrono::seconds>(std_system_now2.time_since_epoch()).count() << std::endl;
    std::cout << "\tstd::chrono::steady_clock::now(): "
              << std::chrono::duration_cast<std::chrono::seconds>(std_steady_now2.time_since_epoch()).count() << std::endl;
    std::cout << "\tnebula::time::WallClock::slowNowInSec(): "
              << nebula_slow_now2 << std::endl;
    std::cout << "\tnebula::time::WallClock::fastNowInSec(): "
              << nebula_fast_now2 << std::endl;
    std::cout << "--------------------------------------------------------------\n";
  }
}

running the above code for a period of time, got the following result.

Current DataTime(system wallclock): 2024-03-11 11:35:12
        std::chrono::system_clock::now(): 1710128112
        std::chrono::steady_clock::now(): 4478530
        nebula::time::WallClock::slowNowInSec(): 1710128112
        nebula::time::WallClock::fastNowInSec(): 1710128216

Expected behavior the fast one can be not so precise but the differences should be limited to a predictable range.

[UndefinedSy]

not sure if this is by-designed

[critical27]

fast won't be accurate. IIRC, its difference is unpredictable. And yes, this may lead a problem when consider TTL if it use the fast function.

[dutor]

Years ago, I had noticed this buggy problem but didn't dive into it, and never have reproduced it ever since.

Yeah you are right. The so called fast version of WallClock is kind of not predictable because of how it works when converting the CPU ticks to realtime duration. It's subject to many aspects including the rdtsc instruction itself, accuracy of the system timer and even system load during caliberation.

So we discourage to use it in some critical situations.

If you are interesting in this issue, you could try out to utilize this kernel module to make the conversion mentioned above more accurate and eliminate the caliberation process.

[UndefinedSy]

thx for the prompt reply.