On Fri, Apr 27, 2018 at 2:55 AM, Olivier Macchioni <olivier.macchioni@xxxxxxxx> wrote: > Hello all, > > PostgreSQL version 9.4.17 > > We have a number of queries running on the same DB from many systems. Among other things, we need to INSERT / UPDATE on a table based on external events - this is done via a pool of 5 SQL connections which process an average of 500 events / second. The table is used by other systems as well... > > We have more and more locks on this table, which prevents it to be updated as it should - and I'm trying to see how to improve things without setting up an external queue system just to manage those events. > > I've enabled "log_lock_waits = on" in the configuration, which generates the following kind of log entries: > > 2018-04-27 07:48:07 CEST [1419.269] "[unknown]" xx@yy LOG: process 1419 still waiting for ExclusiveLock on advisory lock [16417,1653339453,2672182422,2] after 1000.166 ms > 2018-04-27 07:48:07 CEST [1419.270] "[unknown]" xx@yy DETAIL: Process holding the lock: 16418. Wait queue: 1419. > 2018-04-27 07:48:07 CEST [1419.271] "[unknown]" xx@yy STATEMENT: SELECT pg_advisory_xact_lock(1653339453, -1622784874); > 2018-04-27 07:48:07 CEST [1419.272] "[unknown]" xx@yy LOG: process 1419 acquired ExclusiveLock on advisory lock [16417,1653339453,2672182422,2] after 1318.721 ms > 2018-04-27 07:48:07 CEST [1419.273] "[unknown]" xx@yy STATEMENT: SELECT pg_advisory_xact_lock(1653339453, -1622784874); > > I can easily identify the session owner of the different processes, but the process holding the lock belong to an ERP which generates a lot of different kind of queries - I'd like to identify precisely which one is causing this long-lasting lock. > > It doesn't look like this is possible via the PostgreSQL logging features, and doing the usual lock troubleshooting "on the spot" using pg_locks is not practical due to the short duration and odd timing of those locks. > > Does anyone have an idea on how to process in such a case? Here, the locking query is obvious: "SELECT pg_advisory_xact_lock". If this is an ERP application I bet advisory locks are being used to simulate pessimistic locking in some way. Unfortunately this is no help as the real operation is elsewhere in this transaction. Echoing the advice above you need to enable full statement logging and make sure your log_line_prefix contains pid in some easily searched for way such as [%p]. Once you have that, you can trace back in the file based on the locking pid and get to the bottom of the situation pretty easily. Be mindful statement logging, it can consume disk space really quickly and add a lot of overhead to the database. merlin
