On Tue, Feb 6, 2024 at 4:21 PM Michael Paquier <mich...@paquier.xyz> wrote: > > --- a/src/backend/storage/ipc/procarray.c > +++ b/src/backend/storage/ipc/procarray.c > +bool > +SendProcSignalBackendOrAuxproc(int pid, ProcSignalReason reason) > +{ > > Looking at 0001. This API is a thin wrapper of SendProcSignal(), that > just checks that we have actually a process before using it. > Shouldn't it be in procsignal.c. > > Now looking at 0002, this new routine is used in one place. Seeing > that we have something similar in pgstatfuncs.c, wouldn't it be > better, instead of englobing SendProcSignal(), to have one routine > that's able to return a PID for a PostgreSQL process?
I liked the idea of going ahead with logging backtraces for only backends for now, so a separate wrapper like this isn't needed. > All the backtrace-related handling is stored in procsignal.c, could it > be cleaner to move the internals into a separate, new file, like > procbacktrace.c or something similar? +1. Moved all the code to a new file. > LoadBacktraceFunctions() is one more thing we need to set up in all > auxiliary processes. That's a bit sad to require that in all these > places, and we may forget to add it. Could we put more efforts in > centralizing these initializations? If we were to do it for only backends (including bg workers) InitProcess() is the better place. If we were to do it for both backends and auxiliary processes, BaseInit() is best. > The auxiliary processes are one > portion of the problem, and getting stack traces for backend processes > would be useful on its own. Another suggestion that I'd propose to > simplify the patch would be to focus solely on backends for now, and > do something for auxiliary process later on. If you do that, the > strange layer with BackendOrAuxproc() is not a problem anymore, as it > would be left out for now. +1 to keep it simple for now; that is, log backtraces of only backends leaving auxiliary processes aside. > +<screen> > +logging current backtrace of process with PID 3499242: > +postgres: ubuntu postgres [local] INSERT(+0x61a355)[0x5559b94de355] > +postgres: ubuntu postgres [local] > INSERT(procsignal_sigusr1_handler+0x9e)[0x5559b94de4ef] > > This is IMO too much details for the documentation, and could be > confusing depending on how the code evolves in the future. I'd > suggest to keep it minimal, cutting that to a few lines. I don't see > a need to mention ubuntu, either. Well, that 'ubuntu' is the default username there, I've changed it now and kept the output short. I've simplified the tests, now we don't need two separate output files for tests. Please see the attached v27 patch. -- Bharath Rupireddy PostgreSQL Contributors Team RDS Open Source Databases Amazon Web Services: https://aws.amazon.com
From e44351d85f6415c0649c18e00dc92368be0bc1d6 Mon Sep 17 00:00:00 2001 From: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com> Date: Wed, 7 Feb 2024 07:46:05 +0000 Subject: [PATCH v27] Add function to log backtrace of a backend --- doc/src/sgml/func.sgml | 53 +++++++ src/backend/catalog/system_functions.sql | 2 + src/backend/storage/ipc/Makefile | 1 + src/backend/storage/ipc/meson.build | 1 + src/backend/storage/ipc/procbacktrace.c | 143 +++++++++++++++++++ src/backend/storage/ipc/procsignal.c | 4 + src/backend/storage/lmgr/proc.c | 3 + src/include/catalog/pg_proc.dat | 4 + src/include/storage/procbacktrace.h | 20 +++ src/include/storage/procsignal.h | 1 + src/test/regress/expected/misc_functions.out | 51 +++++++ src/test/regress/sql/misc_functions.sql | 41 ++++++ 12 files changed, 324 insertions(+) create mode 100644 src/backend/storage/ipc/procbacktrace.c create mode 100644 src/include/storage/procbacktrace.h diff --git a/doc/src/sgml/func.sgml b/doc/src/sgml/func.sgml index 6788ba8ef4..4d5a31b113 100644 --- a/doc/src/sgml/func.sgml +++ b/doc/src/sgml/func.sgml @@ -27186,6 +27186,24 @@ SELECT collation for ('foo' COLLATE "de_DE"); </para></entry> </row> + <row> + <entry role="func_table_entry"><para role="func_signature"> + <indexterm> + <primary>pg_log_backtrace</primary> + </indexterm> + <function>pg_log_backtrace</function> ( <parameter>pid</parameter> <type>integer</type> ) + <returnvalue>boolean</returnvalue> + </para> + <para> + Requests to log the backtrace of a backend with the specified process + ID. The backtraces will be logged to <systemitem>stderr</systemitem>. + Typically, a backtrace identifies which function a process is currently + executing, and is useful for developers to diagnose stuck processes. + This function is supported only if PostgreSQL was built with the ability + to capture backtraces, otherwise it will emit a warning. + </para></entry> + </row> + <row> <entry role="func_table_entry"><para role="func_signature"> <indexterm> @@ -27300,6 +27318,41 @@ LOG: Grand total: 1651920 bytes in 201 blocks; 622360 free (88 chunks); 1029560 because it may generate a large number of log messages. </para> + <para> + <function>pg_log_backtrace</function> can be used to log the backtrace of + a backend process. For example: +<programlisting> +postgres=# select pg_log_backtrace(pg_backend_pid()); + pg_log_backtrace +------------------ + t +(1 row) +</programlisting> +The backtrace will be logged as specified by the logging configuration. +For example: +<screen> +logging current backtrace of process with PID 174542: +postgres: myuser mydb [local] ALTER TABLE(HandleLogBacktraceInterrupt+0x3c)[0x55fb151249ce] +postgres: myuser postgres [local] ALTER TABLE(procsignal_sigusr1_handler+0x9e)[0x55fb15125cbc] +/lib/x86_64-linux-gnu/libc.so.6(+0x42520)[0x7fd572842520] +/lib/x86_64-linux-gnu/libc.so.6(fsync+0x17)[0x7fd57291b887] +postgres: myuser mydb [local] ALTER TABLE(pg_fsync_no_writethrough+0x2f)[0x55fb1510d18b] +postgres: myuser mydb [local] ALTER TABLE(pg_fsync+0xe0)[0x55fb1510d146] +postgres: myuser mydb [local] ALTER TABLE(FileSync+0xb2)[0x55fb1510fad6] +postgres: myuser mydb [local] ALTER TABLE(mdimmedsync+0x9e)[0x55fb1515040a] +postgres: myuser mydb [local] ALTER TABLE(smgrimmedsync+0x2b)[0x55fb1515218d] +postgres: myuser mydb [local] ALTER TABLE(+0x183d09)[0x55fb14c4ed09] +postgres: myuser mydb [local] ALTER TABLE(+0x18243a)[0x55fb14c4d43a] +postgres: myuser mydb [local] ALTER TABLE(btbuild+0x112)[0x55fb14c4ce69] +postgres: myuser mydb [local] ALTER TABLE(index_build+0x331)[0x55fb14cef750] +postgres: myuser mydb [local] ALTER TABLE(index_create+0x1212)[0x55fb14cec1ea] +postgres: myuser mydb [local] ALTER TABLE(DefineIndex+0x1a73)[0x55fb14df8f7e] +... +</screen> + One can obtain the file name and line number from the logged details by + using <productname>GDB</productname> or + <productname>addr2line</productname> in most Linux systems. + </para> </sect2> <sect2 id="functions-admin-backup"> diff --git a/src/backend/catalog/system_functions.sql b/src/backend/catalog/system_functions.sql index 346cfb98a0..3d8ea385fb 100644 --- a/src/backend/catalog/system_functions.sql +++ b/src/backend/catalog/system_functions.sql @@ -757,6 +757,8 @@ REVOKE EXECUTE ON FUNCTION pg_ls_logicalmapdir() FROM PUBLIC; REVOKE EXECUTE ON FUNCTION pg_ls_replslotdir(text) FROM PUBLIC; +REVOKE EXECUTE ON FUNCTION pg_log_backtrace(integer) FROM PUBLIC; + -- -- We also set up some things as accessible to standard roles. -- diff --git a/src/backend/storage/ipc/Makefile b/src/backend/storage/ipc/Makefile index d8a1653eb6..4647916ea6 100644 --- a/src/backend/storage/ipc/Makefile +++ b/src/backend/storage/ipc/Makefile @@ -18,6 +18,7 @@ OBJS = \ latch.o \ pmsignal.o \ procarray.o \ + procbacktrace.o \ procsignal.o \ shm_mq.o \ shm_toc.o \ diff --git a/src/backend/storage/ipc/meson.build b/src/backend/storage/ipc/meson.build index 5a936171f7..7b38cdd3f0 100644 --- a/src/backend/storage/ipc/meson.build +++ b/src/backend/storage/ipc/meson.build @@ -10,6 +10,7 @@ backend_sources += files( 'latch.c', 'pmsignal.c', 'procarray.c', + 'procbacktrace.c', 'procsignal.c', 'shm_mq.c', 'shm_toc.c', diff --git a/src/backend/storage/ipc/procbacktrace.c b/src/backend/storage/ipc/procbacktrace.c new file mode 100644 index 0000000000..ffb93756c9 --- /dev/null +++ b/src/backend/storage/ipc/procbacktrace.c @@ -0,0 +1,143 @@ +/*------------------------------------------------------------------------- + * + * procbacktrace.c + * Backtrace-related routines + * + * Portions Copyright (c) 1996-2024, PostgreSQL Global Development Group + * Portions Copyright (c) 1994, Regents of the University of California + * + * IDENTIFICATION + * src/backend/storage/ipc/procbacktrace.c + * + *------------------------------------------------------------------------- + */ + +#include "postgres.h" + +#ifdef HAVE_EXECINFO_H +#include <execinfo.h> +#endif + +#include "funcapi.h" +#include "miscadmin.h" +#include "storage/proc.h" +#include "storage/procarray.h" +#include "storage/procbacktrace.h" +#include "storage/procsignal.h" +#include "utils/fmgrprotos.h" + +static volatile sig_atomic_t backtrace_functions_loaded = false; + +/* + * Handle receipt of an interrupt indicating logging of current backtrace. + * + * We capture the backtrace within this signal handler itself in a safe manner. + * It is ensured that no memory allocations happen here. This function emits + * backtrace to stderr as writing to server log allocates memory, making the + * signal halder unsafe. Also, the shared library implementing the + * backtrace-related functions is preloaded to avoid memory allocations upon + * first-time loading, see LoadBacktraceFunctions. + */ +void +HandleLogBacktraceInterrupt(void) +{ + void *buf[100]; + int nframes; + +#ifndef HAVE_BACKTRACE_SYMBOLS + return; +#endif + + if (!backtrace_functions_loaded) + return; + + nframes = backtrace(buf, lengthof(buf)); + + write_stderr("logging current backtrace of process with PID %d:\n", + MyProcPid); + backtrace_symbols_fd(buf, nframes, fileno(stderr)); +} + +/* + * Load backtrace shared library. + * + * Any backtrace-related functions when called for the first time dynamically + * loads the shared library, which usually triggers a call to malloc, making + * them unsafe to use in signal handlers. This function makes backtrace-related + * functions signal-safe. + * + * Note that this function is supposed to be called in the early life of a + * process, preferably after signal handlers are setup; but not from within a + * signal handler. + */ +void +LoadBacktraceFunctions(void) +{ + void *buf[2]; + +#ifndef HAVE_BACKTRACE_SYMBOLS + return; +#endif + + if (backtrace_functions_loaded) + return; + + /* + * It is enough to call any one backtrace-related function to ensure that + * the corresponding shared library is dynamically loaded. We just load + * two most recent function calls, as we don't use the backtrace anyway. + */ + backtrace(buf, lengthof(buf)); + + backtrace_functions_loaded = true; +} + +/* + * Signal a backend to log its current backtrace. + */ +Datum +pg_log_backtrace(PG_FUNCTION_ARGS) +{ + int pid = PG_GETARG_INT32(0); + PGPROC *proc; + +#ifndef HAVE_BACKTRACE_SYMBOLS + ereport(WARNING, + errmsg("backtrace generation is not supported by this installation"), + errhint("You need to rebuild PostgreSQL using a library containing backtrace_symbols.")); + PG_RETURN_BOOL(false); +#endif + + proc = BackendPidGetProc(pid); + + /* + * BackendPidGetProc returns NULL if the pid isn't valid. + * + * Note that the proc will also be NULL if the pid refers to an auxiliary + * process or the postmaster (neither of which can be signaled via + * pg_log_backtrace() to get backtrace). + * + * XXX: It might be worth implementing it for auxiliary processes. + */ + if (proc == NULL) + { + /* + * This is just a warning so a loop-through-resultset will not abort + * if one backend terminated on its own during the run. + */ + ereport(WARNING, + (errmsg("PID %d is not a PostgreSQL backend process", pid))); + + PG_RETURN_BOOL(false); + } + + if (SendProcSignal(pid, PROCSIG_LOG_BACKTRACE, proc->backendId) < 0) + { + /* Again, just a warning to allow loops */ + ereport(WARNING, + (errmsg("could not send signal to process %d: %m", pid))); + PG_RETURN_BOOL(false); + } + + PG_RETURN_BOOL(true); +} diff --git a/src/backend/storage/ipc/procsignal.c b/src/backend/storage/ipc/procsignal.c index e84619e5a5..3f1ce745af 100644 --- a/src/backend/storage/ipc/procsignal.c +++ b/src/backend/storage/ipc/procsignal.c @@ -28,6 +28,7 @@ #include "storage/ipc.h" #include "storage/latch.h" #include "storage/proc.h" +#include "storage/procbacktrace.h" #include "storage/shmem.h" #include "storage/smgr.h" #include "storage/sinval.h" @@ -658,6 +659,9 @@ procsignal_sigusr1_handler(SIGNAL_ARGS) if (CheckProcSignal(PROCSIG_LOG_MEMORY_CONTEXT)) HandleLogMemoryContextInterrupt(); + if (CheckProcSignal(PROCSIG_LOG_BACKTRACE)) + HandleLogBacktraceInterrupt(); + if (CheckProcSignal(PROCSIG_PARALLEL_APPLY_MESSAGE)) HandleParallelApplyMessageInterrupt(); diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c index e5977548fe..73e0368c29 100644 --- a/src/backend/storage/lmgr/proc.c +++ b/src/backend/storage/lmgr/proc.c @@ -48,6 +48,7 @@ #include "storage/pmsignal.h" #include "storage/proc.h" #include "storage/procarray.h" +#include "storage/procbacktrace.h" #include "storage/procsignal.h" #include "storage/spin.h" #include "storage/standby.h" @@ -462,6 +463,8 @@ InitProcess(void) InitLWLockAccess(); InitDeadLockChecking(); + LoadBacktraceFunctions(); + #ifdef EXEC_BACKEND /* diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat index 29af4ce65d..17b95f3f35 100644 --- a/src/include/catalog/pg_proc.dat +++ b/src/include/catalog/pg_proc.dat @@ -12170,4 +12170,8 @@ proargtypes => 'int2', prosrc => 'gist_stratnum_identity' }, +# function to get the backtrace of server process +{ oid => '9661', descr => 'log backtrace of server process', + proname => 'pg_log_backtrace', provolatile => 'v', prorettype => 'bool', + proargtypes => 'int4', prosrc => 'pg_log_backtrace' }, ] diff --git a/src/include/storage/procbacktrace.h b/src/include/storage/procbacktrace.h new file mode 100644 index 0000000000..884bdb34ad --- /dev/null +++ b/src/include/storage/procbacktrace.h @@ -0,0 +1,20 @@ +/*------------------------------------------------------------------------- + * + * procsignal.h + * Backtrace-related routines + * + * + * Portions Copyright (c) 1996-2024, PostgreSQL Global Development Group + * Portions Copyright (c) 1994, Regents of the University of California + * + * src/include/storage/procbacktrace.h + * + *------------------------------------------------------------------------- + */ +#ifndef PROCBACKTRACE_H +#define PROCBACKTRACE_H + +extern void HandleLogBacktraceInterrupt(void); +extern void LoadBacktraceFunctions(void); + +#endif /* PROCBACKTRACE_H */ diff --git a/src/include/storage/procsignal.h b/src/include/storage/procsignal.h index 52dcb4c2ad..a387da8379 100644 --- a/src/include/storage/procsignal.h +++ b/src/include/storage/procsignal.h @@ -36,6 +36,7 @@ typedef enum PROCSIG_BARRIER, /* global barrier interrupt */ PROCSIG_LOG_MEMORY_CONTEXT, /* ask backend to log the memory contexts */ PROCSIG_PARALLEL_APPLY_MESSAGE, /* Message from parallel apply workers */ + PROCSIG_LOG_BACKTRACE, /* ask backend to log the current backtrace */ /* Recovery conflict reasons */ PROCSIG_RECOVERY_CONFLICT_FIRST, diff --git a/src/test/regress/expected/misc_functions.out b/src/test/regress/expected/misc_functions.out index 7c15477104..92328a4f21 100644 --- a/src/test/regress/expected/misc_functions.out +++ b/src/test/regress/expected/misc_functions.out @@ -326,6 +326,57 @@ REVOKE EXECUTE ON FUNCTION pg_log_backend_memory_contexts(integer) FROM regress_log_memory; DROP ROLE regress_log_memory; -- +-- pg_log_backtrace() +-- +-- Backtraces are logged to stderr and not returned to the function. +-- Furthermore, their contents can vary depending on the timing. However, +-- we can verify that the code doesn't fail, and that the permissions are +-- set properly. +CREATE ROLE regress_log_backtrace; +SELECT has_function_privilege('regress_log_backtrace', + 'pg_log_backtrace(integer)', 'EXECUTE'); -- no + has_function_privilege +------------------------ + f +(1 row) + +GRANT EXECUTE ON FUNCTION pg_log_backtrace(integer) + TO regress_log_backtrace; +SELECT has_function_privilege('regress_log_backtrace', + 'pg_log_backtrace(integer)', 'EXECUTE'); -- yes + has_function_privilege +------------------------ + t +(1 row) + +-- Suppress warnings that depend on dynamic content i.e. PID or backtrace +-- generation support. +SET client_min_messages = 'ERROR'; +SET ROLE regress_log_backtrace; +-- Backtrace is logged only for backends +SELECT pg_log_backtrace(pg_backend_pid()); + pg_log_backtrace +------------------ + t +(1 row) + +RESET ROLE; +-- Backtrace is not logged for auxiliary processes +SELECT backend_type, pg_log_backtrace(pid) FROM pg_stat_activity + WHERE backend_type IN ('checkpointer', 'walwriter', 'background writer') + ORDER BY backend_type; + backend_type | pg_log_backtrace +-------------------+------------------ + background writer | f + checkpointer | f + walwriter | f +(3 rows) + +RESET client_min_messages; +REVOKE EXECUTE ON FUNCTION pg_log_backtrace(integer) + FROM regress_log_backtrace; +DROP ROLE regress_log_backtrace; +-- -- Test some built-in SRFs -- -- The outputs of these are variable, so we can't just print their results diff --git a/src/test/regress/sql/misc_functions.sql b/src/test/regress/sql/misc_functions.sql index 851dad90f4..9931c384a6 100644 --- a/src/test/regress/sql/misc_functions.sql +++ b/src/test/regress/sql/misc_functions.sql @@ -102,6 +102,47 @@ REVOKE EXECUTE ON FUNCTION pg_log_backend_memory_contexts(integer) DROP ROLE regress_log_memory; +-- +-- pg_log_backtrace() +-- +-- Backtraces are logged to stderr and not returned to the function. +-- Furthermore, their contents can vary depending on the timing. However, +-- we can verify that the code doesn't fail, and that the permissions are +-- set properly. +CREATE ROLE regress_log_backtrace; + +SELECT has_function_privilege('regress_log_backtrace', + 'pg_log_backtrace(integer)', 'EXECUTE'); -- no + +GRANT EXECUTE ON FUNCTION pg_log_backtrace(integer) + TO regress_log_backtrace; + +SELECT has_function_privilege('regress_log_backtrace', + 'pg_log_backtrace(integer)', 'EXECUTE'); -- yes + +-- Suppress warnings that depend on dynamic content i.e. PID or backtrace +-- generation support. +SET client_min_messages = 'ERROR'; + +SET ROLE regress_log_backtrace; + +-- Backtrace is logged only for backends +SELECT pg_log_backtrace(pg_backend_pid()); + +RESET ROLE; + +-- Backtrace is not logged for auxiliary processes +SELECT backend_type, pg_log_backtrace(pid) FROM pg_stat_activity + WHERE backend_type IN ('checkpointer', 'walwriter', 'background writer') + ORDER BY backend_type; + +RESET client_min_messages; + +REVOKE EXECUTE ON FUNCTION pg_log_backtrace(integer) + FROM regress_log_backtrace; + +DROP ROLE regress_log_backtrace; + -- -- Test some built-in SRFs -- -- 2.34.1