Hi,

I have been working on RocksDB (https://github.com/facebook/rocksdb) and I am running into a problem while building the binaries on Amazon Linux EC2 instance of type i3.8xlarge.

There is a class called Performance Context. It provides time spent in nano seconds in different operations.

There are some unit tests that test this functionality. The functionality uses the following code to calculate the nano seconds spent in the thread.

uint64_t CPUNanos() override {
struct timespec ts;
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &ts);
return static_cast<uint64_t>(ts.tv_sec) * 1000000000 + ts.tv_nsec;
}

On EC2 instance of type i3.8xlarge, some times the time reported is 0 nano seconds. The operation has gone through disk and memory operations so I know the time is not really 0 nano seconds.

I assumed that this is happening because the thread is switched between CPUs. To confirm my assumption, I have wrote a simple program as shown below

#include <iostream>
#include <time.h>
#include <sched.h>
#include <unistd.h>
#include <utility>

uint64_t getNanoSecCPUTime() {
struct timespec ts;
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &ts);
return static_cast<uint64_t>(ts.tv_sec) * 1000000000 + ts.tv_nsec;
}

int main() {

auto iterations = 10'000;
auto count = 0;
auto nanoSec = getNanoSecCPUTime();
for (int i = 0; i < iterations; i++) {
auto newNanoSec = getNanoSecCPUTime();

for (auto k=0; k<1'000;k++) {
auto assign = k;
}

if (nanoSec == newNanoSec) {
std::cout << nanoSec << ":" << newNanoSec << std::endl;
count++;
}
nanoSec = newNanoSec;
}
std::cout << "Matched " << count << " times." << std::endl;
}

This program checks that how many times the nano seconds are reported as same between two calls. It has variable output, sometimes the nanoseconds match 3000+ times, sometimes they match 10 times etc.

I have taken all the CPUs offline using this command for CPU from 1 to 31

echo 0 > /sys/devices/system/cpu/cpuN/online

After that the program never reports any matching values.

I have following questions
* Is it possible that there is genuinely zero nano seconds passed between two calls?
* Is the call to clock_gettime with CLOCK_THREAD_CPUTIME_ID is a reliable way to measure thread time. If not, what can be done?

Note: If I replace CLOCK_THREAD_CPUTIME_ID with CLOCK_MONOTONIC, rocks DB build passes all unit tests and also my program passes as well.

Use high_resolution_clock. On Windows and Linux this indirectly bases
on x86's RDTSC. On Windows it unfortunately bases on QueryPerformance
Counter() which has 100ns-resolution although QueryPerformanceCounter()
bases on RDTSC if the TSC is invariant, like with every x86-CPU of the
last two decades.
With the runtimes of MSVC, clang++ and g++ you could even use steady
_clock, which uses duration<int64_t, nano>.

Am 13.05.2023 um 00:09 schrieb Jehangir Iqbal:
> Hi,
>
> I have been working on RocksDB (https://github.com/facebook/rocksdb) and I am running into a problem while building the binaries on Amazon Linux EC2 instance of type i3.8xlarge.
>
> There is a class called Performance Context. It provides time spent in nano seconds in different operations.
>
> There are some unit tests that test this functionality. The functionality uses the following code to calculate the nano seconds spent in the thread.
>
> uint64_t CPUNanos() override {
> struct timespec ts;
> clock_gettime(CLOCK_THREAD_CPUTIME_ID, &ts);
> return static_cast<uint64_t>(ts.tv_sec) * 1000000000 + ts.tv_nsec;
> }
>
> On EC2 instance of type i3.8xlarge, some times the time reported is 0 nano seconds. The operation has gone through disk and memory operations so I know the time is not really 0 nano seconds.
>
> I assumed that this is happening because the thread is switched between CPUs. To confirm my assumption, I have wrote a simple program as shown below
>
> #include <iostream>
> #include <time.h>
> #include <sched.h>
> #include <unistd.h>
> #include <utility>
>
> uint64_t getNanoSecCPUTime() {
> struct timespec ts;
> clock_gettime(CLOCK_THREAD_CPUTIME_ID, &ts);
> return static_cast<uint64_t>(ts.tv_sec) * 1000000000 + ts.tv_nsec;
> }
>
> int main() {
>
> auto iterations = 10'000;
> auto count = 0;
> auto nanoSec = getNanoSecCPUTime();
> for (int i = 0; i < iterations; i++) {
> auto newNanoSec = getNanoSecCPUTime();
>
> for (auto k=0; k<1'000;k++) {
> auto assign = k;
> }
>
> if (nanoSec == newNanoSec) {
> std::cout << nanoSec << ":" << newNanoSec << std::endl;
> count++;
> }
> nanoSec = newNanoSec;
> }
> std::cout << "Matched " << count << " times." << std::endl;
> }
>
> This program checks that how many times the nano seconds are reported as same between two calls. It has variable output, sometimes the nanoseconds match 3000+ times, sometimes they match 10 times etc.
>
> I have taken all the CPUs offline using this command for CPU from 1 to 31
>
> echo 0 > /sys/devices/system/cpu/cpuN/online
>
> After that the program never reports any matching values.
>
> I have following questions
> * Is it possible that there is genuinely zero nano seconds passed between two calls?
> * Is the call to clock_gettime with CLOCK_THREAD_CPUTIME_ID is a reliable way to measure thread time. If not, what can be done?
>
> Note: If I replace CLOCK_THREAD_CPUTIME_ID with CLOCK_MONOTONIC, rocks DB build passes all unit tests and also my program passes as well.
>
>
>
>
>
>