Boost C++ Libraries: Ticket #5034: boost::this_thread::sleep either returns instantaneously or spins https://svn.boost.org/trac10/ticket/5034 <p> From the docs I'd expect to be able to write this: </p> <div class="wiki-code"><div class="code"><pre><span class="n">std</span><span class="o">::</span><span class="n">cout</span> <span class="o">&lt;&lt;</span> <span class="s">&quot;Time Before Sleep: &quot;</span> <span class="o">&lt;&lt;</span> <span class="n">boost</span><span class="o">::</span><span class="n">posix_time</span><span class="o">::</span><span class="n">microsec_clock</span><span class="o">::</span><span class="n">local_time</span><span class="p">()</span> <span class="o">&lt;&lt;</span> <span class="n">std</span><span class="o">::</span><span class="n">endl</span><span class="p">;</span> <span class="n">boost</span><span class="o">::</span><span class="n">this_thread</span><span class="o">::</span><span class="n">sleep</span><span class="p">(</span> <span class="n">boost</span><span class="o">::</span><span class="n">posix_time</span><span class="o">::</span><span class="n">seconds</span><span class="p">(</span><span class="mi">10</span><span class="p">)</span> <span class="p">);</span> <span class="n">std</span><span class="o">::</span><span class="n">cout</span> <span class="o">&lt;&lt;</span> <span class="s">&quot;Time After Sleep : &quot;</span> <span class="o">&lt;&lt;</span> <span class="n">boost</span><span class="o">::</span><span class="n">posix_time</span><span class="o">::</span><span class="n">microsec_clock</span><span class="o">::</span><span class="n">local_time</span><span class="p">()</span> <span class="o">&lt;&lt;</span> <span class="n">std</span><span class="o">::</span><span class="n">endl</span><span class="p">;</span> </pre></div></div><p> and have the 'this' thread sleep for approximately 10 seconds. Instead sleep returns instantaneously: </p> <pre class="wiki">Time Before Sleep: 2010-Dec-25 01:38:50.949160000 Time After Sleep : 2010-Dec-25 01:38:50.949436000 </pre><p> I've tried this with boost 1.45 and boost 1.43 using gcc 4.4 on debian x86_64. This used to work for me on 32-bit debian unstable using gcc 4.3. </p> <p> In addition to sleep returning instantaneously (happens every time) I have observed with more complex scenarios involving multiple threads sleep enter a busy spin, never returning (process needs killed). I am trying to create a minimal test case for this. </p> <p> Rather obviously the code where this hits is here in source:/boost/tags/release/Boost_1_45_0/libs/thread/src/pthread/thread.cpp </p> <div class="wiki-code"><div class="code"><pre> <span class="kt">void</span> <span class="nf">sleep</span><span class="p">(</span><span class="k">const</span> <span class="n">system_time</span><span class="o">&amp;</span> <span class="n">st</span><span class="p">)</span> <span class="p">{</span> <span class="n">detail</span><span class="o">::</span><span class="n">thread_data_base</span><span class="o">*</span> <span class="k">const</span> <span class="n">thread_info</span><span class="o">=</span><span class="n">detail</span><span class="o">::</span><span class="n">get_current_thread_data</span><span class="p">();</span> <span class="k">if</span><span class="p">(</span><span class="n">thread_info</span><span class="p">)</span> <span class="p">{</span> <span class="n">unique_lock</span><span class="o">&lt;</span><span class="n">mutex</span><span class="o">&gt;</span> <span class="n">lk</span><span class="p">(</span><span class="n">thread_info</span><span class="o">-&gt;</span><span class="n">sleep_mutex</span><span class="p">);</span> <span class="k">while</span><span class="p">(</span><span class="n">thread_info</span><span class="o">-&gt;</span><span class="n">sleep_condition</span><span class="p">.</span><span class="n">timed_wait</span><span class="p">(</span><span class="n">lk</span><span class="p">,</span><span class="n">st</span><span class="p">));</span> <span class="p">}</span> <span class="k">else</span> <span class="p">{</span> <span class="n">xtime</span> <span class="k">const</span> <span class="n">xt</span><span class="o">=</span><span class="n">get_xtime</span><span class="p">(</span><span class="n">st</span><span class="p">);</span> <span class="k">for</span> <span class="p">(</span><span class="kt">int</span> <span class="n">foo</span><span class="o">=</span><span class="mi">0</span><span class="p">;</span> <span class="n">foo</span> <span class="o">&lt;</span> <span class="mi">5</span><span class="p">;</span> <span class="o">++</span><span class="n">foo</span><span class="p">)</span> <span class="p">{</span> <span class="cp"># if defined(BOOST_HAS_PTHREAD_DELAY_NP)</span> <span class="n">timespec</span> <span class="n">ts</span><span class="p">;</span> <span class="n">to_timespec_duration</span><span class="p">(</span><span class="n">xt</span><span class="p">,</span> <span class="n">ts</span><span class="p">);</span> <span class="n">BOOST_VERIFY</span><span class="p">(</span><span class="o">!</span><span class="n">pthread_delay_np</span><span class="p">(</span><span class="o">&amp;</span><span class="n">ts</span><span class="p">));</span> <span class="cp"># elif defined(BOOST_HAS_NANOSLEEP)</span> <span class="n">timespec</span> <span class="n">ts</span><span class="p">;</span> <span class="n">to_timespec_duration</span><span class="p">(</span><span class="n">xt</span><span class="p">,</span> <span class="n">ts</span><span class="p">);</span> <span class="c1">// nanosleep takes a timespec that is an offset, not</span> <span class="c1">// an absolute time.</span> <span class="n">nanosleep</span><span class="p">(</span><span class="o">&amp;</span><span class="n">ts</span><span class="p">,</span> <span class="mi">0</span><span class="p">);</span> <span class="cp"># else</span> <span class="n">mutex</span> <span class="n">mx</span><span class="p">;</span> <span class="n">mutex</span><span class="o">::</span><span class="n">scoped_lock</span> <span class="n">lock</span><span class="p">(</span><span class="n">mx</span><span class="p">);</span> <span class="n">condition</span> <span class="n">cond</span><span class="p">;</span> <span class="n">cond</span><span class="p">.</span><span class="n">timed_wait</span><span class="p">(</span><span class="n">lock</span><span class="p">,</span> <span class="n">xt</span><span class="p">);</span> <span class="cp"># endif</span> <span class="n">xtime</span> <span class="n">cur</span><span class="p">;</span> <span class="n">xtime_get</span><span class="p">(</span><span class="o">&amp;</span><span class="n">cur</span><span class="p">,</span> <span class="n">TIME_UTC</span><span class="p">);</span> <span class="k">if</span> <span class="p">(</span><span class="n">xtime_cmp</span><span class="p">(</span><span class="n">xt</span><span class="p">,</span> <span class="n">cur</span><span class="p">)</span> <span class="o">&lt;=</span> <span class="mi">0</span><span class="p">)</span> <span class="k">return</span><span class="p">;</span> <span class="p">}</span> <span class="p">}</span> <span class="p">}</span> </pre></div></div><p> Specifically something appears to go wrong here: </p> <pre class="wiki"> if(thread_info) { unique_lock&lt;mutex&gt; lk(thread_info-&gt;sleep_mutex); while(thread_info-&gt;sleep_condition.timed_wait(lk,st)); } </pre><p> I came across this while writing a test for something else and so have not been able to follow up in any more detail yet at this time. </p> en-us Boost C++ Libraries /htdocs/site/boost.png https://svn.boost.org/trac10/ticket/5034 Trac 1.4.3 Jamie Allsop <ja11sop@…> Tue, 04 Jan 2011 16:41:26 GMT <link>https://svn.boost.org/trac10/ticket/5034#comment:1 </link> <guid isPermaLink="false">https://svn.boost.org/trac10/ticket/5034#comment:1</guid> <description> <p> When I see the 'spinning' I can grab the following back trace - which doesn't say much but points to the issue being in the <code>timed_wait()</code>, see frame 3. </p> <pre class="wiki">#0 0x00007ffff7bcbf05 in __pthread_mutex_lock (mutex=0xcf8d00) at pthread_mutex_lock.c:61 #1 0x00000000008bc1c5 in boost::mutex::lock (this=0xcf8d00) at /thirdparty/boost/boost_1_45/source/boost/thread/pthread/mutex.hpp:52 #2 0x00000000009d3d76 in boost::unique_lock&lt;boost::mutex&gt;::lock() () #3 0x00000000009f3bf9 in boost::condition_variable::timed_wait(boost::unique_lock&lt;boost::mutex&gt;&amp;, boost::posix_time::ptime const&amp;) () #4 0x00000000009f2b86 in boost::this_thread::sleep(boost::posix_time::ptime const&amp;) () #5 0x00000000008e68a1 in boost::this_thread::sleep&lt;boost::posix_time::seconds&gt; (rel_time=...) at /thirdparty/boost/boost_1_45/source/boost/thread/pthread/thread_data.hpp:138 </pre><p> I still don't have a small enough test case to post but thought at least the back trace would help. To summarise then it seems that there is an issue with the <code>timed_wait()</code>. Either I see it return immediately or spin. </p> <p> It should also be noted that the call to <code>boost::this_thread::sleep()</code> occurs once only in a single thread, in my case the main thread. </p> </description> <category>Ticket</category> </item> <item> <dc:creator>Chris Newbold</dc:creator> <pubDate>Wed, 05 Jan 2011 18:30:08 GMT</pubDate> <title>cc set https://svn.boost.org/trac10/ticket/5034#comment:2 https://svn.boost.org/trac10/ticket/5034#comment:2 <ul> <li><strong>cc</strong> <span class="trac-author">cnewbold@…</span> added </li> </ul> Ticket Jamie Allsop <ja11sop@…> Thu, 27 Jan 2011 13:17:19 GMT <link>https://svn.boost.org/trac10/ticket/5034#comment:3 </link> <guid isPermaLink="false">https://svn.boost.org/trac10/ticket/5034#comment:3</guid> <description> <p> I should add here that I tried this with a debug build of boost thread and could not get any better back trace. I also suspect this is a 64-bit only problem since others have reported no issues on 32-bit builds. </p> </description> <category>Ticket</category> </item> <item> <dc:creator>Anthony Williams</dc:creator> <pubDate>Thu, 27 Jan 2011 14:05:38 GMT</pubDate> <title>status changed; resolution set https://svn.boost.org/trac10/ticket/5034#comment:4 https://svn.boost.org/trac10/ticket/5034#comment:4 <ul> <li><strong>status</strong> <span class="trac-field-old">new</span> → <span class="trac-field-new">closed</span> </li> <li><strong>resolution</strong> → <span class="trac-field-new">worksforme</span> </li> </ul> <p> I cannot reproduce this problem on 64-bit Ubuntu 10.10 </p> Ticket anonymous Mon, 14 Feb 2011 10:59:30 GMT <link>https://svn.boost.org/trac10/ticket/5034#comment:5 </link> <guid isPermaLink="false">https://svn.boost.org/trac10/ticket/5034#comment:5</guid> <description> <p> Similar problem was described here <a class="ext-link" href="http://lists.boost.org/boost-users/2010/10/63635.php"><span class="icon">​</span>http://lists.boost.org/boost-users/2010/10/63635.php</a> I can reproduce it easily on Linux. </p> </description> <category>Ticket</category> </item> <item> <author>Jamie Allsop <ja11sop@…></author> <pubDate>Tue, 22 Feb 2011 23:21:34 GMT</pubDate> <title/> <link>https://svn.boost.org/trac10/ticket/5034#comment:6 </link> <guid isPermaLink="false">https://svn.boost.org/trac10/ticket/5034#comment:6</guid> <description> <p> Can you be more specific about how you reproduce this on Linux? What compile flags you use and on what distribution and architecture? I think this ticket clearly needs re-opened. </p> </description> <category>Ticket</category> </item> <item> <author>storm@…</author> <pubDate>Fri, 24 Jun 2011 01:50:34 GMT</pubDate> <title/> <link>https://svn.boost.org/trac10/ticket/5034#comment:7 </link> <guid isPermaLink="false">https://svn.boost.org/trac10/ticket/5034#comment:7</guid> <description> <p> I see the same exact problem on ubuntu 32bit, on virtualbox (mac host), but it happens ONLY when I run the program in gdb. </p> <p> Spawning 4 thread, each one cycling and sleeping for up to one second between any cycle, I always get 1 or 2 threads that never exit from the sleep. </p> <p> Part of code: </p> <pre class="wiki"> ... cout &lt;&lt; "Updater started with id " &lt;&lt; boost::this_thread::get_id() &lt;&lt; endl; while (true) { /* do things */ // Throttle elapsed = boost::posix_time::microsec_clock::universal_time() - this-&gt;last_update; sleep_for = interval - elapsed; cout &lt;&lt; boost::this_thread::get_id() &lt;&lt; " sleeping for " &lt;&lt; sleep_for &lt;&lt; endl; boost::this_thread::sleep(sleep_for); cout &lt;&lt; boost::this_thread::get_id() &lt;&lt; " sleeped for " &lt;&lt; sleep_for &lt;&lt; endl; } ... </pre><p> I get on console: </p> <pre class="wiki">Updater started with id 0x8090198 Updater started with id 0x8090810 0x8090198 sleeping for 0x8090810 sleeping for 00:00:00.998689 00:00:00.997377 Updater started with id 0x8090fb0 0x8090fb0 sleeping for 00:00:00.998187 Updater started with id 0x8091378 0x8091378 sleeping for 00:00:00.998543 0x8090198 sleeped for 00:00:00.997377 0x8090198 sleeping for 00:00:00.999980 0x8090810 sleeped for 00:00:00.998689 0x8090810 sleeping for 00:00:00.999979 0x8091378 sleeped for 00:00:00.998543 0x8091378 sleeping for 00:00:00.999979 0x8090198 sleeped for 00:00:00.999980 0x8090198 sleeping for 00:00:00.999948 0x8090810 sleeped for 00:00:00.999979 0x8090810 sleeping for 00:00:00.999951 0x8091378 sleeped for 00:00:00.999979 0x8091378 sleeping for 00:00:00.999958 </pre><p> ( 0x8090fb0 is blocked ) </p> </description> <category>Ticket</category> </item> <item> <dc:creator>anonymous</dc:creator> <pubDate>Mon, 11 Jul 2011 21:27:42 GMT</pubDate> <title/> <link>https://svn.boost.org/trac10/ticket/5034#comment:8 </link> <guid isPermaLink="false">https://svn.boost.org/trac10/ticket/5034#comment:8</guid> <description> <p> I think this thread: <a class="ext-link" href="http://lists.boost.org/boost-users/2011/07/69287.php"><span class="icon">​</span>http://lists.boost.org/boost-users/2011/07/69287.php</a> may also describe behaviour that is indirectly related to this issue. </p> </description> <category>Ticket</category> </item> </channel> </rss>