Logging conflicted queries on deadlocks - Mailing list pgsql-hackers

From ITAGAKI Takahiro
Subject Logging conflicted queries on deadlocks
Date
Msg-id 20080228165156.5F4E.52131E4D@oss.ntt.co.jp
Whole thread Raw
Responses Re: Logging conflicted queries on deadlocks
Re: Logging conflicted queries on deadlocks
List pgsql-hackers
Hello,

We see error logs something like following on deadlocks:

| ERROR:  deadlock detected
| DETAIL:  Process 1612 waits for ShareLock on transaction 407; blocked by process 3388.
|         Process 3388 waits for ShareLock on transaction 406; blocked by process 1612.
| STATEMENT:  UPDATE test SET i = i WHERE i = 2;

It shows which query is killed, but we cannot get which query is conflicted.
The opponent's queries are useful for deadlock debug, but the only thing
we can do for now is polling pg_locks and pg_stat_sctivity with hope to
take a snapshot of the system just on deadlocks.

I wrote a small patch to log conflicted queries.
With my patch, deadlock message will change as following:

| ERROR:  deadlock detected
| DETAIL:  Process 3468 waits for ShareLock on transaction 451; blocked by process 4068.
|         STATEMENT: UPDATE test SET i = i WHERE i = 1;    <- ***conflicted query***
|         Process 4068 waits for ShareLock on transaction 450; blocked by process 3468.
| STATEMENT:  UPDATE test SET i = i WHERE i = 2;

There are some open issues. One of the issues is that the killed query is
logged by log_min_error_statement, but conflicted query is logged in DETAIL.
Killed query is logged only on server but conflicted queries are
sent to both server and client. In addition, if log_min_error_statement
is less than ERROR level, only the conflicted queries are logged.
-- it's inconsistent and unsymmetric.

Are there any better format to dump conflicted queries?
Comments welcome.


[[10-line patch to log conflicted query on deadlocks]]
Index: src/backend/storage/lmgr/deadlock.c
===================================================================
--- src/backend/storage/lmgr/deadlock.c    (HEAD)
+++ src/backend/storage/lmgr/deadlock.c    (working copy)
@@ -911,6 +913,18 @@                                         info->lockmode),                         buf2.data,
                nextpid);
 
+
+        if (nextpid != MyProcPid)
+        {
+            PGPROC* proc = BackendPidGetProc(nextpid);
+            if (proc != NULL && (superuser() || proc->roleId == GetUserId()))
+            {
+                PgBackendStatus *beentry;
+                beentry = pgstat_fetch_stat_beentry(proc->backendId);
+                if (beentry && beentry->st_activity[0] != '\0')
+                    appendStringInfo(&buf, "\nSTATEMENT: %s", beentry->st_activity);
+            }
+        }    }    ereport(ERROR,            (errcode(ERRCODE_T_R_DEADLOCK_DETECTED),

Regards,
---
ITAGAKI Takahiro
NTT Open Source Software Center



pgsql-hackers by date:

Previous
From: "Babu, Gabriel Suresh"
Date:
Subject: ES7000 Windows 2003 server 64bit processor
Next
From: "Pavan Deolasee"
Date:
Subject: CREATE TABLE, load and freezing