Horton

Thread

  1. How to investigate deadlocks

    Matthias Apitz <guru@unixarea.de> — 2023-10-02T11:27:42Z

    Hello,

One of our clients running our LMS on top of PostgreSQL 13.1 created a
ticket with these messages:

2023-09-30 16:50:50.951 CEST [18117] ERROR:  deadlock detected
2023-09-30 16:50:50.951 CEST [18117] DETAIL:  Process 18117 waits for ShareLock on transaction 150396154; blocked by process 18187.
	Process 18187 waits for ShareLock on transaction 150396155; blocked by process 18117.
	Process 18117: fetch hc_d03geb
	Process 18187: fetch hc_d02ben
2023-09-30 16:50:50.951 CEST [18117] HINT:  See server log for query details.
2023-09-30 16:50:50.951 CEST [18117] CONTEXT:  while locking tuple (38,57) in relation "d03geb"
2023-09-30 16:50:50.951 CEST [18117] STATEMENT:  fetch hc_d03geb

The shown PIDs for sure are the ones of the Pos backend proc (on Linux).
Is there any chance to investigate it further?

Thanks

	matthias

-- 
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub

  2. Re: How to investigate deadlocks

    Andreas Kretschmer <andreas@a-kretschmer.de> — 2023-10-02T11:36:02Z

    
Am 02.10.23 um 13:27 schrieb Matthias Apitz:
> Hello,
>
> One of our clients running our LMS on top of PostgreSQL 13.1 created a
> ticket with these messages:
>
> 2023-09-30 16:50:50.951 CEST [18117] ERROR:  deadlock detected
> 2023-09-30 16:50:50.951 CEST [18117] DETAIL:  Process 18117 waits for ShareLock on transaction 150396154; blocked by process 18187.
> 	Process 18187 waits for ShareLock on transaction 150396155; blocked by process 18117.
> 	Process 18117: fetch hc_d03geb
> 	Process 18187: fetch hc_d02ben
> 2023-09-30 16:50:50.951 CEST [18117] HINT:  See server log for query details.
> 2023-09-30 16:50:50.951 CEST [18117] CONTEXT:  while locking tuple (38,57) in relation "d03geb"
> 2023-09-30 16:50:50.951 CEST [18117] STATEMENT:  fetch hc_d03geb


have you checked the server log?

See server log for query details.



Regards, Andreas

-- 
Andreas Kretschmer
Technical Account Manager (TAM)
www.enterprisedb.com

  3. Re: How to investigate deadlocks

    Andreas Kretschmer <andreas@a-kretschmer.de> — 2023-10-02T11:39:00Z

    
Am 02.10.23 um 13:27 schrieb Matthias Apitz:
> Hello,
>
> One of our clients running our LMS on top of PostgreSQL 13.1 created a
> ticket with these messages:
>
> 2023-09-30 16:50:50.951 CEST [18117] ERROR:  deadlock detected
> 2023-09-30 16:50:50.951 CEST [18117] DETAIL:  Process 18117 waits for ShareLock on transaction 150396154; blocked by process 18187.
> 	Process 18187 waits for ShareLock on transaction 150396155; blocked by process 18117.
> 	Process 18117: fetch hc_d03geb
> 	Process 18187: fetch hc_d02ben
> 2023-09-30 16:50:50.951 CEST [18117] HINT:  See server log for query details.
> 2023-09-30 16:50:50.951 CEST [18117] CONTEXT:  while locking tuple (38,57) in relation "d03geb"
> 2023-09-30 16:50:50.951 CEST [18117] STATEMENT:  fetch hc_d03geb
>
> The shown PIDs for sure are the ones of the Pos backend proc (on Linux).
> Is there any chance to investigate it further?

please also check 
https://www.cybertec-postgresql.com/en/postgresql-understanding-deadlocks/


Andreas

-- 
Andreas Kretschmer
Technical Account Manager (TAM)
www.enterprisedb.com

  4. Re: How to investigate deadlocks

    Laurenz Albe <laurenz.albe@cybertec.at> — 2023-10-02T14:01:48Z

    On Mon, 2023-10-02 at 13:27 +0200, Matthias Apitz wrote:
> One of our clients running our LMS on top of PostgreSQL 13.1 created a
> ticket with these messages:
> 
> 2023-09-30 16:50:50.951 CEST [18117] ERROR:  deadlock detected
> 2023-09-30 16:50:50.951 CEST [18117] DETAIL:  Process 18117 waits for ShareLock on transaction 150396154; blocked by process 18187.
>         Process 18187 waits for ShareLock on transaction 150396155; blocked by process 18117.
>         Process 18117: fetch hc_d03geb
>         Process 18187: fetch hc_d02ben
> 2023-09-30 16:50:50.951 CEST [18117] HINT:  See server log for query details.
> 2023-09-30 16:50:50.951 CEST [18117] CONTEXT:  while locking tuple (38,57) in relation "d03geb"
> 2023-09-30 16:50:50.951 CEST [18117] STATEMENT:  fetch hc_d03geb
> 
> The shown PIDs for sure are the ones of the Pos backend proc (on Linux).
> Is there any chance to investigate it further?

See the line:

  HINT:  See server log for query details.

Other than that, it is difficult to figure out the exact cause of a deadlock.
You need to know all the statements that were run in these transactions,
which probably requires deeper knowledge of the application.

Yours,
Laurenz Albe

  5. Re: How to investigate deadlocks

    Tom Lane <tgl@sss.pgh.pa.us> — 2023-10-02T14:16:18Z

    Matthias Apitz <guru@unixarea.de> writes:
> One of our clients running our LMS on top of PostgreSQL 13.1 created a
> ticket with these messages:

> 2023-09-30 16:50:50.951 CEST [18117] ERROR:  deadlock detected
> 2023-09-30 16:50:50.951 CEST [18117] DETAIL:  Process 18117 waits for ShareLock on transaction 150396154; blocked by process 18187.
> 	Process 18187 waits for ShareLock on transaction 150396155; blocked by process 18117.
> 	Process 18117: fetch hc_d03geb
> 	Process 18187: fetch hc_d02ben
> 2023-09-30 16:50:50.951 CEST [18117] HINT:  See server log for query details.
> 2023-09-30 16:50:50.951 CEST [18117] CONTEXT:  while locking tuple (38,57) in relation "d03geb"
> 2023-09-30 16:50:50.951 CEST [18117] STATEMENT:  fetch hc_d03geb

> The shown PIDs for sure are the ones of the Pos backend proc (on Linux).
> Is there any chance to investigate it further?

Well, not with this amount of info.  But it seems like a fairly
safe bet that the locks being contended for arise from trying to
SELECT-FOR-UPDATE the same two rows in different orders.
You'd need to look at the cursors being fetched from and see
what you can do to make their row locking orders be reliably
consistent.  Or see if you can avoid needing exclusive row
locks in the first place.

			regards, tom lane

  6. Re: How to investigate deadlocks

    David G. Johnston <david.g.johnston@gmail.com> — 2023-10-02T22:25:02Z

    On Monday, October 2, 2023, Matthias Apitz <guru@unixarea.de> wrote:

>
> Hello,
>
> One of our clients running our LMS on top of PostgreSQL 13.1 created a
> ticket with these messages:
>
> 2023-09-30 16:50:50.951 CEST [18117] ERROR:  deadlock detected
> 2023-09-30 16:50:50.951 CEST [18117] DETAIL:  Process 18117 waits for
> ShareLock on transaction 150396154; blocked by process 18187.
>         Process 18187 waits for ShareLock on transaction 150396155;
> blocked by process 18117.
>         Process 18117: fetch hc_d03geb
>         Process 18187: fetch hc_d02ben
> 2023-09-30 16:50:50.951 CEST [18117] HINT:  See server log for query
> details.
> 2023-09-30 16:50:50.951 CEST [18117] CONTEXT:  while locking tuple (38,57)
> in relation "d03geb"
> 2023-09-30 16:50:50.951 CEST [18117] STATEMENT:  fetch hc_d03geb
>
> The shown PIDs for sure are the ones of the Pos backend proc (on Linux).
> Is there any chance to investigate it further?
>

Presuming you control the software performing the fetches, sure.  But the
database has pretty much told you all it can from its perspective.  Start
from the two fetches, work out the table/row access ordering, and figure
out where you have the same pairs of tables being accessed but in different
orders.

David J.