diff options
author | Andres Freund <andres@anarazel.de> | 2022-11-21 20:34:17 -0800 |
---|---|---|
committer | Andres Freund <andres@anarazel.de> | 2022-11-21 20:34:17 -0800 |
commit | 92daeca45df6551dd85f92f7369eaa57a35fb8a9 (patch) | |
tree | ba02243ae9ee125666ea2aec25e50a95dc0927dd /src | |
parent | bd82928625e7ebe40eaaa57f3b4d03bae19491de (diff) | |
download | postgresql-92daeca45df6551dd85f92f7369eaa57a35fb8a9.tar.gz postgresql-92daeca45df6551dd85f92f7369eaa57a35fb8a9.zip |
Add wait event for pg_usleep() in perform_spin_delay()
The lwlock wait queue scalability issue fixed in a4adc31f690 was quite hard to
find because of the exponential backoff and because we adjust spins_per_delay
over time within a backend.
To make it easier to find similar issues in the future, add a wait event for
the pg_usleep() in perform_spin_delay(). Showing a wait event while spinning
without sleeping would increase the overhead of spinlocks, which we do not
want.
We may at some later point want to have more granular wait events, but that'd
be a substantial amount of work. This provides at least some insights into
something currently hard to observe.
Reviewed-by: Michael Paquier <michael@paquier.xyz>
Reviewed-by: Robert Haas <robertmhaas@gmail.com>
Reviewed-by: Alexander Korotkov <aekorotkov@gmail.com>
https://postgr.es/m/20221120204310.xywrhyxyytsajuuq@awork3.anarazel.de
Diffstat (limited to 'src')
-rw-r--r-- | src/backend/storage/lmgr/s_lock.c | 11 | ||||
-rw-r--r-- | src/backend/utils/activity/wait_event.c | 3 | ||||
-rw-r--r-- | src/include/utils/wait_event.h | 1 |
3 files changed, 15 insertions, 0 deletions
diff --git a/src/backend/storage/lmgr/s_lock.c b/src/backend/storage/lmgr/s_lock.c index 4e473ec27ec..c3227b11abc 100644 --- a/src/backend/storage/lmgr/s_lock.c +++ b/src/backend/storage/lmgr/s_lock.c @@ -53,6 +53,7 @@ #include "common/pg_prng.h" #include "port/atomics.h" #include "storage/s_lock.h" +#include "utils/wait_event.h" #define MIN_SPINS_PER_DELAY 10 #define MAX_SPINS_PER_DELAY 1000 @@ -136,7 +137,17 @@ perform_spin_delay(SpinDelayStatus *status) if (status->cur_delay == 0) /* first time to delay? */ status->cur_delay = MIN_DELAY_USEC; + /* + * Once we start sleeping, the overhead of reporting a wait event is + * justified. Actively spinning easily stands out in profilers, but + * sleeping with an exponential backoff is harder to spot... + * + * We might want to report something more granular at some point, but + * this is better than nothing. + */ + pgstat_report_wait_start(WAIT_EVENT_SPIN_DELAY); pg_usleep(status->cur_delay); + pgstat_report_wait_end(); #if defined(S_LOCK_TEST) fprintf(stdout, "*"); diff --git a/src/backend/utils/activity/wait_event.c b/src/backend/utils/activity/wait_event.c index 92f24a6c9bc..b2abd75ddbd 100644 --- a/src/backend/utils/activity/wait_event.c +++ b/src/backend/utils/activity/wait_event.c @@ -497,6 +497,9 @@ pgstat_get_wait_timeout(WaitEventTimeout w) case WAIT_EVENT_REGISTER_SYNC_REQUEST: event_name = "RegisterSyncRequest"; break; + case WAIT_EVENT_SPIN_DELAY: + event_name = "SpinDelay"; + break; case WAIT_EVENT_VACUUM_DELAY: event_name = "VacuumDelay"; break; diff --git a/src/include/utils/wait_event.h b/src/include/utils/wait_event.h index 6f2d5612e06..0b2100be4a2 100644 --- a/src/include/utils/wait_event.h +++ b/src/include/utils/wait_event.h @@ -145,6 +145,7 @@ typedef enum WAIT_EVENT_RECOVERY_APPLY_DELAY, WAIT_EVENT_RECOVERY_RETRIEVE_RETRY_INTERVAL, WAIT_EVENT_REGISTER_SYNC_REQUEST, + WAIT_EVENT_SPIN_DELAY, WAIT_EVENT_VACUUM_DELAY, WAIT_EVENT_VACUUM_TRUNCATE } WaitEventTimeout; |