2

I had a problem with an index missing on a table and the only way I had to gather clues was this way:

BEGIN TRANSACTION;
-- OVER 100 DELETES
COMMIT;

In DBeaver, I selected only the first line and the subsequent deletes, executed that. Then, selected the commit line, executed that and waited until I felt that this is taking too long.

Then DBeaver gave me this message, when I canceled the transaction:

SQL Error [57014]: ERROR: canceling statement due to user request
  Where: SQL statement "SELECT 1 FROM ONLY "schema"."table" x WHERE $1 OPERATOR(pg_catalog.=) "id_model" AND $2 OPERATOR(pg_catalog.=) "id_property1" AND $3 OPERATOR(pg_catalog.=) "id_property2" FOR KEY SHARE OF x"

id_model is the WHERE clause for all the DELETEs in question. The query mentioned in the message is definitely not code written by me, anywhere in any function/procedure/trigger I can think of.

I took from this that a missing index on table with columns id_property1 and id_property2 was the problem, and apparently it was.

Are there any logs explaining what is happening "under the hood" when the server is processing several statements queued in the transaction where I could have more easily found that statement?

There are several delete foreign key constraints configured in the model, so I guess when indexes are missing, the server is taking a while to find the correct way around?

2
  • 1
    That is not a message, it is a nested SQL statement executed by a trigger function that implements a foreign key constraint. It would be interesting to know what exactly the message looked like. Nov 2, 2023 at 7:49
  • I posted the complete message. What I'm lookin for is a way to spot these statements somewhere in logs so I don't have to do it in an awkward way through DBeaver or any other DB tool. Nov 2, 2023 at 13:33

2 Answers 2

1

The strange statement you see was run from a trigger that implements foreign key constraints in PostgreSQL.

There are two ways to get data about these statements:

  1. If you set shared_preload_libraries = 'pg_stat_statements' and pg_stat_statements.track = all and restart PostgreSQL, pg_stat_statements will collect statistics about these "hidden" statements as well. You can view these data with the pg_stat_statements view provided by the extension of the same name.

  2. If you set shared_preload_libraries = 'auto_explain' and auto_explain.log_nested_statements = on and auto_explain.log_min_duration = '500ms' and restart PostgreSQL, you will get the execution plan of all statements that run for more than half a second logged, including these "hidden" statements.

1

Can't comment on DBeaver. It's a generic client, not optimized for Postgres. I have seen occasional complaints about frictions here on dba.SE and SO.

It's the responsibility of the client to show messages (ERROR, WARNING, NOTICE, ...) for each command. Not sure how DBeaver handles that. Maybe you have to execute each DELETE separately (still staying within the same transaction) to see all messages.

You can tweak the Postgres settings client_min_messages and log_min_messages to adjust the message levels that are sent to the client and DB log respectively.

But the SELECT statement you display is not a "message". It's a plain SQL command. Either you or your client must have issued it. The uncommonly explicit syntax (OPERATOR(pg_catalog.=) instead of just =) indicates machine-generated code. Maybe it was part of a bigger message displaying what the cancelled query had been waiting for. If a missing index causes one particular statement to dominate execution time, chances to catch that red-handed are good when interrupting execution. It's still coincidence.

Also, while a qualifying index can speed up SQL commands (a lot), a "missing" index is not an error condition (or condition for any message level). You won't get a message from Postgres. Creating indexes happens at the user's discretion. Creating just the right ones is one of the main tasks of the DB architect / administrator. There are countless subtleties to this. Target columns of FK constraints are indexed by definition (a PK or UNIQUE constraint is required). Source columns of FK constraints are prime candidates for a plain B-tree index. Or, as the manual puts it:

A foreign key must reference columns that either are a primary key or form a unique constraint. This means that the referenced columns always have an index (the one underlying the primary key or unique constraint); so checks on whether a referencing row has a match will be efficient. Since a DELETE of a row from the referenced table or an UPDATE of a referenced column will require a scan of the referencing table for rows matching the old value, it is often a good idea to index the referencing columns too. Because this is not always needed, and there are many choices available on how to index, declaration of a foreign key constraint does not automatically create an index on the referencing columns.

Monitor slow queries to get indication (not proof) for the most pressing missing optimizations. There are various ways, most prominently: set log_min_duration_statement or possibly log_min_duration_sample and friends, and then study the generated DB logs.

And/or use EXPLAIN (and all its features) to diagnose suspicious execution plans.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

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