As we know, the deadlock error message isn't the most friendly one. All the
client gets back is process PIDs, transaction IDs, and lock types. You have to
check the server log to retrieve lock details. This is tedious.
In one of my apps I even added a deadlock exception handler on the app side to
query pg_stat_activity for processes involved in the deadlock and include their
application names and queries in the exception message. It is a little racy but
works well enough.
Ideally I'd like to see that data coming from Postgres upon detecting the
deadlock. That's why I made this small change.
The change makes the deadlock error look as follows - the new element is the
application name or "<insufficient privilege>" in its place if the activity
user doesn't match the current user (and the current use isn't a superuser):
postgres=*> SELECT * FROM q WHERE id = 2 FOR UPDATE;
ERROR: deadlock detected
DETAIL: Process 194520 (application_name: <insufficient privilege>) waits for
ShareLock on transaction 776; blocked by process 194521.
Process 194521 (application_name: woof) waits for ShareLock on transaction 775;
blocked by process 194520.
HINT: See server log for query details.
CONTEXT: while locking tuple (0,2) in relation "q"
I added a new LocalPgBackendCurrentActivity struct combining application name
and query string pointers and a sameProcess boolean. It is returned by value,
since it's small. Performance-wise, this is a a part of the deadlock handler,
if the DB hits it frequently, there are much more serious problems going on.
I could extend it by sending the queries back to the client, with an identical
security check, but this is a potential information exposure of whatever's in
the query plaintext. Another extension is to replace "(application_name:
<insufficient privilege>)" with something better like "(unknown
application_name)", or even nothing.
Attached patch is for master, 2fb7560c. It doesn't contain any tests.
Let me know if you approve of the patch and if it makes sense to continue
working on it.
Best,
Karoline
From f7d3b3854ece45b2ba3b79643e99c1acbb09abae Mon Sep 17 00:00:00 2001
From: Karoline Pauls <c...@karolinepauls.com>
Date: Wed, 8 May 2024 23:49:46 +0100
Subject: [PATCH] call pgstat_get_backend_current_activity once
---
src/backend/storage/lmgr/deadlock.c | 31 +++++++++++++--------
src/backend/utils/activity/backend_status.c | 10 +++----
src/include/utils/backend_status.h | 4 ++-
src/tools/pgindent/typedefs.list | 1 +
4 files changed, 29 insertions(+), 17 deletions(-)
diff --git a/src/backend/storage/lmgr/deadlock.c b/src/backend/storage/lmgr/deadlock.c
index d94f65df..c08f66af 100644
--- a/src/backend/storage/lmgr/deadlock.c
+++ b/src/backend/storage/lmgr/deadlock.c
@@ -1075,17 +1075,22 @@ DeadLockReport(void)
StringInfoData logbuf; /* errdetail for server log */
StringInfoData locktagbuf;
int i;
+ bool isSuperuser = superuser();
+ LocalPgBackendCurrentActivity *activities = \
+ (LocalPgBackendCurrentActivity *) palloc(sizeof(LocalPgBackendCurrentActivity) * nDeadlockDetails);
initStringInfo(&clientbuf);
initStringInfo(&logbuf);
initStringInfo(&locktagbuf);
- /* Generate the "waits for" lines sent to the client */
+ /* Generate the "waits for" lines sent to the client and the log */
for (i = 0; i < nDeadlockDetails; i++)
{
DEADLOCK_INFO *info = &deadlockDetails[i];
int nextpid;
- LocalPgBackendCurrentActivity activity = pgstat_get_backend_current_activity(info->pid, true);
+ const char *lockModeName = GetLockmodeName(info->locktag.locktag_lockmethodid, info->lockmode);
+
+ activities[i] = pgstat_get_backend_current_activity(info->pid);
/* The last proc waits for the first one... */
if (i < nDeadlockDetails - 1)
@@ -1104,29 +1109,33 @@ DeadLockReport(void)
appendStringInfo(&clientbuf,
_("Process %d (application_name: %s) waits for %s on %s; blocked by process %d."),
info->pid,
- activity.st_appname,
- GetLockmodeName(info->locktag.locktag_lockmethodid,
- info->lockmode),
+ (activities[i].sameUser || isSuperuser) ? activities[i].st_appname : "<insufficient privilege>",
+ lockModeName,
locktagbuf.data,
nextpid);
- }
- /* Duplicate all the above for the server ... */
- appendBinaryStringInfo(&logbuf, clientbuf.data, clientbuf.len);
+ /* the difference is that we don't do user checking for the server log */
+ appendStringInfo(&logbuf,
+ _("Process %d (application_name: %s) waits for %s on %s; blocked by process %d."),
+ info->pid,
+ activities[i].st_appname,
+ lockModeName,
+ locktagbuf.data,
+ nextpid);
+ }
/* ... and add info about query strings */
for (i = 0; i < nDeadlockDetails; i++)
{
DEADLOCK_INFO *info = &deadlockDetails[i];
- LocalPgBackendCurrentActivity activity = pgstat_get_backend_current_activity(info->pid, false);
appendStringInfoChar(&logbuf, '\n');
appendStringInfo(&logbuf,
_("Process %d, (application_name: %s): %s"),
info->pid,
- activity.st_appname,
- activity.st_activity);
+ activities[i].st_appname,
+ activities[i].st_activity);
}
pgstat_report_deadlock();
diff --git a/src/backend/utils/activity/backend_status.c b/src/backend/utils/activity/backend_status.c
index 1703aa79..6ccc76ae 100644
--- a/src/backend/utils/activity/backend_status.c
+++ b/src/backend/utils/activity/backend_status.c
@@ -882,11 +882,11 @@ pgstat_read_current_status(void)
* ----------
*/
struct LocalPgBackendCurrentActivity
-pgstat_get_backend_current_activity(int pid, bool checkUser)
+pgstat_get_backend_current_activity(int pid)
{
PgBackendStatus *beentry;
int i;
- LocalPgBackendCurrentActivity activity = {"", "<backend information not available>"};
+ LocalPgBackendCurrentActivity activity = {"?", "<backend information not available>", false};
beentry = BackendStatusArray;
for (i = 1; i <= MaxBackends; i++)
@@ -926,9 +926,9 @@ pgstat_get_backend_current_activity(int pid, bool checkUser)
if (found)
{
/* Now it is safe to use the non-volatile pointer */
- if (checkUser && !superuser() && beentry->st_userid != GetUserId())
- activity.st_activity = "<insufficient privilege>";
- else if (*(beentry->st_activity_raw) == '\0')
+ activity.sameUser = beentry->st_userid != GetUserId();
+
+ if (*(beentry->st_activity_raw) == '\0')
activity.st_activity = "<command string not enabled>";
else
{
diff --git a/src/include/utils/backend_status.h b/src/include/utils/backend_status.h
index a2110a8a..08d1b026 100644
--- a/src/include/utils/backend_status.h
+++ b/src/include/utils/backend_status.h
@@ -283,6 +283,8 @@ typedef struct LocalPgBackendCurrentActivity
{
char *st_appname;
char *st_activity;
+ /* true if the activity user is the caller user */
+ bool sameUser;
} LocalPgBackendCurrentActivity;
/* ----------
@@ -325,7 +327,7 @@ extern void pgstat_report_query_id(uint64 query_id, bool force);
extern void pgstat_report_tempfile(size_t filesize);
extern void pgstat_report_appname(const char *appname);
extern void pgstat_report_xact_timestamp(TimestampTz tstamp);
-extern LocalPgBackendCurrentActivity pgstat_get_backend_current_activity(int pid, bool checkUser);
+extern LocalPgBackendCurrentActivity pgstat_get_backend_current_activity(int pid);
extern const char *pgstat_get_crashed_backend_activity(int pid, char *buffer,
int buflen);
extern uint64 pgstat_get_my_query_id(void);
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index 2311f82d..f50c8935 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -1492,6 +1492,7 @@ ListenStmt
LoInfo
LoadStmt
LocalBufferLookupEnt
+LocalPgBackendCurrentActivity
LocalPgBackendStatus
LocalTransactionId
LocationIndex
--
2.34.1
