1

I'm trying to monitor an application that uses PostgreSQL (13) to identify what can cause this error (occasionally):

ERROR: out of shared memory
Hint: You might need to increase max_pred_locks_per_transaction.

I've increase the max_pred_locks_per_transaction (and max_locks_per_transaction), but I'm trying to find the potential cause in the application itself, to see if something better can be done about it.

When I monitor the locks, there are sometimes SIReadLock that seem to be running for a relatively long time, all hung up on COMMIT (although they do finish eventually). A number of the queries executed are likely to involve after-insert/update triggers.

Is there a way to monitor exactly which queries are creating those locks (as opposed to just seeing COMMIT at the end)? (Is there a general recommended way to investigate this sort of problems?)

Here is the query to monitor the locks:

SELECT pg_database.datname AS database,
       pg_namespace.nspname AS schema,
       pg_class.relname AS table,
       pg_locks.mode AS lock_mode,
       pg_locks.page AS lock_page,
       pg_locks.tuple AS lock_tuple,
       pg_locks.locktype AS lock_type,
       pg_locks.virtualxid AS virtual_xid,
       pg_locks.virtualtransaction AS virtual_transaction,
       pg_locks.transactionid AS transaction_id,
       AGE(now(), pg_stat_activity.query_start) AS time_running,
       pg_stat_activity.query_start AS time_started,
       pg_stat_activity.query
FROM pg_class
    INNER JOIN pg_locks ON pg_locks.relation = pg_class.oid
    INNER JOIN pg_database ON pg_database.oid = pg_locks.database
    INNER JOIN pg_namespace ON pg_namespace.oid = pg_class.relnamespace
    INNER JOIN pg_stat_activity ON pg_stat_activity.pid = pg_locks.pid
WHERE pg_class.relkind = 'r'
    ORDER BY 11 DESC;

Here is a sample output (more rows not displayed):

   table       |    lock_mode    | lock_page | lock_tuple | lock_type | virtual_xid | virtual_transaction| transaction_id |  time_running   |         time_started          |    query
---------------+-----------------+-----------+------------+-----------+-------------+--------------------+----------------+-----------------+-------------------------------+--------------
 test_table_a  | SIReadLock      |      8410 |            | page      |             | 25/298509          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8416 |            | page      |             | 25/295398          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_b  | SIReadLock      |           |            | relation  |             | 25/299949          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8411 |            | page      |             | 25/296128          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_c  | SIReadLock      |           |            | relation  |             | 25/297437          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8413 |            | page      |             | 25/300961          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8405 |            | page      |             | 25/294361          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8403 |        110 | tuple     |             | 25/300599          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8419 |            | page      |             | 25/298137          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_d  | SIReadLock      |           |            | relation  |             | 25/296086          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8413 |            | page      |             | 25/294361          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8421 |            | page      |             | 25/298137          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8422 |            | page      |             | 25/296692          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_b  | SIReadLock      |           |            | relation  |             | 25/300080          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8405 |            | page      |             | 25/299590          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_c  | SIReadLock      |           |            | relation  |             | 25/294222          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_b  | SIReadLock      |           |            | relation  |             | 25/299148          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8407 |            | page      |             | 25/296692          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_d  | SIReadLock      |           |            | relation  |             | 25/295640          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8431 |            | page      |             | 25/298779          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8426 |            | page      |             | 25/294976          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8410 |            | page      |             | 25/297792          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8416 |            | page      |             | 25/294361          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8426 |            | page      |             | 25/300585          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8417 |          1 | tuple     |             | 25/297792          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_c  | SIReadLock      |           |            | relation  |             | 25/295787          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_e  | SIReadLock      |           |            | relation  |             | 25/297764          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8421 |            | page      |             | 25/295893          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8427 |            | page      |             | 25/294719          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_d  | SIReadLock      |           |            | relation  |             | 25/297663          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_c  | SIReadLock      |           |            | relation  |             | 25/294139          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8431 |            | page      |             | 25/300947          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_d  | SIReadLock      |           |            | relation  |             | 25/295370          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8422 |            | page      |             | 25/297792          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_c  | SIReadLock      |           |            | relation  |             | 25/297064          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8410 |            | page      |             | 25/299949          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8415 |            | page      |             | 25/296128          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8428 |            | page      |             | 25/300080          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8431 |            | page      |             | 25/297423          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8417 |          1 | tuple     |             | 25/298509          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8408 |            | page      |             | 25/297064          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8427 |            | page      |             | 25/295384          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8425 |            | page      |             | 25/294236          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT
 test_table_a  | SIReadLock      |      8415 |            | page      |             | 25/294361          |                | 00:45:46.929129 | 2021-09-06 12:13:31.525553+01 | COMMIT

(There's generally fewer than 30 connections to this database server, 10 to this database.)

Improve this question

2 Answers 2

Reset to default
2

max_pred_locks_per_transaction determines the size of the “predicate lock target hashtable”. This is a different data structure than the lock table, so you can run out of shared memory there while the lock table is not full.

It is normal that SIReadLocks are held after the transaction commits. Your query is misleading: those COMMIT s are not hanging, they are done.

Improve this answer
6
  • 1
    Thank you. I've increased both max_pred_locks_per_transaction and max_locks_per_transaction (having seen both suggestions in error messages). As far as I understand, pg_locks is for both regular and predicate locks. Is there a way to track what those hanging COMMIT queries actually do (or perhaps track what the triggers actually do)?
    – Bruno
    Oct 7, 2021 at 10:54
  • 1
    Thanks, I'd not realised they were done. Are you effectively saying that those locks effectively have nothing to do with the OOM errors I'm getting? Is it also normal for those SIReadLocks to be held for such a long time?
    – Bruno
    Oct 7, 2021 at 11:18
  • 1
    Yes, that is normal. Sure, the number of locks (or predicate lock targets) makes you go OOM. But the COMMITs are completed. Just raise the limit and be happy.
    – Laurenz Albe
    Oct 7, 2021 at 11:38
  • 1
    I guess I'd generally be interested in having a way to monitor which queries make this number grow (possibly in order to try to improve the application that makes those queries in the first place). Somehow, I get the impression that increasing the limit (e.g. 500 at the moment for both) is only postponing the problem...
    – Bruno
    Oct 7, 2021 at 19:28
  • 1
    I don't know of a way to monitor that. 500 is high - do you have long running transactions? If there is really a leak, that would be a PostgreSQL bug.
    – Laurenz Albe
    Oct 8, 2021 at 4:09
0

After trying one week, I did not find any good solutions to it. Eventually I managed to pin down a potential query causing this by caughting it red handed.

Increase lock usage is usually tied to a long-running query or a query that behaves irrationally. It may happen in some PSQL versions and PSQL versions have bugs, though this is rare.

I had the same issue with Hint: You might need to increase max_pred_locks_per_transaction. and I had already increased max_pred_locks_per_transaction to 2048, a ridiculously high value.

How I tracked the underlying issue down:

  1. Monitor PostgreSQL process memory. I monitored the Docker container where PSQL was running using Datadog. The issue was triggering somewhat randomly and I could not find a way to monitor per connection or per query lock and memory usage. Especially, in this case, as the problematic query pretty much brought the whole database down.

enter image description here

  1. Monitor active queries using pg_activity. You can do this by hand from any PSQL IDE or psql cli prompt, but pg_activity makes it much easier.

enter image description here

After a lot of manual monitoring, I managed to pin down the query that caused exceed lock, and therefore memory usage, increase.

  1. Fix the query

In my case, the solution was to get rid of the query in the first place. Other solutions you can do

  • If this application side query, split it to several query and commit batches. Make sure your application keeps the transaction open only for a short while and commits after updating hundreds or thousands of rows. Do not let a single transaction to touch multiple rows.

  • Re-engine the query e.g. to use materialised views

Improve this answer

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.