Boost C++ Libraries: Ticket #8006: Boost::Chrono Assertion at startup - steady_clock::now() - Windows

meckschlager@… — Thu, 07 Feb 2013 11:01:37 GMT

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 — Thu, 07 Feb 2013 18:19:19 GMT

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 — Thu, 07 Feb 2013 18:22:56 GMT

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@… — Fri, 08 Feb 2013 06:54:42 GMT

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 — Fri, 08 Feb 2013 22:46:24 GMT

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.

status changed

viboes — Wed, 20 Mar 2013 22:15:54 GMT

status new → assigned

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

viboes — Wed, 10 Apr 2013 17:09:11 GMT

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?

status, description changed; resolution set

viboes — Sun, 19 May 2013 14:40:52 GMT

status assigned → closed
resolution → worksforme
description modified (diff)

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

status, version changed; resolution deleted

anonymous — Sat, 15 Jun 2013 07:29:57 GMT

status closed → reopened
version Boost 1.48.0 → Boost 1.50.0
resolution worksforme

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 — Sat, 15 Jun 2013 08:46:03 GMT

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?

status changed

viboes — Sat, 15 Jun 2013 09:09:00 GMT

status reopened → new

status changed

viboes — Sat, 15 Jun 2013 09:09:12 GMT

status new → assigned

summary changed

viboes — Sat, 15 Jun 2013 10:24:55 GMT

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

dmitry@… — Tue, 17 Sep 2013 11:49:31 GMT

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 — Sun, 20 Oct 2013 18:39:15 GMT

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

andreas.weis@… — Tue, 07 Jan 2014 09:42:43 GMT

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@… — Tue, 07 Jan 2014 09:57:59 GMT

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@… — Tue, 07 Jan 2014 10:00:29 GMT

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

viboes — Thu, 09 Jan 2014 06:27:28 GMT

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 — Sun, 19 Jan 2014 07:12:49 GMT

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

milestone changed

viboes — Sun, 19 Jan 2014 07:13:58 GMT

milestone To Be Determined → Boost 1.56.0

status changed; resolution set

viboes — Sun, 23 Feb 2014 13:41:18 GMT

status assigned → closed
resolution → fixed

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

dsp@… — Mon, 28 Jul 2014 05:47:47 GMT

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 — Thu, 26 Mar 2015 20:52:24 GMT

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 — Thu, 26 Mar 2015 20:52:28 GMT

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.

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

CharlesSavoie — Fri, 27 Mar 2015 03:38:39 GMT

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.

status changed; resolution deleted

viboes — Fri, 27 Mar 2015 07:09:37 GMT

status closed → reopened
resolution fixed

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

milestone changed

viboes — Fri, 27 Mar 2015 07:09:49 GMT

milestone Boost 1.56.0 → To Be Determined

viboes — Sun, 28 Jun 2015 09:49:16 GMT

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 — Sun, 28 Jun 2015 09:51:13 GMT

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

type changed

viboes — Sun, 25 Oct 2015 23:49:21 GMT

type Bugs → Support Requests

Moved to support until someone respond.

anonymous — Sun, 31 Jul 2016 21:14:05 GMT

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:

steady_clock::now()
shared_mutex::try_lock_shared_for()
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@… — Sun, 31 Jul 2016 21:15:12 GMT

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:

steady_clock::now()
shared_mutex::try_lock_shared_for()
shared_lock::try_lock_for()

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

status changed; resolution set; milestone deleted

viboes — Mon, 28 Aug 2017 05:26:38 GMT

status reopened → closed
resolution → fixed
milestone To Be Determined

This should be fixed since boost 1.56.

Please, reopen it it is still there.