pg.ddx.io pgsql-performance@postgresql.org mailing list archivehelp / color / mirror / Atom feed
Hash Join performance 5+ messages / 2 participants [nested] [flat]
* Hash Join performance @ 2009-03-13 21:15 Vamsidhar Thummala <vamsi@cs.duke.edu> 0 siblings, 1 reply; 5+ messages in thread From: Vamsidhar Thummala @ 2009-03-13 21:15 UTC (permalink / raw) To: pgsql-performance ^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: Hash Join performance @ 2009-03-13 21:34 Tom Lane <tgl@sss.pgh.pa.us> parent: Vamsidhar Thummala <vamsi@cs.duke.edu> 0 siblings, 1 reply; 5+ messages in thread From: Tom Lane @ 2009-03-13 21:34 UTC (permalink / raw) To: Vamsidhar Thummala <vamsi@cs.duke.edu>; +Cc: pgsql-performance Vamsidhar Thummala <vamsi@cs.duke.edu> writes: > 1) The actual time on Seq Scan on Lineitem shows that the first record is > fetched at time 0.022ms and the last record is fetched at 53.5s. Does it > mean the sequential scan is completed with-in first 53.4s (absolute time)? No, it means that we spent a total of 53.5 seconds executing that plan node and its children. There's no direct way to determine how that was interleaved with the execution of a peer plan node. In the particular case here, since that seqscan is the outer child of a hash join, you can infer that all the time charged to the inner child (the Hash node and its children) happened first, while we were building the hashtable, which is then probed for each row of the outer relation. > 2) Why is the Hash Join (top most) so slow? Doesn't look that bad to me. The net time charged to the HashJoin node is 186107.210 - 53597.555 - 112439.592 = 20070.063 msec. In addition it would be reasonable to count the hashtable build time, which evidently is 112439.592 - 111855.510 = 584.082 msec. So the hashtable build took about 10 msec/row, in addition to the data fetching; and then the actual join spent about 3 microsec per outer row, again exclusive of obtaining those rows. The table build seems a bit slow, maybe, but I don't see a problem with the join speed. regards, tom lane ^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: Hash Join performance @ 2009-03-13 22:11 Vamsidhar Thummala <vamsi@cs.duke.edu> parent: Tom Lane <tgl@sss.pgh.pa.us> 0 siblings, 1 reply; 5+ messages in thread From: Vamsidhar Thummala @ 2009-03-13 22:11 UTC (permalink / raw) To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance Thanks for such quick response. On Fri, Mar 13, 2009 at 5:34 PM, Tom Lane wrote: > > 2) Why is the Hash Join (top most) so slow? > > Doesn't look that bad to me. The net time charged to the HashJoin node > is 186107.210 - 53597.555 - 112439.592 = 20070.063 msec. In addition it > would be reasonable to count the hashtable build time, which evidently > is 112439.592 - 111855.510 = 584.082 msec. So the hashtable build took > about 10 msec/row, in addition to the data fetching; and then the actual > join spent about 3 microsec per outer row, again exclusive of obtaining > those rows. The table build seems a bit slow, maybe, but I don't see a > problem with the join speed. > I am wondering why are we subtracting the entire Seq Scan time of Lineitem from the total time to calculate the HashJoin time. Does the Hash probing start as soon as the first record of Lineitem is available, i.e., after 112439.592ms? Here is another plan I have for the same TPC-H 18 query with different configuration parameters (shared_buffers set to 400MB, just for experimental purposes) and HashJoin seems to take longer time (at least 155.58s based on above calculation): GroupAggregate (cost=905532.09..912092.04 rows=119707 width=57) (actual time=392705.160..392705.853 rows=57 loops=1) -> Sort (cost=905532.09..906082.74 rows=119707 width=57) (actual time=392705.116..392705.220 rows=399 loops=1) Sort Key: orders.o_totalprice, orders.o_orderdate, customer.c_name, customer.c_custkey, orders.o_orderkey -> Hash Join (cost=507550.05..877523.36 rows=119707 width=57) (actual time=72616.327..392703.675 rows=399 loops=1) Hash Cond: (public.lineitem.l_orderkey = orders.o_orderkey) -> Seq Scan on lineitem (cost=0.00..261655.05 rows=6000947 width=14) (actual time=0.027..178712.709 rows=6001215 loops=1) -> Hash (cost=506580.84..506580.84 rows=29921 width=51) (actual time=58421.050..58421.050 rows=57 loops=1) -> Hash Join (cost=416568.25..506580.84 rows=29921 width=51) (actual time=25208.925..58419.502 rows=57 loops=1) Hash Cond: (orders.o_custkey = customer.c_custkey) -> Merge IN Join (cost=405349.14..493081.88 rows=29921 width=29) (actual time=37.244..57646.024 rows=57 loops=1) Merge Cond: (orders.o_orderkey = "IN_subquery".l_orderkey) -> Index Scan using orders_pkey on orders (cost=0.00..79501.17 rows=1499952 width=25) (actual time=0.100..5379.828 rows=1496151 loops=1) -> Materialize (cost=405349.14..406004.72 rows=29921 width=4) (actual time=34.825..51619.816 rows=57 loops=1) -> GroupAggregate (cost=0.00..404639.71 rows=29921 width=14) (actual time=34.818..51619.488 rows=57 loops=1) Filter: (sum(l_quantity) > 300::numeric) -> Index Scan using fkey_lineitem_1 on lineitem (cost=0.00..348617.14 rows=6000947 width=14) (actual time=0.079..44140.117 rows=6001215 loops=1) -> Hash (cost=6803.60..6803.60 rows=149978 width=26) (actual time=640.980..640.980 rows=150000 loops=1) -> Seq Scan on customer (cost=0.00..6803.60 rows=149978 width=26) (actual time=0.021..510.993 rows=150000 loops=1) I re-ran the query multiple times to verify the accuracy of results. Regards, ~Vamsi ^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: Hash Join performance @ 2009-03-13 23:08 Tom Lane <tgl@sss.pgh.pa.us> parent: Vamsidhar Thummala <vamsi@cs.duke.edu> 0 siblings, 1 reply; 5+ messages in thread From: Tom Lane @ 2009-03-13 23:08 UTC (permalink / raw) To: Vamsidhar Thummala <vamsi@cs.duke.edu>; +Cc: pgsql-performance Vamsidhar Thummala <vamsi@cs.duke.edu> writes: > I am wondering why are we subtracting the entire Seq Scan time of Lineitem > from the total time to calculate the HashJoin time. Well, if you're trying to identify the speed of the join itself and not how long it takes to provide the input for it, that seems like a sensible calculation to make. > Here is another plan I have for the same TPC-H 18 query with different > configuration parameters (shared_buffers set to 400MB, just for experimental > purposes) and HashJoin seems to take longer time (at least 155.58s based on > above calculation): Yeah, that seems to work out to about 25us per row instead of 3us, which is a lot slower. Maybe the hash got split up into multiple batches ... what have you got work_mem set to? Try turning on log_temp_files and see if it records any temp files as getting created. regards, tom lane ^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: Hash Join performance @ 2009-03-14 02:10 Vamsidhar Thummala <vamsi@cs.duke.edu> parent: Tom Lane <tgl@sss.pgh.pa.us> 0 siblings, 0 replies; 5+ messages in thread From: Vamsidhar Thummala @ 2009-03-14 02:10 UTC (permalink / raw) To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance On Fri, Mar 13, 2009 at 7:08 PM, Tom Lane wrote: > Vamsidhar Thummala writes: > > I am wondering why are we subtracting the entire Seq Scan time of > Lineitem > > from the total time to calculate the HashJoin time. > > Well, if you're trying to identify the speed of the join itself and not > how long it takes to provide the input for it, that seems like a > sensible calculation to make. I am still not clear on this. I am thinking the output is produced in a pipelined fashion i.e., as soon as the record of outer child is read (sequentially here) and if HashJoin finds a match by probing the inner hash table (in memory), we have an output record. Please correct if I am wrong here. > > > > Here is another plan I have for the same TPC-H 18 query with different > > configuration parameters (shared_buffers set to 400MB, just for > experimental > > purposes) and HashJoin seems to take longer time (at least 155.58s based > on > > above calculation): > > Yeah, that seems to work out to about 25us per row instead of 3us, which > is a lot slower. Maybe the hash got split up into multiple batches ... > what have you got work_mem set to? Try turning on log_temp_files and > see if it records any temp files as getting created. Unfortunately, I am working with Postgres 8.2 which doesn't have log_temp_files. The work_mem is still at 1MB (all other parameters were kept constant apart from shared_buffers w.r.t previous configuration). The hash is build on 57 records (~20kb, customer row length is 179 bytes and orders row length is 104 bytes) produced by inner subplan and so I will be surprised if multiple batches are created. Thank you. Regards, -Vamsi ^ permalink raw reply [nested|flat] 5+ messages in thread
end of thread, other threads:[~2009-03-14 02:10 UTC | newest] Thread overview: 5+ messages (download: mbox mbox.gz follow: Atom feed) -- links below jump to the message on this page -- 2009-03-13 21:15 Hash Join performance Vamsidhar Thummala <vamsi@cs.duke.edu> 2009-03-13 21:34 ` Tom Lane <tgl@sss.pgh.pa.us> 2009-03-13 22:11 ` Vamsidhar Thummala <vamsi@cs.duke.edu> 2009-03-13 23:08 ` Tom Lane <tgl@sss.pgh.pa.us> 2009-03-14 02:10 ` Vamsidhar Thummala <vamsi@cs.duke.edu>
This inbox is served by DDX for PostgreSQL; see mirroring instructions for how to clone and mirror all data and code used for this inbox