Re: EXPLAIN ANALYZE total runtime != walltime

Tom Lane wrote:
> Jon Lapham <lapham@jandr.org> writes:
>
>>I have been using the EXPLAIN ANALYZE command to debug some performance
>>bottlenecks in my database.  In doing so, I have found an oddity (to me
>>anyway).  The "19ms" total runtime reported below actually takes 25
>>seconds on my computer (no other CPU intensive processes running).
>
>
> I think that the foreign-key-checking triggers that are fired by the
> DELETE will execute at end of statement, which is outside the time
> window measured and reported by EXPLAIN ANALYZE.  Better look at your FK
> setup.  The usual culprit for slow DELETE is an unindexed referencing
> column in another table, but it could also be that the referencing
> column is not the same datatype as the key column.

Yup, you are right, I have another table that has a FK reference to the
table I am deleting.  I'll look into improving performance by indexing
the referencing column.

Is there some way to get at something equvalent to UNIX's "time" command
for benchmarking purposes?

Was there something in the output of EXPLAIN ANALYZE VERBOSE that let
you to conclude that the timing difference was due to a FK referencing
this table?

I want to learn how you guys figure this stuff out...

Should something be mentioned in the docs about foreign-key-checking
triggers not being included in the total runtime of EXPLAIN ANALYZE?  I
just checked (the 7.4.2 docs, anyway) and there is no mention of this.

Thanks for the help!
Jon

--
-**-*-*---*-*---*-*---*-----*-*-----*---*-*---*-----*-----*-*-----*---
  Jon Lapham  <lapham@jandr.org>                Rio de Janeiro, Brasil
  Personal: http://www.jandr.org/
***-*--*----*-------*------------*--------------------*---------------