John Arbash Meinel <john@arbash-meinel.com> writes:
>> " -> Sort (cost=59478.03..59909.58 rows=172618 width=75) (actual
>> time=46844.000..46985.000 rows=159960 loops=1)"
>>
>> " Sort Key: a.locationid"
>>
> This sort actually isn't taking very long. It starts at 46800 and runs
> until 47000 so it takes < 1 second.
>> " -> Merge Right Join (cost=0.00..39739.84 rows=172618
>> width=75) (actual time=250.000..43657.000 rows=176431 loops=1)"
You're not reading it quite right. The first "actual" number is the
time at which the first result row was delivered, which for a sort is
after the completion of (the bulk of) the sorting work. What you
really need to look at is the difference between the completion times
of the node and its immediate input(s). In this case I'd blame the
sort for 46985.000 - 43657.000 msec.
Come to think of it, though, you should not be putting a whole lot of
trust in EXPLAIN ANALYZE numbers taken on Windows, because they are
based on gettimeofday which has absolutely awful resolution on that
platform. (There's a workaround for this in our CVS, but it's not in
8.0.*.) I think we can still conclude that the indexscan on
tblassociate is most of the cost, but I wouldn't venture to say that
it's exactly such-and-such percent.
regards, tom lane
