From b9fe5485726915c963882d1d99eb582023a9bf55 Mon Sep 17 00:00:00 2001 From: Bharath Rupireddy Date: Wed, 7 Feb 2024 18:22:10 +0000 Subject: [PATCH v29 1/2] Add function to log backtrace of a backend --- doc/src/sgml/func.sgml | 45 ++++++ 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 | 149 +++++++++++++++++++ src/backend/storage/ipc/procsignal.c | 4 + src/backend/storage/lmgr/proc.c | 3 + src/include/catalog/pg_proc.dat | 6 + src/include/storage/procbacktrace.h | 20 +++ src/include/storage/procsignal.h | 1 + src/test/regress/expected/misc_functions.out | 49 ++++++ src/test/regress/sql/misc_functions.sql | 40 +++++ 12 files changed, 321 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..b7d7305331 100644 --- a/doc/src/sgml/func.sgml +++ b/doc/src/sgml/func.sgml @@ -27186,6 +27186,24 @@ SELECT collation for ('foo' COLLATE "de_DE"); + + + + pg_log_backend_backtrace + + pg_log_backend_backtrace ( pid integer ) + boolean + + + Requests to log the backtrace of a backend with the specified process + ID. The backtraces will be logged to stderr. + 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. + + + @@ -27300,6 +27318,33 @@ LOG: Grand total: 1651920 bytes in 201 blocks; 622360 free (88 chunks); 1029560 because it may generate a large number of log messages. + + pg_log_backend_backtrace can be used to log the backtrace of + a backend process. For example: + +postgres=# select pg_log_backend_backtrace(pg_backend_pid()); + pg_log_backend_backtrace +------------------ + t +(1 row) + +The backtrace will be logged as specified by the logging configuration. +For example: + +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] +... + + One can obtain the file name and line number from the logged details by + using GDB or + addr2line in most Linux systems. + diff --git a/src/backend/catalog/system_functions.sql b/src/backend/catalog/system_functions.sql index 346cfb98a0..f4c6334bb9 100644 --- a/src/backend/catalog/system_functions.sql +++ b/src/backend/catalog/system_functions.sql @@ -751,6 +751,8 @@ REVOKE EXECUTE ON FUNCTION pg_ls_dir(text,boolean,boolean) FROM public; REVOKE EXECUTE ON FUNCTION pg_log_backend_memory_contexts(integer) FROM PUBLIC; +REVOKE EXECUTE ON FUNCTION pg_log_backend_backtrace(integer) FROM PUBLIC; + REVOKE EXECUTE ON FUNCTION pg_ls_logicalsnapdir() FROM PUBLIC; REVOKE EXECUTE ON FUNCTION pg_ls_logicalmapdir() FROM PUBLIC; 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..bfab5783da --- /dev/null +++ b/src/backend/storage/ipc/procbacktrace.c @@ -0,0 +1,149 @@ +/*------------------------------------------------------------------------- + * + * 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 +#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" + +#ifdef HAVE_EXECINFO_H +static volatile sig_atomic_t backtrace_functions_loaded = false; +#endif + +/* + * 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) +{ +#ifdef HAVE_EXECINFO_H + void *buf[100]; + int nframes; + + 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)); +#endif +} + +/* + * 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) +{ +#ifdef HAVE_BACKTRACE_SYMBOLS + void *buf[2]; + + 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; +#endif +} + +/* + * pg_log_backend_backtrace + * Signal a backend to log its current backtrace. + * + * By default, only superusers are allowed to signal to log the backtrace + * because allowing any users to issue this request at an unbounded + * rate would cause lots of log messages on stderr and which can lead to + * denial of service. Additional roles can be permitted with GRANT. + * + * On receipt of this signal, a backend emits the current backtrace to stderr + * in the signal handler. + */ +Datum +pg_log_backend_backtrace(PG_FUNCTION_ARGS) +{ +#ifdef HAVE_BACKTRACE_SYMBOLS + int pid = PG_GETARG_INT32(0); + PGPROC *proc; + + 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_backend_backtrace() to get backtrace). + */ + 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); +#else + ereport(WARNING, + errmsg("backtrace generation is not supported by this installation"), + errhint("You need to build PostgreSQL with library containing backtrace_symbols.")); + + PG_RETURN_BOOL(false); +#endif +} 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..cee43a8304 100644 --- a/src/include/catalog/pg_proc.dat +++ b/src/include/catalog/pg_proc.dat @@ -8274,6 +8274,12 @@ prorettype => 'bool', proargtypes => 'int4', prosrc => 'pg_log_backend_memory_contexts' }, +# logging backtrace of the specified backend +{ oid => '9661', descr => 'log backtrace of the specified backend', + proname => 'pg_log_backend_backtrace', provolatile => 'v', + prorettype => 'bool', proargtypes => 'int4', + prosrc => 'pg_log_backend_backtrace' }, + # non-persistent series generator { oid => '1066', descr => 'non-persistent series generator', proname => 'generate_series', prorows => '1000', 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..5772b335d6 100644 --- a/src/include/storage/procsignal.h +++ b/src/include/storage/procsignal.h @@ -35,6 +35,7 @@ typedef enum PROCSIG_WALSND_INIT_STOPPING, /* ask walsenders to prepare for shutdown */ PROCSIG_BARRIER, /* global barrier interrupt */ PROCSIG_LOG_MEMORY_CONTEXT, /* ask backend to log the memory contexts */ + PROCSIG_LOG_BACKTRACE, /* ask backend to log the current backtrace */ PROCSIG_PARALLEL_APPLY_MESSAGE, /* Message from parallel apply workers */ /* Recovery conflict reasons */ diff --git a/src/test/regress/expected/misc_functions.out b/src/test/regress/expected/misc_functions.out index 7c15477104..3ff0136347 100644 --- a/src/test/regress/expected/misc_functions.out +++ b/src/test/regress/expected/misc_functions.out @@ -326,6 +326,55 @@ REVOKE EXECUTE ON FUNCTION pg_log_backend_memory_contexts(integer) FROM regress_log_memory; DROP ROLE regress_log_memory; -- +-- pg_log_backend_backtrace() +-- +-- Backtraces are logged to stderr and not returned to the function. +-- Furthermore, the output of this function can vary depending on backtrace +-- generation support. However, we can at least verify that the code doesn't +-- fail, and that the permissions are set properly. +-- Suppress warnings that depend on dynamic output i.e. PID or backtrace +-- generation support. +SET client_min_messages = 'ERROR'; +SELECT count(*) > 0 AS ok FROM pg_log_backend_backtrace(pg_backend_pid()); + ok +---- + t +(1 row) + +RESET client_min_messages; +CREATE ROLE regress_log_backtrace; +SELECT has_function_privilege('regress_log_backtrace', + 'pg_log_backend_backtrace(integer)', 'EXECUTE'); -- no + has_function_privilege +------------------------ + f +(1 row) + +GRANT EXECUTE ON FUNCTION pg_log_backend_backtrace(integer) + TO regress_log_backtrace; +SELECT has_function_privilege('regress_log_backtrace', + 'pg_log_backend_backtrace(integer)', 'EXECUTE'); -- yes + has_function_privilege +------------------------ + t +(1 row) + +SET ROLE regress_log_backtrace; +-- Suppress warnings that depend on dynamic output i.e. PID or backtrace +-- generation support. +SET client_min_messages = 'ERROR'; +SELECT count(*) > 0 AS ok FROM pg_log_backend_backtrace(pg_backend_pid()); + ok +---- + t +(1 row) + +RESET client_min_messages; +RESET ROLE; +REVOKE EXECUTE ON FUNCTION pg_log_backend_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..2a3f9bacaa 100644 --- a/src/test/regress/sql/misc_functions.sql +++ b/src/test/regress/sql/misc_functions.sql @@ -102,6 +102,46 @@ REVOKE EXECUTE ON FUNCTION pg_log_backend_memory_contexts(integer) DROP ROLE regress_log_memory; +-- +-- pg_log_backend_backtrace() +-- +-- Backtraces are logged to stderr and not returned to the function. +-- Furthermore, the output of this function can vary depending on backtrace +-- generation support. However, we can at least verify that the code doesn't +-- fail, and that the permissions are set properly. + +-- Suppress warnings that depend on dynamic output i.e. PID or backtrace +-- generation support. +SET client_min_messages = 'ERROR'; +SELECT count(*) > 0 AS ok FROM pg_log_backend_backtrace(pg_backend_pid()); +RESET client_min_messages; + +CREATE ROLE regress_log_backtrace; + +SELECT has_function_privilege('regress_log_backtrace', + 'pg_log_backend_backtrace(integer)', 'EXECUTE'); -- no + +GRANT EXECUTE ON FUNCTION pg_log_backend_backtrace(integer) + TO regress_log_backtrace; + +SELECT has_function_privilege('regress_log_backtrace', + 'pg_log_backend_backtrace(integer)', 'EXECUTE'); -- yes + +SET ROLE regress_log_backtrace; + +-- Suppress warnings that depend on dynamic output i.e. PID or backtrace +-- generation support. +SET client_min_messages = 'ERROR'; +SELECT count(*) > 0 AS ok FROM pg_log_backend_backtrace(pg_backend_pid()); +RESET client_min_messages; + +RESET ROLE; + +REVOKE EXECUTE ON FUNCTION pg_log_backend_backtrace(integer) + FROM regress_log_backtrace; + +DROP ROLE regress_log_backtrace; + -- -- Test some built-in SRFs -- -- 2.34.1