* [PATCH] libgcc: fix Win32 CV abnormal spurious wakeups in timed wait [PR113850]
@ 2024-02-09 14:18 Matteo Italia
2024-02-10 10:10 ` Matteo Italia
0 siblings, 1 reply; 5+ messages in thread
From: Matteo Italia @ 2024-02-09 14:18 UTC (permalink / raw)
To: gcc-patches; +Cc: Matteo Italia, 10walls, ebotcazou
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. */
--
2.34.1
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] libgcc: fix Win32 CV abnormal spurious wakeups in timed wait [PR113850]
2024-02-09 14:18 [PATCH] libgcc: fix Win32 CV abnormal spurious wakeups in timed wait [PR113850] Matteo Italia
@ 2024-02-10 10:10 ` Matteo Italia
2024-02-17 0:24 ` Jonathan Yong
0 siblings, 1 reply; 5+ messages in thread
From: Matteo Italia @ 2024-02-10 10:10 UTC (permalink / raw)
To: gcc-patches; +Cc: 10walls, ebotcazou
[-- 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
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] libgcc: fix Win32 CV abnormal spurious wakeups in timed wait [PR113850]
2024-02-10 10:10 ` Matteo Italia
@ 2024-02-17 0:24 ` Jonathan Yong
2024-02-19 13:48 ` Matteo Italia
0 siblings, 1 reply; 5+ messages in thread
From: Jonathan Yong @ 2024-02-17 0:24 UTC (permalink / raw)
To: Matteo Italia, gcc-patches; +Cc: ebotcazou
On 2/10/24 10:10, Matteo Italia wrote:
> 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.
>>
> 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.
Thanks, pushed to master and 13.x branches.
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] libgcc: fix Win32 CV abnormal spurious wakeups in timed wait [PR113850]
2024-02-17 0:24 ` Jonathan Yong
@ 2024-02-19 13:48 ` Matteo Italia
2024-02-19 13:55 ` Jonathan Yong
0 siblings, 1 reply; 5+ messages in thread
From: Matteo Italia @ 2024-02-19 13:48 UTC (permalink / raw)
To: Jonathan Yong, gcc-patches; +Cc: ebotcazou
Il 17/02/24 01:24, Jonathan Yong ha scritto:
> On 2/10/24 10:10, Matteo Italia wrote:
>> 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.
>>>
>> 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.
>
> Thanks, pushed to master and 13.x branches.
Great, thank you! Do I need to change the status of the Bugzilla entry
to RESOLVED, or it's going to be closed automatically at the next
releases, or something else?
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] libgcc: fix Win32 CV abnormal spurious wakeups in timed wait [PR113850]
2024-02-19 13:48 ` Matteo Italia
@ 2024-02-19 13:55 ` Jonathan Yong
0 siblings, 0 replies; 5+ messages in thread
From: Jonathan Yong @ 2024-02-19 13:55 UTC (permalink / raw)
To: Matteo Italia, gcc-patches; +Cc: ebotcazou
On 2/19/24 13:48, Matteo Italia wrote:
> Il 17/02/24 01:24, Jonathan Yong ha scritto:
>> On 2/10/24 10:10, Matteo Italia wrote:
>>> 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.
>>>>
>>> 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.
>>
>> Thanks, pushed to master and 13.x branches.
> Great, thank you! Do I need to change the status of the Bugzilla entry
> to RESOLVED, or it's going to be closed automatically at the next
> releases, or something else?
Closed as resolved, thanks.
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2024-02-19 13:56 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2024-02-09 14:18 [PATCH] libgcc: fix Win32 CV abnormal spurious wakeups in timed wait [PR113850] Matteo Italia
2024-02-10 10:10 ` Matteo Italia
2024-02-17 0:24 ` Jonathan Yong
2024-02-19 13:48 ` Matteo Italia
2024-02-19 13:55 ` Jonathan Yong
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).