On Wed, Feb 09, 2005 at 02:37:39PM -0700, Ed L. wrote: > Very helpful, thanks. So time spent in that node & its children > = first number of "actual time" * loops? That seems consistent > with the fact that reindexing the index led to the huge speedup. > If the second number of the "actual time" part means time > elapsed in this node and its children until the last row was > returned, why does it say "actual time=4.63..4.63" instead of > "actual time=4.63..4767.62"? Would it say that if there had > been 1 row returned instead of none? The meaning of the times is (IIRC) derived from the numbers used in the planning. The first number is "time to first result", the second number is "time to last result". So if you're doing a "LIMIT 1" query, only the first number is relevent. The purpose of the explain output is to determine where the bottlenecks are and as such each node only counts time spent in it and all its subnodes. So for example a Sort node has a really high start time (because all subnodes must complete before sorting can complete) but the end time is shortly after because it only needs to pump out tuples. The complication comes because nodes can be executed in their entirety repeatedly, especially with nested joins, the inner loop is repeatedly executed with different parameters. I was one of the major contributers of this feature originally and there was discussion about how to represent this. I think the rationale is that the figures should not appear radically different just because a Node is reexecuted a lot, so you get an extra result "loops" and the numbers look like a single index scan. If you look at the numbers the planner uses, it follows the same pattern. In general, the EXPLAIN ANALYZE output follows the planner output as close as possible. If you look at the original query posted, it showed an Index Scan costing 4.63..4.63 which means the index scan is taking (on average) 4.63ms to return 1 row! If it displayed as 4000 or something it would be a lot less clear what was going on. Hope this helps, -- Martijn van Oosterhout <kleptog@xxxxxxxxx> http://svana.org/kleptog/ > Patent. n. Genius is 5% inspiration and 95% perspiration. A patent is a > tool for doing 5% of the work and then sitting around waiting for someone > else to do the other 95% so you can sue them.
Attachment:
pgpEq67qsbU0g.pgp
Description: PGP signature
