public inbox for gcc-bugs@sourceware.org
help / color / mirror / Atom feed
* [Bug libgcc/113850] New: condition variables timed wait does a lot of spurious wakeups on Win32 threading implementation
@ 2024-02-09 14:01 matteo at mitalia dot net
  2024-02-09 14:02 ` [Bug libgcc/113850] " matteo at mitalia dot net
                   ` (5 more replies)
  0 siblings, 6 replies; 7+ messages in thread
From: matteo at mitalia dot net @ 2024-02-09 14:01 UTC (permalink / raw)
  To: gcc-bugs

https://gcc.gnu.org/bugzilla/show_bug.cgi?id=113850

            Bug ID: 113850
           Summary: condition variables timed wait does a lot of spurious
                    wakeups on Win32 threading implementation
           Product: gcc
           Version: 13.1.0
            Status: UNCONFIRMED
          Severity: normal
          Priority: P3
         Component: libgcc
          Assignee: unassigned at gcc dot gnu.org
          Reporter: matteo at mitalia dot net
  Target Milestone: ---

Created attachment 57371
  --> https://gcc.gnu.org/bugzilla/attachment.cgi?id=57371&action=edit
Test program to reproduce the bug

Sample program:
```
#include <condition_variable>
#include <chrono>
#include <thread>
#include <stdio.h>

int main() {
    std::condition_variable cv;
    std::mutex mx;
    bool pass = false;

    auto thread_fn = [&](bool timed) {
        int wakeups = 0;
        using sc = std::chrono::system_clock;
        auto before = sc::now();
        std::unique_lock<std::mutex> ml(mx);
        if (timed) {
            cv.wait_for(ml, std::chrono::seconds(2), [&]{
                ++wakeups;
                return pass;
            });
        } else {
            cv.wait(ml, [&]{
                ++wakeups;
                return pass;
            });
        }
        printf("pass: %d; wakeups: %d; elapsed: %d ms\n", pass, wakeups,
                int((sc::now() - before) / std::chrono::milliseconds(1)));
        pass = false;
    };

    {
        // timed wait, let expire
        std::thread t(thread_fn, true);
        t.join();
    }

    {
        // timed wait, wake up explicitly after 1 second
        std::thread t(thread_fn, true);
        std::this_thread::sleep_for(std::chrono::seconds(1));
        {
            std::unique_lock<std::mutex> ml(mx);
            pass = true;
        }
        cv.notify_all();
        t.join();
    }

    {
        // non-timed wait, wake up explicitly after 1 second
        std::thread t(thread_fn, false);
        std::this_thread::sleep_for(std::chrono::seconds(1));
        {
            std::unique_lock<std::mutex> ml(mx);
            pass = true;
        }
        cv.notify_all();
        t.join();
    }
    return 0;
}
```

On Linux or on Win32 with the MCF threading model the output looks like
```
pass: 0; wakeups: 2; elapsed: 2000 ms
pass: 1; wakeups: 2; elapsed: 991 ms
pass: 1; wakeups: 2; elapsed: 996 ms
```

but with the Win32 "regular" threading model
```
pass: 0; wakeups: 1418; elapsed: 2000 ms
pass: 1; wakeups: 479; elapsed: 988 ms
pass: 1; wakeups: 2; elapsed: 992 ms
```

As can be seen here, there's a huge number of spurious wakeups, but only for
the timed waits; ultimately, I traced the problem to
`__gthr_win32_abs_to_rel_time`, that is used to convert from the absolute
`timespec` value (used internally through the gthread abstraction layer) to the
relative milliseconds to be passed to `SleepConditionVariableCS`:

```
/* Convert absolute thread time to relative time in millisecond.  */

DWORD
__gthr_win32_abs_to_rel_time (const __gthread_time_t *abs_time)
{
  union {
    ULONGLONG nsec100;
    FILETIME ft;
  } now;
  ULONGLONG abs_time_nsec100;

  /* The Windows epoch is 1/1/1601 while the Unix epoch is 1/1/1970.  */
  GetSystemTimeAsFileTime (&now.ft);
  now.nsec100 -= FILETIME_1970;

  abs_time_nsec100
    = (ULONGLONG) abs_time->tv_sec * NSEC100_PER_SEC
        + CEIL_DIV (abs_time->tv_nsec, 100);

  if (abs_time_nsec100 < now.nsec100)
    return 0;

  return (DWORD) CEIL_DIV (abs_time_nsec100 - now.nsec100, NSEC100_PER_SEC);
}
```

the final line has a typo: as the return value is in milliseconds, it should
divide by the constant NSEC100_PER_MSEC; as it is, it returns the value in
seconds, so it's going to be 1000 times smaller than it should, which results
in ~1000× spurious wakeups. I suppose that was a typo or some
rebase/refactoring mishap, as the correct constant was already defined above
(and wasn't used for anything else). The patch of course is trivial, and
applying it makes the test program return to its "normal" wakeups count.

^ permalink raw reply	[flat|nested] 7+ messages in thread
end of thread, other threads:[~2024-02-19 13:55 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2024-02-09 14:01 [Bug libgcc/113850] New: condition variables timed wait does a lot of spurious wakeups on Win32 threading implementation matteo at mitalia dot net
2024-02-09 14:02 ` [Bug libgcc/113850] " matteo at mitalia dot net
2024-02-09 19:50 ` ebotcazou at gcc dot gnu.org
2024-02-12  8:36 ` matteo at mitalia dot net
2024-02-16 23:47 ` cvs-commit at gcc dot gnu.org
2024-02-16 23:49 ` cvs-commit at gcc dot gnu.org
2024-02-19 13:55 ` jyong at gcc dot gnu.org

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).