Thread: Poor performance with ON DELETE CASCADE

Poor performance with ON DELETE CASCADE

From
Conal
Date:
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.

I have tried to use EXPLAIN and ANALYZE, and this tells me that the
deletion from the central table is not a problem, but that the
cascading deletions are very slow. e.g.

   Trigger for constraint topic_map_object_parent_uid_fkey:
time=93063.837 calls=115

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?


Re: Poor performance with ON DELETE CASCADE

From
Tom Lane
Date:
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

Re: Poor performance with ON DELETE CASCADE

From
Conal
Date:
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?