On 20 December 2017 at 08:46, Craig Ringer <cr...@2ndquadrant.com> wrote:
> On 20 December 2017 at 02:35, Andres Freund <and...@anarazel.de> wrote: > > >> > Yeah. But please don't mess with MemoryContextStats per se --- >> > I dunno about you guys but "call MemoryContextStats(TopMemoryContext)" >> > is kinda wired into my gdb reflexes. I think what'd make sense >> > is a new function "MemoryContextStatsTo(context, function_pointer)". >> > It's okay to redefine the APIs of the per-context-type functions >> > these would call, though, because nobody calls those functions directly. >> >> We already have MemoryContextStatsDetail() - it seems to make sense to >> expand that API and leave MemoryContextStats() alone. I don't think >> there's a need for a third variant? >> > > Cool, can do. > > I'll have to expose a typedef for the printf-wrapper callback in > memnodes.h and add it to the stats method, which I thought would be more > likely to get complaints than the global hook. I'm actually happier to do > it with a passed callback. > > Will revise when I get a chance in the next couple of days. > Done. It uses vfprintf unconditionally, even on Windows where we'd usually use write_stderr, so it doesn't change the current MemoryContextStats behaviour. 2017-12-21 14:39:20.045 AWST [10588] pg_regress/misc_functions LOG: diagnostic dump requested; memory context info: TopMemoryContext: 67440 total in 5 blocks; 13376 free (6 chunks); 54064 used pgstat TabStatusArray lookup hash table: 8192 total in 1 blocks; 1376 free (0 chunks); 6816 used TopTransactionContext: 8192 total in 1 blocks; 7728 free (1 chunks); 464 used ... To verify that stderr output still works properly I ran: SELECT repeat('spamspamspam', 20000000), repeat('spamspamspam', 20000000), repeat('spamspamspam', 20000000), repeat('spamspamspam', 20000000), ... lots ...; and got the expected +ERROR: out of memory +DETAIL: Failed on request of size 240000004. and memory context dump to stderr. I didn't add a TAP test for that because I'd rather avoid exercising OOM in tests where we don't know what the host's swap config is like, how its ulimit behaves, whether it has craziness like the OOM killer, etc. But it might make sense to add a TAP test to set a low ulimit and exercise OOM recovery at some point. I've added a separate vfprintf wrapper for memory context use that doesn't try to use the windows error log like write_stderr(...) does. If we want to change OOM behaviour on Windows it can be done in a followup. -- Craig Ringer http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Training & Services
From db5caa16cd3c78544f7a6e336c3d8b9118f7cdaf Mon Sep 17 00:00:00 2001 From: Craig Ringer <cr...@2ndquadrant.com> Date: Tue, 19 Dec 2017 20:47:36 +0800 Subject: [PATCH v2] Add pg_diag_backend to print memory context info The new pg_diag_backend(pid) function signals a backend to dump a summary of its memory context state when it next calls CHECK_FOR_INTERRUPTS(). The memory context information is output to the server log. This works on any backend that uses the standard procsignal_sigusr1_handler or explicitly handles PROCSIG_DIAG_REQUEST in its own handler. Currently this includes normal user backends, the walsender and autovacuum workers but not the other system processes. Background workers must handle it explicitly handle SIGUSR1 with procsignal_sigusr1_handler. --- doc/src/sgml/bgworker.sgml | 10 ++++- doc/src/sgml/func.sgml | 13 ++++++ src/backend/storage/ipc/procsignal.c | 3 ++ src/backend/tcop/postgres.c | 66 ++++++++++++++++++++++++++++ src/backend/utils/adt/misc.c | 16 +++++++ src/backend/utils/init/globals.c | 1 + src/backend/utils/mmgr/aset.c | 10 +++-- src/backend/utils/mmgr/mcxt.c | 50 ++++++++++++++++----- src/include/catalog/pg_proc.h | 2 + src/include/miscadmin.h | 4 ++ src/include/nodes/memnodes.h | 10 ++++- src/include/storage/procsignal.h | 5 ++- src/include/utils/memutils.h | 4 +- src/test/regress/expected/misc_functions.out | 12 +++++ src/test/regress/sql/misc_functions.sql | 9 ++++ 15 files changed, 194 insertions(+), 21 deletions(-) diff --git a/doc/src/sgml/bgworker.sgml b/doc/src/sgml/bgworker.sgml index 4bc2b69..50bb54f 100644 --- a/doc/src/sgml/bgworker.sgml +++ b/doc/src/sgml/bgworker.sgml @@ -185,7 +185,8 @@ typedef struct BackgroundWorker when the process is started or exits. It should be 0 for workers registered at postmaster startup time, or when the backend registering the worker does not wish to wait for the worker to start up. Otherwise, it should be - initialized to <literal>MyProcPid</literal>. + initialized to <literal>MyProcPid</literal>. Typically this sets the + receiving process's latch via its signal handler. </para> <para>Once running, the process can connect to a database by calling @@ -208,7 +209,12 @@ typedef struct BackgroundWorker allow the process to customize its signal handlers, if necessary. Signals can be unblocked in the new process by calling <function>BackgroundWorkerUnblockSignals</function> and blocked by calling - <function>BackgroundWorkerBlockSignals</function>. + <function>BackgroundWorkerBlockSignals</function>. The default + <literal>SIGUSR1</literal> handler for background workers just + sets the process latch. Background workers may instead adopt + the <function>procsignal_sigusr1_handler</function> used by + normal backends and call <function>CHECK_FOR_INTERRUPTS()</function> + in their main loops. </para> <para> diff --git a/doc/src/sgml/func.sgml b/doc/src/sgml/func.sgml index 4dd9d02..be5ed54 100644 --- a/doc/src/sgml/func.sgml +++ b/doc/src/sgml/func.sgml @@ -18348,6 +18348,9 @@ SELECT set_config('log_statement_stats', 'off', false); <indexterm> <primary>pg_terminate_backend</primary> </indexterm> + <indexterm> + <primary>pg_diag_backend</primary> + </indexterm> <indexterm> <primary>signal</primary> @@ -18407,6 +18410,16 @@ SELECT set_config('log_statement_stats', 'off', false); however only superusers can terminate superuser backends. </entry> </row> + <row> + <entry> + <literal><function>pg_diag_backend(<parameter>pid</parameter> <type>int</type>)</function></literal> + </entry> + <entry><type>boolean</type></entry> + <entry>Ask a backend to report diagnostics including memory use details + to the server log. Restricted to superusers. The log entry begins + with <literal>diagnostic dump</literal> or the localized equivalent. + </entry> + </row> </tbody> </tgroup> </table> diff --git a/src/backend/storage/ipc/procsignal.c b/src/backend/storage/ipc/procsignal.c index b9302ac..450e4f1 100644 --- a/src/backend/storage/ipc/procsignal.c +++ b/src/backend/storage/ipc/procsignal.c @@ -292,6 +292,9 @@ procsignal_sigusr1_handler(SIGNAL_ARGS) if (CheckProcSignal(PROCSIG_RECOVERY_CONFLICT_BUFFERPIN)) RecoveryConflictInterrupt(PROCSIG_RECOVERY_CONFLICT_BUFFERPIN); + if (CheckProcSignal(PROCSIG_DIAG_REQUEST)) + HandleDiagRequestInterrupt(PROCSIG_DIAG_REQUEST); + SetLatch(MyLatch); latch_sigusr1_handler(); diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 1ae9ac2..b7a8d4d 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -193,6 +193,9 @@ static void drop_unnamed_stmt(void); static void log_disconnections(int code, Datum arg); static void enable_statement_timeout(void); static void disable_statement_timeout(void); +static void HandleDiagRequest(void); +static void printwrapper_stringinfo(void *extra, const char *fmt, ...) + pg_attribute_printf(2, 3); /* ---------------------------------------------------------------- @@ -3047,8 +3050,71 @@ ProcessInterrupts(void) if (ParallelMessagePending) HandleParallelMessages(); + + if (DiagRequestPending) + HandleDiagRequest(); +} + +/* + * Accumulate writes into the buffer in diag_request_buf, + * for use with functions that expect a printf-like callback. + */ +static void +printwrapper_stringinfo(void *extra, const char * fmt, ...) +{ + StringInfo out = extra; + for (;;) + { + va_list args; + int needed; + va_start(args, fmt); + needed = appendStringInfoVA(out, fmt, args); + va_end(args); + if (needed == 0) + break; + enlargeStringInfo(out, needed); + } } +/* + * The interrupt-handler side of handling a diagnostic request + * interrupt. This just saves the request for handling during + * CHECK_FOR_INTERRUPTS(). Any prior request that isn't yet actioned is + * clobbered. + */ +void +HandleDiagRequestInterrupt(ProcSignalReason request) +{ + DiagRequestPending = request; + InterruptPending = true; +} + +/* + * Dump memory context information to the logs in response to a + * PROCSIG_DIAG_REQUEST sent via pg_diag_backend or similar. + * + * Usually invoked via procsignal_sigusr1_handler and + * CHECK_FOR_INTERRUPTS(), so this won't work by default + * for background workers and other nonstandard processes. + */ +static void +HandleDiagRequest(void) +{ + ProcSignalReason DiagRequest = DiagRequestPending; + DiagRequestPending = 0; + + /* So far we only have a generic diagnostics dump */ + if (DiagRequest == PROCSIG_DIAG_REQUEST) + { + StringInfoData outbuf; + initStringInfo(&outbuf); + MemoryContextStatsDetail(TopMemoryContext, 100, + printwrapper_stringinfo, (void*)&outbuf); + elog(LOG, "diagnostic dump requested; memory context info: %s", + outbuf.data); + pfree(outbuf.data); + } +} /* * IA64-specific code to fetch the AR.BSP register for stack depth checks. diff --git a/src/backend/utils/adt/misc.c b/src/backend/utils/adt/misc.c index f53d411..ac0c29f 100644 --- a/src/backend/utils/adt/misc.c +++ b/src/backend/utils/adt/misc.c @@ -321,6 +321,22 @@ pg_terminate_backend(PG_FUNCTION_ARGS) PG_RETURN_BOOL(r == SIGNAL_BACKEND_SUCCESS); } +Datum +pg_diag_backend(PG_FUNCTION_ARGS) +{ + int pid = PG_GETARG_INT32(0); + int r; + + if (!superuser()) + ereport(ERROR, + (errcode(ERRCODE_INSUFFICIENT_PRIVILEGE), + errmsg("pg_diag_backend requires superuser privileges"))); + + r = SendProcSignal(pid, PROCSIG_DIAG_REQUEST, InvalidBackendId); + + PG_RETURN_BOOL(r == 0); +} + /* * Signal to reload the database configuration * diff --git a/src/backend/utils/init/globals.c b/src/backend/utils/init/globals.c index 9680a4b..f3e4a4d 100644 --- a/src/backend/utils/init/globals.c +++ b/src/backend/utils/init/globals.c @@ -29,6 +29,7 @@ ProtocolVersion FrontendProtocol; volatile bool InterruptPending = false; volatile bool QueryCancelPending = false; volatile bool ProcDiePending = false; +volatile int DiagRequestPending = false; volatile bool ClientConnectionLost = false; volatile bool IdleInTransactionSessionTimeoutPending = false; volatile sig_atomic_t ConfigReloadPending = false; diff --git a/src/backend/utils/mmgr/aset.c b/src/backend/utils/mmgr/aset.c index 1519da0..547b695 100644 --- a/src/backend/utils/mmgr/aset.c +++ b/src/backend/utils/mmgr/aset.c @@ -277,7 +277,8 @@ static void AllocSetDelete(MemoryContext context); static Size AllocSetGetChunkSpace(MemoryContext context, void *pointer); static bool AllocSetIsEmpty(MemoryContext context); static void AllocSetStats(MemoryContext context, int level, bool print, - MemoryContextCounters *totals); + MemoryContextCounters *totals, printf_wrapper outfunc, + void *outfunc_extra); #ifdef MEMORY_CONTEXT_CHECKING static void AllocSetCheck(MemoryContext context); @@ -1333,7 +1334,8 @@ AllocSetIsEmpty(MemoryContext context) */ static void AllocSetStats(MemoryContext context, int level, bool print, - MemoryContextCounters *totals) + MemoryContextCounters *totals, printf_wrapper outfunc, + void *outfunc_extra) { AllocSet set = (AllocSet) context; Size nblocks = 0; @@ -1369,8 +1371,8 @@ AllocSetStats(MemoryContext context, int level, bool print, int i; for (i = 0; i < level; i++) - fprintf(stderr, " "); - fprintf(stderr, + outfunc(outfunc_extra, " "); + outfunc(outfunc_extra, "%s: %zu total in %zd blocks; %zu free (%zd chunks); %zu used\n", set->header.name, totalspace, nblocks, freespace, freechunks, totalspace - freespace); diff --git a/src/backend/utils/mmgr/mcxt.c b/src/backend/utils/mmgr/mcxt.c index 97382a6..c108d87 100644 --- a/src/backend/utils/mmgr/mcxt.c +++ b/src/backend/utils/mmgr/mcxt.c @@ -54,7 +54,11 @@ MemoryContext PortalContext = NULL; static void MemoryContextCallResetCallbacks(MemoryContext context); static void MemoryContextStatsInternal(MemoryContext context, int level, bool print, int max_children, - MemoryContextCounters *totals); + MemoryContextCounters *totals, + printf_wrapper outfunc, void *outfunc_args); + +static void fprintf_stderr_wrapper(void *args, const char *fmt, ...) + pg_attribute_printf(2, 3); /* * You should not do memory allocations within a critical section, because @@ -426,6 +430,24 @@ MemoryContextIsEmpty(MemoryContext context) } /* + * MemoryContextStats doesn't want to try to write to elog(...) + * as it could be called under severe memory pressure. So we + * write straight to stderr. + * + * This duplicates write_stderr(...) without the Windows + * event log support. + */ +static void +fprintf_stderr_wrapper(void *args, const char *fmt, ...) +{ + va_list ap; + va_start(ap, fmt); + vfprintf(stderr, fmt, ap); + va_end(ap); + fflush(stderr); +} + +/* * MemoryContextStats * Print statistics about the named context and all its descendants. * @@ -437,7 +459,7 @@ void MemoryContextStats(MemoryContext context) { /* A hard-wired limit on the number of children is usually good enough */ - MemoryContextStatsDetail(context, 100); + MemoryContextStatsDetail(context, 100, fprintf_stderr_wrapper, NULL); } /* @@ -446,15 +468,17 @@ MemoryContextStats(MemoryContext context) * Entry point for use if you want to vary the number of child contexts shown. */ void -MemoryContextStatsDetail(MemoryContext context, int max_children) +MemoryContextStatsDetail(MemoryContext context, int max_children, + printf_wrapper outfunc, void *outfunc_extra) { MemoryContextCounters grand_totals; memset(&grand_totals, 0, sizeof(grand_totals)); - MemoryContextStatsInternal(context, 0, true, max_children, &grand_totals); + MemoryContextStatsInternal(context, 0, true, max_children, &grand_totals, + outfunc, outfunc_extra); - fprintf(stderr, + outfunc(outfunc_extra, "Grand total: %zu bytes in %zd blocks; %zu free (%zd chunks); %zu used\n", grand_totals.totalspace, grand_totals.nblocks, grand_totals.freespace, grand_totals.freechunks, @@ -471,7 +495,8 @@ MemoryContextStatsDetail(MemoryContext context, int max_children) static void MemoryContextStatsInternal(MemoryContext context, int level, bool print, int max_children, - MemoryContextCounters *totals) + MemoryContextCounters *totals, + printf_wrapper outfunc, void *outfunc_extra) { MemoryContextCounters local_totals; MemoryContext child; @@ -480,7 +505,8 @@ MemoryContextStatsInternal(MemoryContext context, int level, AssertArg(MemoryContextIsValid(context)); /* Examine the context itself */ - context->methods->stats(context, level, print, totals); + context->methods->stats(context, level, print, totals, + outfunc, outfunc_extra); /* * Examine children. If there are more than max_children of them, we do @@ -495,11 +521,13 @@ MemoryContextStatsInternal(MemoryContext context, int level, if (ichild < max_children) MemoryContextStatsInternal(child, level + 1, print, max_children, - totals); + totals, + outfunc, outfunc_extra); else MemoryContextStatsInternal(child, level + 1, false, max_children, - &local_totals); + &local_totals, + outfunc, outfunc_extra); } /* Deal with excess children */ @@ -510,8 +538,8 @@ MemoryContextStatsInternal(MemoryContext context, int level, int i; for (i = 0; i <= level; i++) - fprintf(stderr, " "); - fprintf(stderr, + outfunc(outfunc_extra, " "); + outfunc(outfunc_extra, "%d more child contexts containing %zu total in %zd blocks; %zu free (%zd chunks); %zu used\n", ichild - max_children, local_totals.totalspace, diff --git a/src/include/catalog/pg_proc.h b/src/include/catalog/pg_proc.h index c969375..2f8fb7b 100644 --- a/src/include/catalog/pg_proc.h +++ b/src/include/catalog/pg_proc.h @@ -3256,6 +3256,8 @@ DATA(insert OID = 2171 ( pg_cancel_backend PGNSP PGUID 12 1 0 0 0 f f f f t f v DESCR("cancel a server process' current query"); DATA(insert OID = 2096 ( pg_terminate_backend PGNSP PGUID 12 1 0 0 0 f f f f t f v s 1 0 16 "23" _null_ _null_ _null_ _null_ _null_ pg_terminate_backend _null_ _null_ _null_ )); DESCR("terminate a server process"); +DATA(insert OID = 3556 ( pg_diag_backend PGNSP PGUID 12 1 0 0 0 f f f f t f v s 1 0 16 "23" _null_ _null_ _null_ _null_ _null_ pg_diag_backend _null_ _null_ _null_ )); +DESCR("signal a server process to dump diagnostics to the log"); DATA(insert OID = 2172 ( pg_start_backup PGNSP PGUID 12 1 0 0 0 f f f f t f v r 3 0 3220 "25 16 16" _null_ _null_ _null_ _null_ _null_ pg_start_backup _null_ _null_ _null_ )); DESCR("prepare for taking an online backup"); DATA(insert OID = 2173 ( pg_stop_backup PGNSP PGUID 12 1 0 0 0 f f f f t f v r 0 0 3220 "" _null_ _null_ _null_ _null_ _null_ pg_stop_backup _null_ _null_ _null_ )); diff --git a/src/include/miscadmin.h b/src/include/miscadmin.h index 59da7a6..9b17173 100644 --- a/src/include/miscadmin.h +++ b/src/include/miscadmin.h @@ -80,6 +80,7 @@ extern PGDLLIMPORT volatile bool InterruptPending; extern PGDLLIMPORT volatile bool QueryCancelPending; extern PGDLLIMPORT volatile bool ProcDiePending; +extern PGDLLIMPORT volatile int DiagRequestPending; extern PGDLLIMPORT volatile bool IdleInTransactionSessionTimeoutPending; extern PGDLLIMPORT volatile sig_atomic_t ConfigReloadPending; @@ -275,6 +276,9 @@ extern bool stack_is_too_deep(void); extern void PostgresSigHupHandler(SIGNAL_ARGS); +enum ProcSignalReason; +extern void HandleDiagRequestInterrupt(enum ProcSignalReason request); + /* in tcop/utility.c */ extern void PreventCommandIfReadOnly(const char *cmdname); extern void PreventCommandIfParallelMode(const char *cmdname); diff --git a/src/include/nodes/memnodes.h b/src/include/nodes/memnodes.h index c7eb1e7..86d022c 100644 --- a/src/include/nodes/memnodes.h +++ b/src/include/nodes/memnodes.h @@ -35,6 +35,13 @@ typedef struct MemoryContextCounters } MemoryContextCounters; /* + * MemoryContextStats can't use elog(...) during OOM so we need + * to be able to route its output to different destinations. + */ +typedef void (*printf_wrapper)(void *extra, const char *fmt, ...) + pg_attribute_printf(2, 3); + +/* * MemoryContext * A logical context in which memory allocations occur. * @@ -62,7 +69,8 @@ typedef struct MemoryContextMethods Size (*get_chunk_space) (MemoryContext context, void *pointer); bool (*is_empty) (MemoryContext context); void (*stats) (MemoryContext context, int level, bool print, - MemoryContextCounters *totals); + MemoryContextCounters *totals, + printf_wrapper outfunc, void *outfunc_extra); #ifdef MEMORY_CONTEXT_CHECKING void (*check) (MemoryContext context); #endif diff --git a/src/include/storage/procsignal.h b/src/include/storage/procsignal.h index 20bb05b..121fb86 100644 --- a/src/include/storage/procsignal.h +++ b/src/include/storage/procsignal.h @@ -27,7 +27,7 @@ * Also, because of race conditions, it's important that all the signals be * defined so that no harm is done if a process mistakenly receives one. */ -typedef enum +typedef enum ProcSignalReason { PROCSIG_CATCHUP_INTERRUPT, /* sinval catchup interrupt */ PROCSIG_NOTIFY_INTERRUPT, /* listen/notify interrupt */ @@ -42,6 +42,9 @@ typedef enum PROCSIG_RECOVERY_CONFLICT_BUFFERPIN, PROCSIG_RECOVERY_CONFLICT_STARTUP_DEADLOCK, + /* Signals used to ask the backend for diagnostic output */ + PROCSIG_DIAG_REQUEST, /* Dump memory context info etc */ + NUM_PROCSIGNALS /* Must be last! */ } ProcSignalReason; diff --git a/src/include/utils/memutils.h b/src/include/utils/memutils.h index 9c30eb7..1b08f4e 100644 --- a/src/include/utils/memutils.h +++ b/src/include/utils/memutils.h @@ -45,7 +45,6 @@ #define AllocHugeSizeIsValid(size) ((Size) (size) <= MaxAllocHugeSize) - /* * Standard top-level memory contexts. * @@ -82,7 +81,8 @@ extern Size GetMemoryChunkSpace(void *pointer); extern MemoryContext MemoryContextGetParent(MemoryContext context); extern bool MemoryContextIsEmpty(MemoryContext context); extern void MemoryContextStats(MemoryContext context); -extern void MemoryContextStatsDetail(MemoryContext context, int max_children); +extern void MemoryContextStatsDetail(MemoryContext context, int max_children, + printf_wrapper outfunc, void *outfunc_extra); extern void MemoryContextAllowInCriticalSection(MemoryContext context, bool allow); diff --git a/src/test/regress/expected/misc_functions.out b/src/test/regress/expected/misc_functions.out index 130a0e4..9ce99c6 100644 --- a/src/test/regress/expected/misc_functions.out +++ b/src/test/regress/expected/misc_functions.out @@ -1,4 +1,16 @@ -- +-- Misc admin functions +-- +-- pg_diag_backend makes the backend log, so it can't really +-- be tested within pg_regress except to ensure it doesn't +-- upset the backend. +SELECT pg_diag_backend(pg_backend_pid()); + pg_diag_backend +----------------- + t +(1 row) + +-- -- num_nulls() -- SELECT num_nonnulls(NULL); diff --git a/src/test/regress/sql/misc_functions.sql b/src/test/regress/sql/misc_functions.sql index 1a20c1f..fb64b87 100644 --- a/src/test/regress/sql/misc_functions.sql +++ b/src/test/regress/sql/misc_functions.sql @@ -1,4 +1,13 @@ -- +-- Misc admin functions +-- + +-- pg_diag_backend makes the backend log, so it can't really +-- be tested within pg_regress except to ensure it doesn't +-- upset the backend. +SELECT pg_diag_backend(pg_backend_pid()); + +-- -- num_nulls() -- -- 2.9.5