From: Matteo Italia <matteo@mitalia.net>
To: gcc-patches@gcc.gnu.org
Cc: 10walls@gmail.com, ebotcazou@adacore.com
Subject: Re: [PATCH] libgcc: fix Win32 CV abnormal spurious wakeups in timed wait [PR113850]
Date: Sat, 10 Feb 2024 11:10:20 +0100 [thread overview]
Message-ID: <53b85d35-e949-4412-bcfb-8b9bacf6b8ca@mitalia.net> (raw)
In-Reply-To: <20240209141858.75189-1-matteo@mitalia.net>
[-- Attachment #1: Type: text/plain, Size: 4284 bytes --]
Il 09/02/24 15:18, Matteo Italia ha scritto:
> The Win32 threading model uses __gthr_win32_abs_to_rel_time to convert
> the timespec used in gthreads to specify the absolute time for end of
> the condition variables timed wait to a milliseconds value relative to
> "now" to pass to the Win32 SleepConditionVariableCS function.
>
> Unfortunately, the conversion is incorrect, as, due to a typo, it
> returns the relative time _in seconds_, so SleepConditionVariableCS
> receives a timeout value 1000 times shorter than it should be, resulting
> in a huge amount of spurious wakeups in calls such as
> std::condition_variable::wait_for or wait_until.
>
> This can be demonstrated easily by this sample program:
>
> ```
>
> 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 builds that other threading models (e.g. POSIX on Linux, or
> winpthreads or MCF on Win32) the output is something like
> ```
> pass: 0; wakeups: 2; elapsed: 2000 ms
> pass: 1; wakeups: 2; elapsed: 991 ms
> pass: 1; wakeups: 2; elapsed: 996 ms
> ```
>
> while on the affected builds it's more like
> ```
> pass: 0; wakeups: 1418; elapsed: 2000 ms
> pass: 1; wakeups: 479; elapsed: 988 ms
> pass: 1; wakeups: 2; elapsed: 992 ms
> ```
> (notice the huge number of wakeups).
>
> This commit fixes the conversion, adjusting the final division by
> NSEC100_PER_SEC to use NSEC100_PER_MSEC instead (already defined in the
> file and not used in any other place, so the problem here was probably a
> typo or some rebase/refactoring mishap).
>
> libgcc/ChangeLog:
>
> * config/i386/gthr-win32-cond.c (__gthr_win32_abs_to_rel_time):
> fix absolute timespec to relative milliseconds count
> conversion (it incorrectly returned seconds instead of
> milliseconds); this avoids spurious wakeups in
> __gthr_win32_cond_timedwait
> ---
> libgcc/config/i386/gthr-win32-cond.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/libgcc/config/i386/gthr-win32-cond.c b/libgcc/config/i386/gthr-win32-cond.c
> index ecb007a54b2..650c448f286 100644
> --- a/libgcc/config/i386/gthr-win32-cond.c
> +++ b/libgcc/config/i386/gthr-win32-cond.c
> @@ -78,7 +78,7 @@ __gthr_win32_abs_to_rel_time (const __gthread_time_t *abs_time)
> if (abs_time_nsec100 < now.nsec100)
> return 0;
>
> - return (DWORD) CEIL_DIV (abs_time_nsec100 - now.nsec100, NSEC100_PER_SEC);
> + return (DWORD) CEIL_DIV (abs_time_nsec100 - now.nsec100, NSEC100_PER_MSEC);
> }
>
> /* Check the sizes of the local version of the Win32 types. */
Re-reading the commit message I found a few typos, and it was generally
a bit more obscure than I like; reworded it now, hope it's better.
[-- Attachment #2: 0001-libgcc-fix-Win32-CV-abnormal-spurious-wakeups-in-tim.patch --]
[-- Type: text/x-patch, Size: 4039 bytes --]
From 1592691385f6639b64bd6ec43bdbd8175628fa12 Mon Sep 17 00:00:00 2001
From: Matteo Italia <matteo@mitalia.net>
Date: Fri, 9 Feb 2024 15:04:20 +0100
Subject: [PATCH] libgcc: fix Win32 CV abnormal spurious wakeups in timed wait
[PR113850]
To: gcc-patches@gcc.gnu.org
Cc: 10walls@gmail.com,
ebotcazou@adacore.com,
matteo@mitalia.net
Fix a typo in __gthr_win32_abs_to_rel_time that caused it to return a
relative time in seconds instead of milliseconds. As a consequence,
__gthr_win32_cond_timedwait called SleepConditionVariableCS with a
1000x shorter timeout; this caused ~1000x more spurious wakeups in
CV timed waits such as std::condition_variable::wait_for or wait_until,
resulting generally in much higher CPU usage.
This can be demonstrated by this 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 builds based on non-affected threading models (e.g. POSIX on Linux,
or winpthreads or MCF on Win32) the output is something like
```
pass: 0; wakeups: 2; elapsed: 2000 ms
pass: 1; wakeups: 2; elapsed: 991 ms
pass: 1; wakeups: 2; elapsed: 996 ms
```
while with the Win32 threading model we get
```
pass: 0; wakeups: 1418; elapsed: 2000 ms
pass: 1; wakeups: 479; elapsed: 988 ms
pass: 1; wakeups: 2; elapsed: 992 ms
```
(notice the huge number of wakeups in the timed wait cases only).
This commit fixes the conversion, adjusting the final division by
NSEC100_PER_SEC to use NSEC100_PER_MSEC instead (already defined in the
file and not used in any other place, so probably just a typo).
libgcc/ChangeLog:
* config/i386/gthr-win32-cond.c (__gthr_win32_abs_to_rel_time):
fix absolute timespec to relative milliseconds count
conversion (it incorrectly returned seconds instead of
milliseconds); this avoids spurious wakeups in
__gthr_win32_cond_timedwait
---
libgcc/config/i386/gthr-win32-cond.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/libgcc/config/i386/gthr-win32-cond.c b/libgcc/config/i386/gthr-win32-cond.c
index ecb007a54b2..650c448f286 100644
--- a/libgcc/config/i386/gthr-win32-cond.c
+++ b/libgcc/config/i386/gthr-win32-cond.c
@@ -78,7 +78,7 @@ __gthr_win32_abs_to_rel_time (const __gthread_time_t *abs_time)
if (abs_time_nsec100 < now.nsec100)
return 0;
- return (DWORD) CEIL_DIV (abs_time_nsec100 - now.nsec100, NSEC100_PER_SEC);
+ return (DWORD) CEIL_DIV (abs_time_nsec100 - now.nsec100, NSEC100_PER_MSEC);
}
/* Check the sizes of the local version of the Win32 types. */
--
2.34.1
next prev parent reply other threads:[~2024-02-10 10:10 UTC|newest]
Thread overview: 5+ messages / expand[flat|nested] mbox.gz Atom feed top
2024-02-09 14:18 Matteo Italia
2024-02-10 10:10 ` Matteo Italia [this message]
2024-02-17 0:24 ` Jonathan Yong
2024-02-19 13:48 ` Matteo Italia
2024-02-19 13:55 ` Jonathan Yong
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=53b85d35-e949-4412-bcfb-8b9bacf6b8ca@mitalia.net \
--to=matteo@mitalia.net \
--cc=10walls@gmail.com \
--cc=ebotcazou@adacore.com \
--cc=gcc-patches@gcc.gnu.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
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).