Poor performance with ON DELETE CASCADE

Conal <Conal.Tuohy@gmail.com> writes:

I have a database schema which has a "central" table with several
others depending on it. The dependent tables all have foreign key
constraints with ON DELETE CASCADE so that I can remove tuples from
the "central" table and have the dependent rows removed automatically.
This all works, but it's very slow, and I can't see why. The dependent
tables are all indexed by this foreign key, so the deletions should be
very fast.

Did you recently add the required indexes? Existing releases of
Postgres cache query plans for FK queries for the life of a session,
so it seems barely possible that you are just working with a stale
plan. Another possibility is that you need to ANALYZE the tables
involved so that the planner knows what it's dealing with.

Unfortunately EXPLAIN doesn't provide any information about the
details of how it executes the cascading deletion; there's no query
plan for this, so I can't see why it is taking so long. Is it possible
to obtain a query plan for these "cascaded" delete queries?

If you have the log message level cranked up high enough when the FK
trigger is first fired during a session, it'll log the actual FK query,
and then you can use PREPARE and EXPLAIN EXECUTE to see how it gets
planned. (You need to take that route because it'll be a parameterized
query --- do NOT just plug in some constants and assume you'll get the
same plan.)

regards, tom lane

On Sep 27, 4:27 am, t...@sss.pgh.pa.us (Tom Lane) wrote:

Conal <Conal.Tu...@gmail.com> writes:

I have a database schema which has a "central" table with several
others depending on it. The dependent tables all have foreign key
constraints with ON DELETE CASCADE so that I can remove tuples from
the "central" table and have the dependent rows removed automatically.
This all works, but it's very slow, and I can't see why. The dependent
tables are all indexed by this foreign key, so the deletions should be
very fast.

Did you recently add the required indexes? Existing releases of
Postgres cache query plans for FK queries for the life of a session,
so it seems barely possible that you are just working with a stale
plan. Another possibility is that you need to ANALYZE the tables
involved so that the planner knows what it's dealing with.

No I have restarted postgresql, vacuumed and analyzed, and nothing has
helped.

Unfortunately EXPLAIN doesn't provide any information about the
details of how it executes the cascading deletion; there's no query
plan for this, so I can't see why it is taking so long. Is it possible
to obtain a query plan for these "cascaded" delete queries?

If you have the log message level cranked up high enough when the FK
trigger is first fired during a session, it'll log the actual FK query,
and then you can use PREPARE and EXPLAIN EXECUTE to see how it gets
planned. (You need to take that route because it'll be a parameterized
query --- do NOT just plug in some constants and assume you'll get the
same plan.)

Thanks Tom, but this doesn't seem to be the case. I have cranked up
log_min_messages to debug5 level, and i get a lot of messages, but the
cascaded deletes are not shown in the log at all. Here is a snippet of
the log showing the first occurrence of "DELETE" onwards:

2007-10-04 17:16:55 NZDT LOG: 00000: statement: PREPARE S_9 AS DELETE
FROM topic_map_object WHERE uid=$1
2007-10-04 17:16:55 NZDT LOCATION: exec_parse_message, postgres.c:
1153
2007-10-04 17:16:55 NZDT DEBUG: 00000: StartTransactionCommand
2007-10-04 17:16:55 NZDT LOCATION: start_xact_command, postgres.c:
1996
2007-10-04 17:16:55 NZDT LOG: 00000: statement: <BIND>
2007-10-04 17:16:55 NZDT LOCATION: exec_bind_message, postgres.c:1454
2007-10-04 17:16:55 NZDT LOG: 00000: statement: EXECUTE <unnamed>
[PREPARE: DELETE FROM topic_map_object WHERE uid=$1]
2007-10-04 17:16:55 NZDT LOCATION: exec_execute_message, postgres.c:
1733
2007-10-04 17:16:55 NZDT DEBUG: 00000: ProcessQuery
2007-10-04 17:16:55 NZDT LOCATION: ProcessQuery, pquery.c:128
2007-10-04 17:16:56 NZDT DEBUG: 00000: CommitTransactionCommand
2007-10-04 17:16:56 NZDT LOCATION: finish_xact_command, postgres.c:
2019
2007-10-04 17:16:56 NZDT DEBUG: 00000: StartTransactionCommand
2007-10-04 17:16:56 NZDT LOCATION: start_xact_command, postgres.c:
1996
2007-10-04 17:16:56 NZDT LOG: 00000: statement: <BIND>
2007-10-04 17:16:56 NZDT LOCATION: exec_bind_message, postgres.c:1454
2007-10-04 17:16:56 NZDT LOG: 00000: statement: EXECUTE <unnamed>
[PREPARE: DELETE FROM topic_map_object WHERE uid=$1]
2007-10-04 17:16:56 NZDT LOCATION: exec_execute_message, postgres.c:
1733
2007-10-04 17:16:56 NZDT DEBUG: 00000: ProcessQuery
2007-10-04 17:16:56 NZDT LOCATION: ProcessQuery, pquery.c:128
2007-10-04 17:16:58 NZDT DEBUG: 00000: CommitTransactionCommand
2007-10-04 17:16:58 NZDT LOCATION: finish_xact_command, postgres.c:
2019
2007-10-04 17:16:58 NZDT DEBUG: 00000: StartTransactionCommand
2007-10-04 17:16:58 NZDT LOCATION: start_xact_command, postgres.c:
1996
2007-10-04 17:16:58 NZDT LOG: 00000: statement: <BIND>
2007-10-04 17:16:58 NZDT LOCATION: exec_bind_message, postgres.c:1454
2007-10-04 17:16:58 NZDT LOG: 00000: statement: EXECUTE <unnamed>
[PREPARE: DELETE FROM topic_map_object WHERE uid=$1]
2007-10-04 17:16:58 NZDT LOCATION: exec_execute_message, postgres.c:
1733
2007-10-04 17:16:58 NZDT DEBUG: 00000: ProcessQuery
2007-10-04 17:16:58 NZDT LOCATION: ProcessQuery, pquery.c:128
2007-10-04 17:17:00 NZDT DEBUG: 00000: CommitTransactionCommand
2007-10-04 17:17:00 NZDT LOCATION: finish_xact_command, postgres.c:
2019

The client code is deleting a number of rows from the topic_map_object
table, one at a time.

Any ideas?