David Teran <david.teran@cluster9.com> writes:
> [ query plan ]
I got a little distracted by the bizarre actual-time values shown for
some of the query steps:
> -> Merge Join (cost=2451266.53..2655338.83 rows=13604393 width=8)
> (actual time=82899.466..-2371037.726 rows=2091599 loops=1)
> -> Sort (cost=2451169.10..2483246.47 rows=12830947 width=8)
> (actual time=82891.076..-529619.213 rows=4187378 loops=1)
> -> Hash IN Join (cost=507.32..439065.37 rows=12830947
> width=8) (actual time=61.943..1874640.807 rows=4187378 loops=1)
The hash-join total time is obviously wrong seeing that the total
runtime is only about 100000 msec, and the negative values for the other
two are even more obviously wrong.
I recall that we saw similar symptoms once before, and I thought we'd
fixed it, but I didn't find any relevant mentions in the CVS logs.
What version are you running, exactly? Could you repeat the EXPLAIN
with client_min_messages set to 'debug2', and see if you see any
messages about InstrStartTimer or InstrStopNode?
regards, tom lane
