Boost::Chrono Assertion at startup - steady_clock::now() - Windows

[meckschlager@…]

steady_clock::time_point now = steady_clock::now(); sometimes causes

Assertion failed: 0 && "Boost::Chrono - Internal Error", file C:\Projects\Librari
es\src\boost\boost_1_48_0\boost/chrono/detail/inlined/win/chrono.hpp, line 44
on Windows XP, boost 1.48

[meckschlager@…]

Now I see, boost::chrono is all thread unsafe and I was reading the time from 2 threads simultaneously (I guess that's so not uncommon) Is that really good? Locking the time reading method seems a bit weird to me...

[viboes]

Replying to meckschlager@…:

Now I see, boost::chrono is all thread unsafe and I was reading the time from 2 threads simultaneously (I guess that's so not uncommon)

Why do you think that the code is thread unsafe?

Is that really good? Locking the time reading method seems a bit weird to me...

What is weird for you?

[viboes]

Replying to meckschlager@…:

steady_clock::time_point now = steady_clock::now(); sometimes causes Assertion failed: 0 && "Boost::Chrono - Internal Error", file C:\Projects\Librari es\src\boost\boost_1_48_0\boost/chrono/detail/inlined/win/chrono.hpp, line 44 on Windows XP, boost 1.48

The code in question is

    if ( (nanosecs_per_tic <= 0.0L) ||
            (!boost::detail::win32::QueryPerformanceCounter( &pcount )) )
    {
      BOOST_ASSERT(0 && "Boost::Chrono - Internal Error");
      return steady_clock::time_point();
    }

could you check which condition is true?

[meckschlager@…]

Hi, thanks embracing that issue up!

Why do you think that the code is thread unsafe?

It states so in the chrono users guide "All functions in the library are thread-unsafe except when noted explicitly." (http://www.boost.org/doc/libs/1_52_0/doc/html/chrono/users_guide.html) thats why I came to the working solution

lock steady_clock::time_point now = steady_clock::now(); unlock

Now, it just seems unnecessary that multiple threads might have to wait to get the current time, which many os methods would return without requiring a lock.

cheers m.

[viboes]

Replying to meckschlager@…:

Hi, thanks embracing that issue up!

Why do you think that the code is thread unsafe?

It states so in the chrono users guide "All functions in the library are thread-unsafe except when noted explicitly." (http://www.boost.org/doc/libs/1_52_0/doc/html/chrono/users_guide.html) thats why I came to the working solution

lock steady_clock::time_point now = steady_clock::now(); unlock

Now, it just seems unnecessary that multiple threads might have to wait to get the current time, which many os methods would return without requiring a lock.

Hrr! I would fix this on the documentation, call to Clock::now() should be thread safe.

Thanks for the report.

[viboes]

I have fixed the documentation in revision [83511]. have you analyzed which condition was failing?

[viboes]

Replying to viboes:

I have fixed the documentation in revision [83511]. have you analyzed which condition was failing?

Could you tell me which is the result of

boost::detail::win32::QueryPerformanceCounter( &pcount ) 

when the program asserts?

[viboes]

I can not reproduce this error. Without your help I'm unable to help you? Reopen it if you have some insight.

[anonymous]

The same assertion happen in my application. Application running 4 threads constructed by thread_group.

pcount = {0x063ff1c300000000}
nanosecs_per_tic = 488.71054212171725


call stack
----------
boost::chrono::steady_clock::now()          Line 44 + 0x16 bytes	C++
boost::condition_variable_any::wait_for<... Line 508 + 0x23 bytes	C++
... (call from my application)


BOOST v1.50
MSVC 9
 - WIN32;_DEBUG;_WIN32_WINNT=0x0501
 - /Od (disabled optimization)

Running at: Windows 7, intel i7

Hope this information can help.

kt.

[viboes]

I don't know how to explain that QueryPerformanceCounter fails. Maybe the following remark could explain it

"Remarks

On a multiprocessor computer, it should not matter which processor is called. However, you can get different results on different processors due to bugs in the basic input/output system (BIOS) or the hardware abstraction layer (HAL)."

Anyway. it is surprising that Microsoft doesn't provides stead_clocks on their C++11 library implementation (See some post on SO).

I addition neither gcc nor libC++ provide them on windows as

      clock_gettime(CLOCK_MONOTONIC, &tp);

is not available.

What about not providing steady_clock on Windows?

[dmitry@…]

I'm getting this assertion from time to time when use asio::steady_timer which in turns uses steady_clock::now(). I've checked under debugger: nanosecs_per_tic is positive number (311.0 in my case), so QueryPerformanceCounter returns FALSE. GetLastError() in debugger returns 0, but I'm not sure this is the value set after QueryPerformanceCounter. Some googling reveals that the argument to this function must be aligned to 64 bit boundary. I've also checked address of the argument - and it looks aligned properly.

No more guesses from me :/

[viboes]

Thanks for looking on this. Do you think that retrying the call to QueryPerformanceCounter when fails could help?

[andreas.weis@…]

We get this problem as well. I can reproduce everything dmitry described on a Windows 7 x64 installation: QueryPerformanceCounter returns FALSE from time to time, but GetLastError reports ERROR_SUCCESS. The argument to QueryPerformanceCounter is aligned properly, and from what the MSDN docs say the function call should not fail, but it does anyway.

It really looks like the assert is too strict in this case. Maybe just retrying the call to QueryPerformanceCounter will help. As an alternative, I noticed that the chrono implementation shipping with the VC10 standard library uses the GetSystemTimeAsFileTime API instead of the high performance counters. Maybe those functions are more reliable?

[dmitry@…]

Andreas, actually using GetSystemTimeAsFileTime in MSVC STL is a bug. See bug with ID 719443 on Microsoft Connect website (I can't post link here).

Maybe it makes sense to wait until it's implemented and tested by Microsoft, then it can be "backported" to boost::chrono.

Regarding timers on Windows, this article claims that we can't rely on QueryPerformanceCounter API and should fall back to something different on some motherboard models and versions of Windows

[dmitry@…]

"This article" in my last post is the article on gamedev.net site called "Timer pitfalls and solutions"

[viboes]

Please, could you try this patch

diff --git a/include/boost/chrono/detail/inlined/win/chrono.hpp b/include/boost/chrono/detail/inlined/win/chrono.hpp
index 84cac01..e2128d6 100644
--- a/include/boost/chrono/detail/inlined/win/chrono.hpp
+++ b/include/boost/chrono/detail/inlined/win/chrono.hpp
@@ -38,12 +38,19 @@ namespace chrono_detail
     static double nanosecs_per_tic = chrono_detail::get_nanosecs_per_tic();
 
     boost::detail::winapi::LARGE_INTEGER_ pcount;
-    if ( (nanosecs_per_tic <= 0.0L) ||
-            (!boost::detail::winapi::QueryPerformanceCounter( &pcount )) )
+    if ( nanosecs_per_tic <= 0.0L )
     {
-      BOOST_ASSERT(0 && "Boost::Chrono - Internal Error");
+      BOOST_ASSERT(0 && "Boost::Chrono - get_nanosecs_per_tic Internal Error");
       return steady_clock::time_point();
     }
+    unsigned times=0;
+    while ( ! boost::detail::winapi::QueryPerformanceCounter( &pcount ) )
+    {
+      if ( ++times > 3 ) {
+        BOOST_ASSERT(0 && "Boost::Chrono - QueryPerformanceCounter Internal Error");
+        return steady_clock::time_point();
+      }
+    }
 
     return steady_clock::time_point(steady_clock::duration(
       static_cast<steady_clock::rep>((nanosecs_per_tic) * pcount.QuadPart)));

Giving as result

  steady_clock::time_point steady_clock::now() BOOST_NOEXCEPT
  {
    static double nanosecs_per_tic = chrono_detail::get_nanosecs_per_tic();

    boost::detail::winapi::LARGE_INTEGER_ pcount;
    if ( nanosecs_per_tic <= 0.0L )
    {
      BOOST_ASSERT(0 && "Boost::Chrono - get_nanosecs_per_tic Internal Error");
      return steady_clock::time_point();
    }
    unsigned times=0;
    while ( ! boost::detail::winapi::QueryPerformanceCounter( &pcount ) )
    {
      if ( ++times > 3 ) {
        BOOST_ASSERT(0 && "Boost::Chrono - QueryPerformanceCounter Internal Error");
        return steady_clock::time_point();
      }
    }

    return steady_clock::time_point(steady_clock::duration(
      static_cast<steady_clock::rep>((nanosecs_per_tic) * pcount.QuadPart)));
  }

[viboes]

​https://github.com/boostorg/chrono/commit/7e44be61ec499f3d78e3df3a4333ed5ad629f9df

[viboes]

Merged to master ​https://github.com/boostorg/chrono/commit/143260daeb2703961448a0928d199747ca34dfca

[dsp@…]

I have just downloaded the current boost 1.56.0 beta and I notice that the bug-fix applied to

steady_clock::now()

has not been correspondingly applied to the overload

steady_clock::now(system::error_code&)

which is available when BOOST_CHRONO_DONT_PROVIDE_HYBRID_ERROR_HANDLING is not defined.

I would strongly recommend to apply that patch to this function as well, otherwise the discrimination between error and non-error would be different when using either the first or the second overload

[CharlesSavoie]

I too hit this assertion on first use once in a while. It seems unlikely that QueryPerformanceCounter is failing on any modern hardware, or especially that calling it again would solve the problem.

However, the "static double nanosecs_per_tic" is definitely a problem in a multithreaded environment since the return value could be used by one thread before another thread has finished calling the chrono_detail::get_nanosecs_per_tic() function and assigning the value. Static local variables are never to be used in a multithreaded environment, which an MSDN blog post explains. I can't post a link here, so please search for "C++ scoped static initialization is not thread-safe, on purpose!".

I would recommend rethinking this method and all methods that use static local variables.

[CharlesSavoie]

I too hit this assertion on first use once in a while. It seems unlikely that QueryPerformanceCounter is failing on any modern hardware, or especially that calling it again would solve the problem.

However, the "static double nanosecs_per_tic" is definitely a problem in a multithreaded environment since the return value could be used by one thread before another thread has finished calling the chrono_detail::get_nanosecs_per_tic() function and assigning the value. Static local variables are never to be used in a multithreaded environment, which an MSDN blog post explains. I can't post a link here, so please search for "C++ scoped static initialization is not thread-safe, on purpose!".

I would recommend rethinking this method and all methods that use static local variables.

[CharlesSavoie]

Apologies for skipping some of the comments before replying; you did say QueryPerformanceCounter was sometimes returning false on your system. I'll attempt the patch and see if it helps my issue. Again, sorry for assuming otherwise, and for the double post.

[viboes]

Please, reopen a ticket when you want something to be done :)

[viboes]

I don't remember when

static double nanosecs_per_tic

has been removed, but there are no more static in the develop branch.

Please, could you check it?

[viboes]

​https://github.com/boostorg/chrono/commit/318e5f24297977d1bc126d2cd7ac65effe1cb7b7

[viboes]

Moved to support until someone respond.

[anonymous]

I've hit this assertion as well (Boost 1.55, VS 2013, Windows 10 64-bit) by trying to acquire a shared mutex for a limited period of time (1 ms). Here was the callstack:

1. steady_clock::now()
2. shared_mutex::try_lock_shared_for()
3. shared_lock::try_lock_for()

Although obviously not thread-safe, it didn't look to me that the assignment of the return value of chrono_detail::get_nanosecs_per_tic() to the static variable nanosecs_per_tic was the cause of the problem since nanosecs_per_tic had a positive value (about 311) at the time of the assertion.

This implies that the problem must have been with the return value of winapi::QueryPerformanceCounter() to which I didn't have access.

[franz@…]

I've hit this assertion as well (Boost 1.55, VS 2013, Windows 10 64-bit) by trying to acquire a shared mutex for a limited period of time (1 ms). Here was the callstack:

1. steady_clock::now()
2. shared_mutex::try_lock_shared_for()
3. shared_lock::try_lock_for()

Although obviously not thread-safe, it didn't look to me that the assignment of the return value of chrono_detail::get_nanosecs_per_tic() to the static variable nanosecs_per_tic was the cause of the problem since nanosecs_per_tic had a positive value (about 311) at the time of the assertion.

This implies that the problem must have been with the return value of winapi::QueryPerformanceCounter() to which I didn't have access.

[viboes]

This should be fixed since boost 1.56.

Please, reopen it it is still there.