boost chrono endTime - startTime returns negative in boost 1.51
boost, c++, c++-chrono
Solution
Hyperthreading or just scheduling interference, the Boost implementation punts monotonic support to the OS:
POSIX: `clock_gettime (CLOCK_MONOTONIC)` although it still may fail due to kernel errors handling hyper-threading when calibrating the system.
WIN32: `QueryPerformanceCounter()` which on anything but Nehalem architecture or newer is not going to be monotonic across cores and threads.
OSX: `mach_absolute_time()`, i.e. the steady & high resolution clocks are the same. The source code shows that it uses `RDTSC` thus strict dependency upon hardware stability: i.e. no guarantees.
Disabling hyperthreading is a recommended way to go, but say on Windows you are really limited. Aside of dropping timer resolution the only available method is direct access to the underlying hardware timers whilst ensuring thread affinity.
It looks like a good time to submit a bug to Boost, I would recommend:
Win32: Use `GetTick64Count()`, as discussed here.
OSX: Use `clock_get_time (SYSTEM_CLOCK)` according to this question.
Problem
The boost chrono library vs1.51 on my macbook pro returns negative times when I substract endTime - startTime. If you print the timepoints you see that the end time is earlier than the startTime. How can this happen? ``` typedef boost::chrono::steady_clock clock_t; clock_t clock; // Start time measurement boost::chrono::time_point<clock_t> startTime = clock.now(); short test_times = 7; // Spend some time... for ( int i=0; i<test_times; ++i ) { xnodeptr spResultDoc=parser.parse(inputSrc); xstring sXmlResult = spResultDoc->str(); const char16_t* szDbg = sXmlResult.c_str(); BOOST_CHECK(spResultDoc->getNodeType()==xnode::DOCUMENT_NODE && sXmlResult == sXml); } // Stop time measurement boost::chrono::time_point<clock_t> endTime = clock.now(); clock_t::duration elapsed( endTime - startTime); std::cout << std::endl; std::cout << "Now time: " << clock.now() << std::endl; std::cout << "Start time: " << startTime << std::endl; std::cout << "End time: " << endTime << std::endl; std::cout << std::endl << "Total Parse time: " << elapsed << std::endl; std::cout << "Avarage Parse time per iteration: " << (boost::chrono::duration_cast<boost::chrono::milliseconds>(elapsed) / test_times) << std::endl; ``` I tried different clocks but no difference. Any help would be appreciated! EDIT: Forgot to add the output: Now time: 1 nanosecond since boot Start time: 140734799802912 nanoseconds since boot End time: 140734799802480 nanoseconds since boot Total Parse time: -432 nanoseconds Avarage Parse time per iteration: 0 milliseconds