Re: slow query : very simple delete, 100% cpu, nearly no disk activity

On Mon, Sep 7, 2009 at 5:05 AM, Vincent de Phily
<vincent(dot)dephily(at)mobile-devices(dot)fr> wrote:
> On Monday 07 September 2009 03:25:23 Tom Lane wrote:
>> Vincent de Phily <vincent(dot)dephily(at)mobile-devices(dot)fr> writes:
>> > I've been running this simple delete since yesterday afternoon :
>> >> db=# explain delete from message where datetime < '2009-03-03';
>> >> Seq Scan on message  (cost=0.00..34131.95 rows=133158 width=6)
>> >> Filter: (datetime < '2009-03-03 00:00:00'::timestamp without time zone)
>> >
>> > There is no index on that column, so a seqscan is fine. But it really
>> > shouldn't take > 15 hours to delete :
>>
>> 99% of the time, the reason a delete takes way longer than it seems like
>> it should is trigger firing time.  In particular, foreign key triggers
>> where you don't have an index on the referencing column.  Are there
>> any foreign keys linking to this table?
>
> Yes, but they look fine to me (?). Only one FK references the table; it's an
> internal reference :
>
>                                     Table "public.message"
>  Column   |            Type             |                      Modifiers
> -----------+-----------------------------+------------------------------------------------------
>  id        | integer                     | not null default
> nextval('message_id_seq'::regclass)
>  unitid    | integer                     | not null
>  userid    | integer                     |
>  refid     | integer                     |
> (...)
> Indexes:
>    "message_pkey" PRIMARY KEY, btree (id)
>    "message_unitid_fromto_status_idx" btree (unitid, fromto, status)
>    "message_userid_idx" btree (userid)
> Foreign-key constraints:
>    "message_refid_fkey" FOREIGN KEY (refid) REFERENCES message(id) ON UPDATE
> CASCADE ON DELETE CASCADE
>    "message_unitid_fkey" FOREIGN KEY (unitid) REFERENCES units(id) ON UPDATE
> CASCADE ON DELETE CASCADE
>    "message_userid_fkey" FOREIGN KEY (userid) REFERENCES users(id) ON UPDATE
> CASCADE ON DELETE CASCADE
>
>                                      Table "public.units"
>   Column    |            Type             |                     Modifiers
> -------------+-----------------------------+----------------------------------------------------
>  id          | integer                     | not null default
> nextval('units_id_seq'::regclass)
> (...)
> Indexes:
>    "units_pkey" PRIMARY KEY, btree (id)
>    "units_modid_ukey" UNIQUE, btree (modid)
>    "units_profileid_idx" btree (profileid)
> Foreign-key constraints:
>    "units_profileid_fkey" FOREIGN KEY (profileid) REFERENCES profiles(id) ON
> UPDATE CASCADE ON DELETE RESTRICT
>
>                                 Table "public.users"
>  Column  |         Type          |                     Modifiers
> ----------+-----------------------+----------------------------------------------------
>  id       | integer               | not null default
> nextval('users_id_seq'::regclass)
> (...)
> Indexes:
>    "users_pkey" PRIMARY KEY, btree (id)
>    "users_login_ukey" UNIQUE, btree (login)
>
>
> Table users has a handdull of rows, table units has around 40000. 43% of
> message.refid is NULL.
>
> The delete finished during the weekend (DELETE 184368). Nothing in the logs
> except the duration time (103113291.307 ms). I took a db dump before the
> delete finished, in order to be able to reproduce the issue (a 30min test
> shows me it is still slow).

I would try EXPLAIN ANALYZE DELETE ... with a query that is modified
so as to delete only a handful of rows. That will report the amount
of time spent in triggers vs. the main query, which will help you
assess whether your conclusion that the foreign keys are OK is
correct.

...Robert