On Thu, Jul 30, 2026 at 8:46 AM Jakub Wartak <[email protected]> wrote: > > On Tue, Jul 28, 2026 at 4:00 PM Robert Haas <[email protected]> wrote: > > > > On Mon, Jul 27, 2026 at 2:47 AM Jakub Wartak > > <[email protected]> wrote: > > > Now the GUC/concept is called log_excess_connection_attempts, however it > > > is > > > based on postmaster's CPU time or delay in getting CPU scheduled at all. > > > I think name is nice, but one can argue it should be > > > log_excess_postmaster_cpu_time too technically, but I find it way too > > > long. > > > > I think this is a good direction, but over the years I've acquired a > > healthy skepticism of features where the documentation and the actual > > behavior of the code drift apart like this. Since the feature name is > > log_excess_connection_attempts, a user will tend to think that what > > triggers the message is when there are a lot of connection attempts, > > but it's actually trigger by high CPU usage or too much time passing > > between consecutive points at which we consider logging the message. > > OK, I've renamed the CPU overload one to simply just log_postmaster_overloads > and also added the log_postmaster_excess_connections=N for the reasons > explained > below. > > > Plus, checking the CPU usage like this is somewhat expensive, and I > > doubt that high CPU usage over a 1 second period is even meaningful. > > getrusage() is pretty cheap actually as only use *if* that would be > enabled by user + just called once every 1s (which itself compared > to cap of 1-3 thousands of fork()/s is nothing I would say less than > a noise?) + we use RUSAGE_SELF (so by definition it does not iterate on > kernel side fo cpu time of all the possible children). > > > I suspect the right thing to do here is drop all the CPU usage stuff > > and just make it a test for whether the connection rate is high. Then > > you could also make the value of the parameter an integer, like: > > log_excessive_connection_rate=100 to log whenever there are >=100 > > connection in 1 second. That gives the parameter a very specific > > charter that is easy to guess even from just looking at the name. A > > side benefit of this is that you could write a test that would pass > > reliably; just set log_excessive_connection_rate=1 and try to connect. > > 1 >= 1 so a message should appear. > > The problem with just the raw new sessions/s is that how the user is > supposed to know to which value set it to? She/he could observe > rate of pg_stat_database.{sessions,parallel_workers_launched}, and based > to come up with average and then set it up to some value. > > So perhaps we could have two, (the main intention was to just stick to > the CPU usage, but the v3 has bonus second GUC to allow what You just > described). With CPU usage, I think people would agree that anything > >=70-80% is clear sign of overload (so that's just nice on/off toggle). > While with setting raw number of connections with > log_postmaster_excess_connections I've myself reproduced <200-300 > connections/s taking 100% sys for postmaster and it would never occur > to me that I would have to set it up to such _low_ value. > > Anyway please just take a look on [1] to see that it might be not even > obvious that connection startup might be a problem, but if we would even > have this on by default such cases would be fairly trivial to solve in > like seconds (just read the log) and there are fairly more examples > where postmaster bottleneck can be an issue (people running apps usually > do not have visibiity tracing of avg/p95/p99 database connection times > until their apps crap out with errors that those connections failed > due timeouts). > > -J. > > [1] - > https://www.postgresql.org/message-id/CAFbpF8OA44_UG%2BRYJcWH9WjF7E3GA6gka3gvH6nsrSnEe9H0NA%40mail.gmail.com
I've got another occurence where this could be useful, so this pushed me into polishing this patch. It still has two log_postmaster_excess_connections and log_postmaster_overloads and they are both useful. v4 attached, changes since last time: - reset stats more often (when GUCs where enabled single spurious LOG emission happened with stats since the restart) - add counting of accept()/fork() failures too (but not the max_conns hits as) - convert "elapsed" from integer to double to make the math easier - pgindent One doubt I have is this: if both GUCs are enabled (with log_postmaster_excess_connections set to e.g. value of 200), we get duplicate LOG entries, but I thnk we could unitfy the LOG line in such case: 2026-11-09 12:06:30.773 CET [751665] LOG: postmaster potentially overloaded, stats: avg 3179.96 conns/sec; 3178.96 disconns/sec; 0.00 conn errors/sec; 0.00 parallel workers started/sec; CPU: user: 0.02 s, system: 0.97 s, elapsed: 1.00 s 2026-11-09 12:06:30.773 CET [751665] LOG: postmaster excessive connections, stats: avg 3179.96 conns/sec; 3178.96 disconns/sec; 0.00 conn errors/sec; 0.00 parallel workers started/sec; CPU: user: 0.02 s, system: 0.97 s, elapsed: 1.00 s 2026-11-09 12:06:31.773 CET [751665] LOG: postmaster potentially overloaded, stats: avg 3177.37 conns/sec; 3179.37 disconns/sec; 0.00 conn errors/sec; 0.00 parallel workers started/sec; CPU: user: 0.02 s, system: 0.97 s, elapsed: 1.00 s 2026-11-09 12:06:31.773 CET [751665] LOG: postmaster excessive connections, stats: avg 3177.37 conns/sec; 3179.37 disconns/sec; 0.00 conn errors/sec; 0.00 parallel workers started/sec; CPU: user: 0.02 s, system: 0.97 s, elapsed: 1.00 s [..] instead we could do "postmaster overloaded and getting excessive connections, stats: (..)", -J.
From 05b1f3eb7d7f7a760a53e75d7f37b040bdc12996 Mon Sep 17 00:00:00 2001 From: Jakub Wartak <[email protected]> Date: Wed, 27 May 2026 11:39:21 +0200 Subject: [PATCH v4] Add log_postmaster_overloads and log_postmaster_excess_connections log_postmaster_overloads - Add possibility to log basic resource consumption, activity metrics and errors by the postmaster process in cases where it would be overloaded (defined as 75% or getting late on CPU). log_postmaster_excess_connections - Allow logging the same postmaster diagnostic stats just based just on the rate of new connections accepted per second, independent of the postmaster's own CPU usage. This GUC allows detecting connection storms even before the postmaster is not fully saturated. Author: Jakub Wartak <[email protected]> Reviewed-by: Robert Haas <[email protected]> Reviewed-by: Quan Zongliang <[email protected]> Discussion: https://postgr.es/m/CAKZiRmxeTNAe_VZ9m%3Drt%3D5155mvL%3DCFsQ4ENJWhuUdgMe%3D_Udg%40mail.gmail.com --- doc/src/sgml/config.sgml | 99 ++++++++ src/backend/postmaster/bgworker.c | 10 + src/backend/postmaster/postmaster.c | 213 +++++++++++++++++- src/backend/utils/misc/guc_parameters.dat | 16 ++ src/backend/utils/misc/postgresql.conf.sample | 5 + src/include/postmaster/bgworker_internals.h | 1 + src/include/postmaster/postmaster.h | 2 + src/test/postmaster/meson.build | 1 + src/test/postmaster/t/005_log_postmaster.pl | 89 ++++++++ 9 files changed, 434 insertions(+), 2 deletions(-) create mode 100644 src/test/postmaster/t/005_log_postmaster.pl diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index a6a2df177f2..9ae5d2063d7 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -8522,6 +8522,105 @@ log_line_prefix = '%m [%p] %q%u@%d/%a ' </listitem> </varlistentry> + <varlistentry id="guc-log-postmaster-excess-connections" xreflabel="log_postmaster_excess_connections"> + <term><varname>log_postmaster_excess_connections</varname> (<type>integer</type>) + <indexterm> + <primary><varname>log_postmaster_excess_connections</varname></primary> + <secondary>configuration parameter</secondary> + </indexterm> + </term> + <listitem> + <para> + If set to a positive value, the postmaster checks once per second + how many new connections it accepted during that second, and if + that rate exceeds this many connections per second, emits the same + <literal>LOG</literal>-level message as + <xref linkend="guc-log-postmaster-overloads"/> does. This can help + detect connection storms even in cases where the postmaster is not + overloaded. + </para> + <para> + The default is <literal>0</literal>, which disables this check. + This parameter can only be set in the + <filename>postgresql.conf</filename> file or on the server + command line. + </para> + </listitem> + </varlistentry> + + <varlistentry id="guc-log-postmaster-overloads" xreflabel="log_postmaster_overloads"> + <term><varname>log_postmaster_overloads</varname> (<type>boolean</type>) + <indexterm> + <primary><varname>log_postmaster_overloads</varname></primary> + <secondary>configuration parameter</secondary> + </indexterm> + </term> + <listitem> + <para> + If enabled, the postmaster checks its own resource usage every + second, and if it has used more than 75% of one CPU core during + that second, or could not serve at least one incoming connection, + emits a message at <literal>LOG</literal> level + summarizing its recent activity. Since by design the postmaster is a + single process handling all new connections and parallel worker + launches, constant CPU usage above this threshold indicates that it + may be struggling to keep up, typically because of a very high rate of + incoming connection attempts. A sample message looks like: + <screen> + postmaster potentially overloaded, stats: avg 2905.00 conns/sec; 2904.00 disconns/sec; 0.00 conn errors/sec; 0.00 parallel workers started/sec; CPU: user: 0.01 s, system: 0.97 s, elapsed: 1.00 s + </screen> + </para> + <para> + <literal>conn errors</literal> counts connections the postmaster + could not serve: + </para> + <itemizedlist> + <listitem> + <para> + a failed <function>accept()</function> system call, for example + because the postmaster ran out of file descriptors + </para> + </listitem> + <listitem> + <para> + a failure to start a backend process for the connection, for + example because <function>fork()</function> failed due to lack of + memory or process limits + </para> + </listitem> + <listitem> + <para> + a connection that was only given an error because the server was + starting up, shutting down, in recovery, or had no free child + process slot + </para> + </listitem> + </itemizedlist> + <para> + Ordinary <quote>too many clients</quote> rejections caused by + <xref linkend="guc-max-connections"/> are issued by a regular backend + process and are not counted. Note that a single parallel query may + register multiple workers. The final <literal>CPU</literal> portion + reports the postmaster's own resource usage over the same one second + window. See also + <xref linkend="guc-log-postmaster-excess-connections"/>, which emits + the same message based just on the incoming connection rate. + </para> + <para> + The default is <literal>off</literal>. This parameter can only be + set in the <filename>postgresql.conf</filename> file or on the + server command line. + </para> + <tip> + <para> + If you are receiving warnings about potentially overloaded postmaster, + be sure to investigate the application, their connection pools and usage + of independent connection poolers. Be also sure to double-check if the + huge pages are used and if the OS is not being overloaded. + </para> + </tip> + </listitem> + </varlistentry> <varlistentry id="guc-log-recovery-conflict-waits" xreflabel="log_recovery_conflict_waits"> <term><varname>log_recovery_conflict_waits</varname> (<type>boolean</type>) diff --git a/src/backend/postmaster/bgworker.c b/src/backend/postmaster/bgworker.c index 4aef037d5ae..81fcc55e2c5 100644 --- a/src/backend/postmaster/bgworker.c +++ b/src/backend/postmaster/bgworker.c @@ -239,6 +239,16 @@ BackgroundWorkerShmemInit(void *arg) } } +/* + * Return the total count of parallel-worker registrations seen since + * startup by doing unlocked read (for stats it should be good enough). + */ +uint32 +GetParallelWorkerRegisterCount(void) +{ + return BackgroundWorkerData->parallel_register_count; +} + /* * Search the postmaster's backend-private list of RegisteredBgWorker objects * for the one that maps to the given slot number. diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c index f53aa9c404d..2e648449ee3 100644 --- a/src/backend/postmaster/postmaster.c +++ b/src/backend/postmaster/postmaster.c @@ -120,6 +120,7 @@ #include "tcop/tcopprot.h" #include "utils/datetime.h" #include "utils/memutils.h" +#include "utils/pg_rusage.h" #include "utils/pidfile.h" #include "utils/timestamp.h" #include "utils/varlena.h" @@ -241,6 +242,102 @@ bool EnableSSL = false; int PreAuthDelay = 0; int AuthenticationTimeout = 60; +/* + * If enabled, check postmaster CPU usage every PM_STATS_CHECK_INTERVAL + * seconds. + */ +bool log_postmaster_overloads = false; + +/* How often to check when log_postmaster_overloads is on */ +#define PM_STATS_CHECK_INTERVAL 1 + +/* + * Since the postmaster is single process, consider it overloaded when + * it has used more than this fraction of one core during the check + * interval. + */ +#define PM_STATS_CPU_THRESHOLD 0.75 + +/* + * Alternatively, also log if the check itself ran this much later than + * intended (as a multipler of the PM_STATS_CHECK_INTERVAL above). Postmaster + * that isn't getting scheduled in time on CPU to run checks on schedule + * is a sign of trouble even if it is not itself burning much CPU. + */ +#define PM_STATS_ELAPSED_LATE_FACTOR 1.2 + +/* + * If positive, log when the rate of new connections accepted during the + * preceding PM_STATS_CHECK_INTERVAL exceeds this many connections per + * second. 0 disables this check. + */ +int log_postmaster_excess_connections = 0; + +/* pmstats_ru0.tv is the start of the (statistics) interval for log_postmaster_* GUCs */ +static PGRUsage pmstats_ru0; + +/* Running counts used by log_postmaster_* GUCs */ +static uint64 pmstats_new_connections = 0; +static uint64 pmstats_disconnections = 0; +static uint64 pmstats_connection_errors = 0; +static uint64 last_pmstats_connections = 0; +static uint64 last_pmstats_connection_errors = 0; +static uint64 last_pmstats_disconnections = 0; +static uint32 last_pmstats_parallel_regs = 0; + +static bool +pmstats_enabled(void) +{ + return log_postmaster_overloads || log_postmaster_excess_connections > 0; +} + +/* Reset stats when starting a new check interval */ +static void +pmstats_reset(void) +{ + last_pmstats_connections = pmstats_new_connections; + last_pmstats_disconnections = pmstats_disconnections; + last_pmstats_connection_errors = pmstats_connection_errors; + last_pmstats_parallel_regs = GetParallelWorkerRegisterCount(); + pg_rusage_init(&pmstats_ru0); +} + +/* + * Returns seconds elapsed between the start of the current check interval + * and the given time. + */ +static double +pmstats_elapsed(const struct timeval *now) +{ + return (double) (now->tv_sec - pmstats_ru0.tv.tv_sec) + + (double) (now->tv_usec - pmstats_ru0.tv.tv_usec) / 1000000.0; +} + +/* Returns how many milliseconds to sleep until the next check. */ +static int +pmstats_ms_to_next_check(void) +{ + struct timeval tv; + int64 elapsed_us, + remaining_us; + + gettimeofday(&tv, NULL); + elapsed_us = (int64) (tv.tv_sec - pmstats_ru0.tv.tv_sec) * 1000000 + + (tv.tv_usec - pmstats_ru0.tv.tv_usec); + remaining_us = (int64) PM_STATS_CHECK_INTERVAL * 1000000 - elapsed_us; + + /* Did the interval just started? */ + if (remaining_us >= (int64) PM_STATS_CHECK_INTERVAL * 1000000) + return PM_STATS_CHECK_INTERVAL * 1000; /* sleep full interval */ + + /* Are we already late? */ + if (remaining_us <= 0) + return 1; + + /* Convert us to ms, but round up */ + return (int) ((remaining_us + 999) / 1000); +} + bool log_hostname; /* for ps display and logging */ bool enable_bonjour = false; @@ -1635,10 +1732,15 @@ DetermineSleepTime(void) /* result of TimestampDifferenceMilliseconds is in [0, INT_MAX] */ ms = (int) TimestampDifferenceMilliseconds(GetCurrentTimestamp(), next_wakeup); + if (pmstats_enabled()) + ms = Min(ms, pmstats_ms_to_next_check()); return Min(60 * 1000, ms); } - return 60 * 1000; + if (pmstats_enabled()) + return Min(60 * 1000, pmstats_ms_to_next_check()); + else + return 60 * 1000; } /* @@ -1683,6 +1785,7 @@ ServerLoop(void) ConfigurePostmasterWaitSet(true); last_lockfile_recheck_time = last_touch_time = time(NULL); + pmstats_reset(); for (;;) { @@ -1724,7 +1827,13 @@ ServerLoop(void) ClientSocket s; if (AcceptConnection(events[i].fd, &s) == STATUS_OK) - BackendStartup(&s); + { + pmstats_new_connections++; + if (BackendStartup(&s) != STATUS_OK) + pmstats_connection_errors++; + } + else + pmstats_connection_errors++; /* We no longer need the open socket in this process */ if (s.sock != PGINVALID_SOCKET) @@ -1823,6 +1932,85 @@ ServerLoop(void) TouchSocketLockFiles(); last_touch_time = now; } + + /* + * Optionally check periodically whether the postmaster is short of + * CPU or is being handed an excessive rate of new connections, and if + * so, log connection and resource usage statistics to help diagnose + * the root cause (e.g. a flood of connection attempts or slow + * fork()). + */ + if (pmstats_enabled()) + { + struct timeval tv; + double elapsed; + + gettimeofday(&tv, NULL); + elapsed = pmstats_elapsed(&tv); + + /* Did the clock go backwards? Then just start a new interval. */ + if (elapsed < 0.0) + { + pmstats_reset(); + } + else if (elapsed >= PM_STATS_CHECK_INTERVAL) + { + uint32 cur_parallel_regs = GetParallelWorkerRegisterCount(); + uint64 conn_delta = pmstats_new_connections - last_pmstats_connections; + uint64 disc_delta = pmstats_disconnections - last_pmstats_disconnections; + uint64 err_delta = pmstats_connection_errors - last_pmstats_connection_errors; + uint32 pqw_delta = cur_parallel_regs - last_pmstats_parallel_regs; + double conn_rate = (double) conn_delta / elapsed; + PGRUsage cur_ru; + double cpu_seconds; + + /* + * The postmaster is single backend, so treat it as short of + * CPU whenever either of two symptoms is observed: it has + * burned more than PM_STATS_CPU_THRESHOLD of one core over + * the elapsed time, or the check itself is running much later + * than the intended PM_STATS_CHECK_INTERVAL. + */ + pg_rusage_init(&cur_ru); + cpu_seconds = + (cur_ru.ru.ru_utime.tv_sec - pmstats_ru0.ru.ru_utime.tv_sec) + + (cur_ru.ru.ru_utime.tv_usec - pmstats_ru0.ru.ru_utime.tv_usec) / 1000000.0 + + (cur_ru.ru.ru_stime.tv_sec - pmstats_ru0.ru.ru_stime.tv_sec) + + (cur_ru.ru.ru_stime.tv_usec - pmstats_ru0.ru.ru_stime.tv_usec) / 1000000.0; + + if (log_postmaster_overloads) + { + bool cpu_overloaded; + + cpu_overloaded = (cpu_seconds > PM_STATS_CPU_THRESHOLD * elapsed || + elapsed > PM_STATS_ELAPSED_LATE_FACTOR * PM_STATS_CHECK_INTERVAL); + if (cpu_overloaded || err_delta > 0) + { + ereport(LOG, + (errmsg("postmaster potentially overloaded, stats: avg %.2f conns/sec; %.2f disconns/sec; %.2f conn errors/sec; %.2f parallel workers started/sec; %s", + conn_rate, + (double) disc_delta / elapsed, + (double) err_delta / elapsed, + (double) pqw_delta / elapsed, + pg_rusage_show(&pmstats_ru0)))); + } + } + + if (log_postmaster_excess_connections > 0 && + conn_rate > log_postmaster_excess_connections) + { + ereport(LOG, + (errmsg("postmaster excessive connections, stats: avg %.2f conns/sec; %.2f disconns/sec; %.2f conn errors/sec; %.2f parallel workers started/sec; %s", + conn_rate, + (double) disc_delta / elapsed, + (double) err_delta / elapsed, + (double) pqw_delta / elapsed, + pg_rusage_show(&pmstats_ru0)))); + } + + pmstats_reset(); + } + } } } @@ -2028,9 +2216,19 @@ process_pm_reload_request(void) if (Shutdown <= SmartShutdown) { + bool pmstats_was_enabled = pmstats_enabled(); + ereport(LOG, (errmsg("received SIGHUP, reloading configuration files"))); ProcessConfigFile(PGC_SIGHUP); + + /* + * If the postmaster stats checks were just enabled, start the first + * checks now rather than measuring since the last check (which could + * be start of the postmaster itself). + */ + if (!pmstats_was_enabled && pmstats_enabled()) + pmstats_reset(); SignalChildren(SIGHUP, btmask_all_except(B_DEAD_END_BACKEND)); /* Reload authentication config files too */ @@ -2622,6 +2820,10 @@ CleanupBackend(PMChild *bp, else procname = _(GetBackendTypeDesc(bp->bkend_type)); + /* Count external (client or walsender) backend exits for stats. */ + if (IsExternalConnectionBackend(bp->bkend_type)) + pmstats_disconnections++; + /* * If a backend dies in an ugly way then we must signal all other backends * to quickdie. If exit status is zero (normal) or one (FATAL exit), we @@ -3282,6 +3484,9 @@ PostmasterStateMachine(void) ShmemCallRequestCallbacks(); CreateSharedMemoryAndSemaphores(); + /* Start with fresh statistics */ + pmstats_reset(); + UpdatePMState(PM_STARTUP); /* Make sure we can perform I/O while starting up. */ @@ -3669,6 +3874,10 @@ BackendStartup(ClientSocket *client_sock) GetBackendTypeDesc(bn->bkend_type), (int) pid, (int) client_sock->sock))); + /* Potentiall fork() failures above are counted in parent ServerLoop() */ + if (cac != CAC_OK) + pmstats_connection_errors++; + /* * Everything's been successful, it's safe to add this backend to our list * of backends. diff --git a/src/backend/utils/misc/guc_parameters.dat b/src/backend/utils/misc/guc_parameters.dat index 1d0d73074a1..a255387a64c 100644 --- a/src/backend/utils/misc/guc_parameters.dat +++ b/src/backend/utils/misc/guc_parameters.dat @@ -1820,6 +1820,22 @@ check_hook => 'check_stage_log_stats', }, +{ name => 'log_postmaster_excess_connections', type => 'int', context => 'PGC_SIGHUP', group => 'LOGGING_WHAT', + short_desc => 'Logs postmaster stats once per second when the rate of new connections exceeds this value.', + long_desc => '0 disables this check.', + variable => 'log_postmaster_excess_connections', + boot_val => '0', + min => '0', + max => 'INT_MAX', +}, + +{ name => 'log_postmaster_overloads', type => 'bool', context => 'PGC_SIGHUP', group => 'LOGGING_WHAT', + short_desc => 'Logs postmaster stats once per second when it is short of CPU.', + long_desc => 'If the postmaster has signs of being overloaded log message summarizing its recent activity.', + variable => 'log_postmaster_overloads', + boot_val => 'false', +}, + { name => 'log_recovery_conflict_waits', type => 'bool', context => 'PGC_SIGHUP', group => 'LOGGING_WHAT', short_desc => 'Logs standby recovery conflict waits.', variable => 'log_recovery_conflict_waits', diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 01f98de8a9f..fc4b23d0a77 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -670,6 +670,11 @@ # e.g. '<%u%%%d> ' #log_lock_waits = on # log lock waits >= deadlock_timeout #log_lock_failures = off # log lock failures +#log_postmaster_overloads = off # log postmaster stats once per + # second when it is CPU-bound +#log_postmaster_excess_connections = 0 # log postmaster stats once per + # second when new connection rate + # exceeds this value; 0 disables #log_recovery_conflict_waits = off # log standby recovery conflict waits # >= deadlock_timeout #log_parameter_max_length = -1 # when logging statements, limit logged diff --git a/src/include/postmaster/bgworker_internals.h b/src/include/postmaster/bgworker_internals.h index b6261bc01df..a75eab3614c 100644 --- a/src/include/postmaster/bgworker_internals.h +++ b/src/include/postmaster/bgworker_internals.h @@ -48,6 +48,7 @@ extern void ReportBackgroundWorkerExit(RegisteredBgWorker *rw); extern void BackgroundWorkerStopNotifications(pid_t pid); extern void ForgetUnstartedBackgroundWorkers(void); extern void ResetBackgroundWorkerCrashTimes(void); +extern uint32 GetParallelWorkerRegisterCount(void); /* Entry point for background worker processes */ pg_noreturn extern void BackgroundWorkerMain(const void *startup_data, size_t startup_data_len); diff --git a/src/include/postmaster/postmaster.h b/src/include/postmaster/postmaster.h index 716b4c912b3..bac3b630e97 100644 --- a/src/include/postmaster/postmaster.h +++ b/src/include/postmaster/postmaster.h @@ -63,6 +63,8 @@ extern PGDLLIMPORT char *ListenAddresses; extern PGDLLIMPORT bool ClientAuthInProgress; extern PGDLLIMPORT int PreAuthDelay; extern PGDLLIMPORT int AuthenticationTimeout; +extern PGDLLIMPORT bool log_postmaster_overloads; +extern PGDLLIMPORT int log_postmaster_excess_connections; extern PGDLLIMPORT bool log_hostname; extern PGDLLIMPORT bool enable_bonjour; extern PGDLLIMPORT char *bonjour_name; diff --git a/src/test/postmaster/meson.build b/src/test/postmaster/meson.build index fa30883b601..7b64cb4d2f0 100644 --- a/src/test/postmaster/meson.build +++ b/src/test/postmaster/meson.build @@ -10,6 +10,7 @@ tests += { 't/002_connection_limits.pl', 't/003_start_stop.pl', 't/004_negotiate.pl', + 't/005_log_postmaster.pl', ], }, } diff --git a/src/test/postmaster/t/005_log_postmaster.pl b/src/test/postmaster/t/005_log_postmaster.pl new file mode 100644 index 00000000000..1999d2b27a2 --- /dev/null +++ b/src/test/postmaster/t/005_log_postmaster.pl @@ -0,0 +1,89 @@ +# Copyright (c) 2026, PostgreSQL Global Development Group + +# Verify that log_postmaster_overloads does not spam the log with +# "postmaster potentially overloaded, stats:" log lines while the postmaster +# is idle. It is only supposed to log once the postmaster is nearly at +# the edge of single CPU core capacity. Also test +# log_postmaster_excess_connections as it is very similiar. + +use strict; +use warnings FATAL => 'all'; +use PostgreSQL::Test::Cluster; +use PostgreSQL::Test::Utils; +use Test::More; + +# Best-effort detection of the number of CPUs available +sub get_cpus_num +{ + my $ncpus; + + if ($windows_os) + { + $ncpus = $ENV{NUMBER_OF_PROCESSORS}; + } + else + { + $ncpus = `nproc 2>/dev/null`; + chomp $ncpus if defined $ncpus; + if (!defined($ncpus) || $ncpus !~ /^\d+$/) + { + $ncpus = `sysctl -n hw.ncpu 2>/dev/null`; + chomp $ncpus if defined $ncpus; + } + } + + return $ncpus if defined($ncpus) && $ncpus =~ /^\d+$/ && $ncpus > 0; + # Return there is 16 VCPUs as fallback, so that we can that we can + # hopefully overloaded postmaster, but we don't really know, so + # hopefully that's enough. + return 16; +} + +my $clients = get_cpus_num() * 2; +note("using $clients pgbench clients"); + +my $node = PostgreSQL::Test::Cluster->new('primary'); +$node->init; +$node->append_conf( + 'postgresql.conf', qq( +log_postmaster_overloads = on +log_postmaster_excess_connections = 2 +log_connections = off +log_statement = ddl +max_connections = ) . ($clients + 10)); +$node->start; + +# Save current offset (size) of the logfile +my $offset = -s $node->logfile; +my $stats_re = qr/postmaster potentially overloaded/; + +# Give the postmaster some time to have a chance to (wrongly) +# emit the stats line, then check it did not log anything. +$node->safe_psql('postgres', 'SELECT 1'); +sleep 2; +ok( !$node->log_contains($stats_re, $offset), + 'postmaster stats line not emitted while postmaster is not short of CPU' +); + +# Flood the postmaster for 2 seconds and check if the warning got emitted +# This fails on CI and probably buildfram due to not enough VCPUs to saturate +# postmaster, so it is commented out. +#$node->pgbench('--initialize --quiet --scale=1', 0, [], [], +# 'set up pgbench_accounts table'); +#$node->pgbench("--connect -c$clients -j$clients -T 2 -S -n", 0, [], [], +# 'pgbench --connect run to put stress on the postmaster'); +#$node->wait_for_log($stats_re, $offset); +#pass('postmaster stats line emitted while postmaster is short of CPU'); + + +# Try out the log_postmaster_excessive_connections +$node->pgbench('--initialize --quiet --scale=1', 0, [], [], + 'set up pgbench_accounts table'); +$node->pgbench("--connect -c$clients -j$clients -T 2 -S -n", 0, [], [], + 'pgbench --connect run to put stress on the postmaster'); +$stats_re = qr/postmaster excessive connections/; +$node->wait_for_log($stats_re, $offset); +pass('postmaster stats line emitted while postmaster is short of CPU'); + +$node->stop; +done_testing(); -- 2.43.0
