pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
10+ messages / 4 participants
[nested] [flat]

* 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
@ 2007-09-11 16:57  El-Lotso <el.lotso@gmail.com>
  0 siblings, 1 reply; 10+ messages in thread

From: El-Lotso @ 2007-09-11 16:57 UTC (permalink / raw)
  To: pgsql-performance; +Cc: el.lotso@gmail.com

Hi,

appreciate if someone can have some pointers for this. 

PG.8.2.4 1.4G centrino(s/core) 1.5GB ram/5400rpm laptop HD

3 mail tables which has already been selected "out" into separate tables
(useing create table foo as select * from foo_main where x=y)

These test tables containing only a very small subset of the main data's
table (max 1k to 10k rows vs 1.5mill to 7mill rows in the main table)

table definitions and actual query are attached. (names has been altered
to protect the innocent)

I've played around with some tweaking of the postgres.conf setting per
guidance from jdavis (in irc) w/o much(any) improvement. Also tried
re-writing the queries to NOT use subselects (per depesz in irc also)
also yielded nothing spectacular.

The only thing I noticed was that when the subqueries combine more than
3 tables, then PG will choke. If only at 3 joined tables per subquery,
the results come out fast, even for 6K rows.

but if the subqueries (these subqueries by itself, executes fast and
returns results in 1 to 10secs) were done independently and then placed
into a temp table, and then finally joined together using a query such
as

select a.a,b.b,c.c from a inner join b on (x = x) left outer join c on(x
= y)

then it would also be fast

work_mem = 8MB / 32MB /128MB (32 MB default in my setup)
effective_Cache_size = 128MB/500MB (500 default)
shared_buffers = 200MB
geqo_threshold = 5 (default 12)
geqo_effort = 2 (default 5)
ramdom_page_cose = 8.0 (default 4)
maintenance_work_mem = 64MB
join_collapse_limit = 1/8/15  (8 default)
from_collapse_limit = 1/8/15 (8 default)
enable_nestloop = f (on by default)

based on current performance, even with a small number of rows in the
individual tables (max 20k), I can't even get a result out in 2 hours.
(> 3 tables joined per subquery) which is making me re-think of PG's
useful-ness.



BTW, I also tried 8.2.4 CVS_STABLE Branch

Attachments:

PG_long_running_query.txt (text/plain, 12.0K) download Table "test_db.d" Column | Type | Modifiers -------------------------+-----------------------------+----------- id | character varying(12) | not null record_update_date_time | timestamp without time zone | code | character varying(5) | Indexes: "d_pkey" PRIMARY KEY, btree (id) "idx_d_upd" btree (record_update_date_time) Table "test_db.trh" Column | Type | Modifiers -------------------------+-----------------------------+----------- unique_id | character varying(35) | not null id | character varying(12) | hid | smallint | index_1 | character varying(3) | index_2 | character varying(3) | record_update_date_time | timestamp without time zone | start_timestamp | timestamp without time zone | phase_id | smallint | ttype | smallint | pber_2 | double precision | pber_3 | double precision | pber_4 | double precision | Indexes: "trh_pkey" PRIMARY KEY, btree (unique_id) "idx_trh_id" btree (id) Table "test_db.ts" Column | Type | Modifiers -------------------------+-----------------------------+----------- unique_id | character varying(50) | not null id | character varying(12) | record_update_date_time | timestamp without time zone | start_timestamp | timestamp without time zone | ttype | smallint | seq_time | timestamp without time zone | seq_date | timestamp without time zone | code | character varying(5) | Indexes: "ts_pkey" PRIMARY KEY, btree (unique_id) "idx_ts_id" btree (id) Table "test_db.trd" Column | Type | Modifiers -------------------------+-----------------------------+----------- unique_id | character varying(50) | not null id | character varying(12) | index_1 | character varying(3) | index_2 | character varying(3) | start_timestamp | timestamp without time zone | record_update_date_time | timestamp without time zone | phase_id | smallint | ttype | smallint | fval_2 | smallint | fval_3 | smallint | fval_4 | smallint | Indexes: "trd_pkey" PRIMARY KEY, btree (unique_id) "idx_td_id" btree (id) explain analyse SELECT JOIN1.ID, JOIN1.HID, JOIN1.START_TIMESTAMP, JOIN1.PHASE_ID, JOIN1.CODE, JOIN1.LOG_PBER_2, JOIN2.LOG_PBER_3, JOIN3.LOG_PBER_4 FROM ( SELECT TRH.ID, TRH.HID, TRH.START_TIMESTAMP, TRH.PHASE_ID, TS.SEQ_DATE, TS.SEQ_TIME, TRH.TTYPE, D.CODE, CASE WHEN PBER_2 = 0 THEN 0 ELSE LOG(TRH.PBER_2) END AS LOG_PBER_2 FROM TRH INNER JOIN D ON D.ID = TRH.ID INNER JOIN TS ON TS.ID = TRH.ID AND TS.TTYPE = TRH.TTYPE AND TS.START_TIMESTAMP = TRH.START_TIMESTAMP /* inner join trd on trd.id = trh.id and trd.ttype = trh.ttype and trd.start_timestamp = trh.start_timestamp */ WHERE D.RECORD_UPDATE_DATE_TIME BETWEEN '8/20/2007' AND '9/8/2007' AND TRH.TTYPE IN (35,75,703,740,764) AND D.CODE IN ('HUA69') ) JOIN1 LEFT OUTER JOIN ( SELECT TRH.ID, TRH.HID, TRH.START_TIMESTAMP, TRH.PHASE_ID, TS.SEQ_DATE, TS.SEQ_TIME, TRH.TTYPE, D.CODE, CASE WHEN PBER_3 = 0 THEN 0 ELSE LOG(TRH.PBER_3) END AS LOG_PBER_3 FROM TRH INNER JOIN D ON D.ID = TRH.ID INNER JOIN TS ON TS.ID = TRH.ID AND TS.TTYPE = TRH.TTYPE AND TS.START_TIMESTAMP = TRH.START_TIMESTAMP /* inner join trd on trd.id = trh.id and trd.ttype = trh.ttype and trd.start_timestamp = trh.start_timestamp */ WHERE D.RECORD_UPDATE_DATE_TIME BETWEEN '8/20/2007' AND '9/8/2007' AND TRH.TTYPE IN (69,178,198,704,757,741,765) AND D.CODE IN ('HUA69') ) JOIN2 ON JOIN2.ID = JOIN1.ID AND JOIN2.HID = JOIN1.HID AND JOIN2.SEQ_TIME = JOIN1.SEQ_TIME AND JOIN2.SEQ_DATE = JOIN1.SEQ_DATE LEFT OUTER JOIN (SELECT TRH.ID, TRH.HID, TRH.START_TIMESTAMP, TRH.PHASE_ID, TS.SEQ_DATE, TS.SEQ_TIME, TRH.TTYPE, D.CODE, CASE WHEN PBER_4 = 0 THEN 0 ELSE LOG(TRH.PBER_4) END AS LOG_PBER_4 FROM TRH INNER JOIN D ON D.ID = TRH.ID INNER JOIN TS ON TS.ID = TRH.ID AND TS.TTYPE = TRH.TTYPE AND TS.START_TIMESTAMP = TRH.START_TIMESTAMP /* inner join trd on trd.id = trh.id and trd.ttype = trh.ttype and trd.start_timestamp = trh.start_timestamp */ WHERE D.RECORD_UPDATE_DATE_TIME BETWEEN '8/20/2007' AND '9/8/2007' AND TRH.TTYPE IN (177,197,705,742,758,766) AND D.CODE IN ('HUA69') ) JOIN3 ON JOIN3.ID = JOIN1.ID AND JOIN3.HID = JOIN1.HID AND JOIN3.SEQ_TIME = JOIN1.SEQ_TIME AND JOIN3.SEQ_DATE = JOIN1.SEQ_DATE =========================2.5k results w/ 3 tables joined per subquery=============================== Hash Left Join (cost=4673.17..6517.48 rows=3 width=59) (actual time=204.802..288.454 rows=2552 loops=1) Hash Cond: (((trh.id)::text = (join2.id)::text) AND (trh.hid = join2.hid) AND (ts.seq_time = join2.seq_time) AND (ts.seq_date = join2.seq_date)) -> Hash Left Join (cost=2470.15..4314.39 rows=3 width=67) (actual time=111.784..183.319 rows=2552 loops=1) Hash Cond: (((trh.id)::text = (join3.id)::text) AND (trh.hid = join3.hid) AND (ts.seq_time = join3.seq_time) AND (ts.seq_date = join3.seq_date)) -> Hash Join (cost=299.32..2143.51 rows=3 width=59) (actual time=16.166..76.762 rows=2552 loops=1) Hash Cond: (((trh.id)::text = (d.id)::text) AND (trh.ttype = ts.ttype) AND (trh.start_timestamp = ts.start_timestamp)) -> Seq Scan on trh (cost=0.00..1742.67 rows=9021 width=36) (actual time=0.489..40.565 rows=8888 loops=1) Filter: (ttype = ANY ('{35,75,703,740,764}'::integer[])) -> Hash (cost=284.78..284.78 rows=831 width=63) (actual time=15.620..15.620 rows=969 loops=1) -> Hash Join (cost=37.86..284.78 rows=831 width=63) (actual time=1.332..13.315 rows=969 loops=1) Hash Cond: ((ts.id)::text = (d.id)::text) -> Seq Scan on ts (cost=0.00..226.44 rows=3244 width=40) (actual time=0.117..6.091 rows=3244 loops=1) -> Hash (cost=35.56..35.56 rows=184 width=23) (actual time=1.195..1.195 rows=186 loops=1) -> Seq Scan on d (cost=0.00..35.56 rows=184 width=23) (actual time=0.479..0.854 rows=186 loops=1) Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA69'::text)) -> Hash (cost=2170.77..2170.77 rows=3 width=42) (actual time=95.550..95.550 rows=2488 loops=1) -> Subquery Scan join3 (cost=299.32..2170.77 rows=3 width=42) (actual time=15.951..89.594 rows=2488 loops=1) -> Hash Join (cost=299.32..2170.74 rows=3 width=61) (actual time=15.946..83.598 rows=2488 loops=1) Hash Cond: (((trh.id)::text = (d.id)::text) AND (trh.ttype = ts.ttype) AND (trh.start_timestamp = ts.start_timestamp)) -> Seq Scan on trh (cost=0.00..1775.26 rows=8543 width=36) (actual time=0.416..44.637 rows=8624 loops=1) Filter: (ttype = ANY ('{177,197,705,742,758,766}'::integer[])) -> Hash (cost=284.78..284.78 rows=831 width=63) (actual time=15.472..15.472 rows=969 loops=1) -> Hash Join (cost=37.86..284.78 rows=831 width=63) (actual time=1.311..13.160 rows=969 loops=1) Hash Cond: ((ts.id)::text = (d.id)::text) -> Seq Scan on ts (cost=0.00..226.44 rows=3244 width=40) (actual time=0.108..5.779 rows=3244 loops=1) -> Hash (cost=35.56..35.56 rows=184 width=23) (actual time=1.180..1.180 rows=186 loops=1) -> Seq Scan on d (cost=0.00..35.56 rows=184 width=23) (actual time=0.470..0.850 rows=186 loops=1) Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA69'::text)) -> Hash (cost=2202.96..2202.96 rows=3 width=42) (actual time=92.933..92.933 rows=2704 loops=1) -> Subquery Scan join2 (cost=299.32..2202.96 rows=3 width=42) (actual time=16.333..86.181 rows=2704 loops=1) -> Hash Join (cost=299.32..2202.93 rows=3 width=61) (actual time=16.329..79.362 rows=2704 loops=1) Hash Cond: (((trh.id)::text = (d.id)::text) AND (trh.ttype = ts.ttype) AND (trh.start_timestamp = ts.start_timestamp)) -> Seq Scan on trh (cost=0.00..1807.85 rows=8508 width=36) (actual time=0.438..41.233 rows=8560 loops=1) Filter: (ttype = ANY ('{69,178,198,704,757,741,765}'::integer[])) -> Hash (cost=284.78..284.78 rows=831 width=63) (actual time=15.840..15.840 rows=969 loops=1) -> Hash Join (cost=37.86..284.78 rows=831 width=63) (actual time=1.482..13.557 rows=969 loops=1) Hash Cond: ((ts.id)::text = (d.id)::text) -> Seq Scan on ts (cost=0.00..226.44 rows=3244 width=40) (actual time=0.113..6.124 rows=3244 loops=1) -> Hash (cost=35.56..35.56 rows=184 width=23) (actual time=1.346..1.346 rows=186 loops=1) -> Seq Scan on d (cost=0.00..35.56 rows=184 width=23) (actual time=0.621..0.997 rows=186 loops=1) Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA69'::text)) Total runtime: 291.763 ms =============================== If I were to un-comment the join to table trd, the PG will choke and not come out with results for up to 20+mins (for the above 2.5K results sets retrieved) For 6K results, 2 hours and it's still crunching. re-writing to NOT use subselects and also joining 4 tables will also choke explain analyse select d.id, d.code, trh.hid, trh.start_timestamp, trh.phase_id, log(trh.pber_2) as log_pber_2, log(trh2.pber_3) as log_pber_3,log(trh3.pber_4) as log_pber_4,trd.fval_2, trd2.fval_3,trd3.fval_4 from d inner join trd on trd.id = d.id inner join ( trh inner join ts on (trh.id = ts.id and ts.ttype = trh.ttype and ts.start_timestamp = trh.start_timestamp)) on (d.id = trh.id and trh.id = trd.id and trd.ttype = trh.ttype and trd.start_timestamp = trh.start_timestamp and TRH.TTYPE IN (35,75,703,740,764)) left join ( trh trh2 inner join ts ts2 on (trh2.id = ts2.id and ts2.ttype = trh2.ttype and ts2.start_timestamp = trh2.start_timestamp) inner join trd trd2 on trd2.id = trh2.id and trd2.ttype = trh2.ttype and trd2.start_timestamp = trh2.start_timestamp ) on (d.id = trh2.id and ts2.seq_date = ts.seq_date and ts2.seq_time = ts.seq_time and trh2.hid=trh.hid and TRH2.TTYPE IN (69,178,198,704,757,741,765)) left join ( trh trh3 inner join ts ts3 on (trh3.id = ts3.id and ts3.ttype = trh3.ttype and ts3.start_timestamp = trh3.start_timestamp) inner join trd trd3 on trd3.id = trh3.id and trd3.ttype = trh3.ttype and trd3.start_timestamp = trh3.start_timestamp ) on (d.id = trh3.id and ts3.seq_date = ts.seq_date and ts3.seq_time = ts.seq_time and trh3.hid=trh.hid and TRH3.TTYPE IN (177,197,705,742,758,766)) where d.code = 'HUA69'
^ permalink raw reply [nested|flat] 10+ messages in thread

* Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
@ 2007-09-11 17:02  El-Lotso <el.lotso@gmail.com>
  parent: El-Lotso <el.lotso@gmail.com>
  0 siblings, 1 reply; 10+ messages in thread

From: El-Lotso @ 2007-09-11 17:02 UTC (permalink / raw)
  To: pgsql-performance; +Cc: el.lotso@gmail.com; nikeow@yahoo.com

sorry.. I sent this as I was about to go to bed and the explain analyse
of the query w/ 4 tables joined per subquery came out.

So.. attaching it..

On Wed, 2007-09-12 at 00:57 +0800, El-Lotso wrote:
> Hi,
> 
> appreciate if someone can have some pointers for this. 
> 
> PG.8.2.4 1.4G centrino(s/core) 1.5GB ram/5400rpm laptop HD
> 
> 3 mail tables which has already been selected "out" into separate tables
> (useing create table foo as select * from foo_main where x=y)
> 
> These test tables containing only a very small subset of the main data's
> table (max 1k to 10k rows vs 1.5mill to 7mill rows in the main table)
> 
> table definitions and actual query are attached. (names has been altered
> to protect the innocent)
> 
> I've played around with some tweaking of the postgres.conf setting per
> guidance from jdavis (in irc) w/o much(any) improvement. Also tried
> re-writing the queries to NOT use subselects (per depesz in irc also)
> also yielded nothing spectacular.
> 
> The only thing I noticed was that when the subqueries combine more than
> 3 tables, then PG will choke. If only at 3 joined tables per subquery,
> the results come out fast, even for 6K rows.
> 
> but if the subqueries (these subqueries by itself, executes fast and
> returns results in 1 to 10secs) were done independently and then placed
> into a temp table, and then finally joined together using a query such
> as
> 
> select a.a,b.b,c.c from a inner join b on (x = x) left outer join c on(x
> = y)
> 
> then it would also be fast
> 
> work_mem = 8MB / 32MB /128MB (32 MB default in my setup)
> effective_Cache_size = 128MB/500MB (500 default)
> shared_buffers = 200MB
> geqo_threshold = 5 (default 12)
> geqo_effort = 2 (default 5)
> ramdom_page_cose = 8.0 (default 4)
> maintenance_work_mem = 64MB
> join_collapse_limit = 1/8/15  (8 default)
> from_collapse_limit = 1/8/15 (8 default)
> enable_nestloop = f (on by default)
> 
> based on current performance, even with a small number of rows in the
> individual tables (max 20k), I can't even get a result out in 2 hours.
> (> 3 tables joined per subquery) which is making me re-think of PG's
> useful-ness.
> 
> 
> 
> BTW, I also tried 8.2.4 CVS_STABLE Branch

Attachments:

PG_long_running_query.txt (text/plain, 19.0K) download Table "test_db.d" Column | Type | Modifiers -------------------------+-----------------------------+----------- id | character varying(12) | not null record_update_date_time | timestamp without time zone | code | character varying(5) | Indexes: "d_pkey" PRIMARY KEY, btree (id) "idx_d_upd" btree (record_update_date_time) Table "test_db.trh" Column | Type | Modifiers -------------------------+-----------------------------+----------- unique_id | character varying(35) | not null id | character varying(12) | hid | smallint | index_1 | character varying(3) | index_2 | character varying(3) | record_update_date_time | timestamp without time zone | start_timestamp | timestamp without time zone | phase_id | smallint | ttype | smallint | pber_2 | double precision | pber_3 | double precision | pber_4 | double precision | Indexes: "trh_pkey" PRIMARY KEY, btree (unique_id) "idx_trh_id" btree (id) Table "test_db.ts" Column | Type | Modifiers -------------------------+-----------------------------+----------- unique_id | character varying(50) | not null id | character varying(12) | record_update_date_time | timestamp without time zone | start_timestamp | timestamp without time zone | ttype | smallint | seq_time | timestamp without time zone | seq_date | timestamp without time zone | code | character varying(5) | Indexes: "ts_pkey" PRIMARY KEY, btree (unique_id) "idx_ts_id" btree (id) Table "test_db.trd" Column | Type | Modifiers -------------------------+-----------------------------+----------- unique_id | character varying(50) | not null id | character varying(12) | index_1 | character varying(3) | index_2 | character varying(3) | start_timestamp | timestamp without time zone | record_update_date_time | timestamp without time zone | phase_id | smallint | ttype | smallint | fval_2 | smallint | fval_3 | smallint | fval_4 | smallint | Indexes: "trd_pkey" PRIMARY KEY, btree (unique_id) "idx_td_id" btree (id) explain analyse SELECT JOIN1.ID, JOIN1.HID, JOIN1.START_TIMESTAMP, JOIN1.PHASE_ID, JOIN1.CODE, JOIN1.LOG_PBER_2, JOIN2.LOG_PBER_3, JOIN3.LOG_PBER_4 FROM ( SELECT TRH.ID, TRH.HID, TRH.START_TIMESTAMP, TRH.PHASE_ID, TS.SEQ_DATE, TS.SEQ_TIME, TRH.TTYPE, D.CODE, CASE WHEN PBER_2 = 0 THEN 0 ELSE LOG(TRH.PBER_2) END AS LOG_PBER_2 FROM TRH INNER JOIN D ON D.ID = TRH.ID INNER JOIN TS ON TS.ID = TRH.ID AND TS.TTYPE = TRH.TTYPE AND TS.START_TIMESTAMP = TRH.START_TIMESTAMP /* inner join trd on trd.id = trh.id and trd.ttype = trh.ttype and trd.start_timestamp = trh.start_timestamp */ WHERE D.RECORD_UPDATE_DATE_TIME BETWEEN '8/20/2007' AND '9/8/2007' AND TRH.TTYPE IN (35,75,703,740,764) AND D.CODE IN ('HUA69') ) JOIN1 LEFT OUTER JOIN ( SELECT TRH.ID, TRH.HID, TRH.START_TIMESTAMP, TRH.PHASE_ID, TS.SEQ_DATE, TS.SEQ_TIME, TRH.TTYPE, D.CODE, CASE WHEN PBER_3 = 0 THEN 0 ELSE LOG(TRH.PBER_3) END AS LOG_PBER_3 FROM TRH INNER JOIN D ON D.ID = TRH.ID INNER JOIN TS ON TS.ID = TRH.ID AND TS.TTYPE = TRH.TTYPE AND TS.START_TIMESTAMP = TRH.START_TIMESTAMP /* inner join trd on trd.id = trh.id and trd.ttype = trh.ttype and trd.start_timestamp = trh.start_timestamp */ WHERE D.RECORD_UPDATE_DATE_TIME BETWEEN '8/20/2007' AND '9/8/2007' AND TRH.TTYPE IN (69,178,198,704,757,741,765) AND D.CODE IN ('HUA69') ) JOIN2 ON JOIN2.ID = JOIN1.ID AND JOIN2.HID = JOIN1.HID AND JOIN2.SEQ_TIME = JOIN1.SEQ_TIME AND JOIN2.SEQ_DATE = JOIN1.SEQ_DATE LEFT OUTER JOIN (SELECT TRH.ID, TRH.HID, TRH.START_TIMESTAMP, TRH.PHASE_ID, TS.SEQ_DATE, TS.SEQ_TIME, TRH.TTYPE, D.CODE, CASE WHEN PBER_4 = 0 THEN 0 ELSE LOG(TRH.PBER_4) END AS LOG_PBER_4 FROM TRH INNER JOIN D ON D.ID = TRH.ID INNER JOIN TS ON TS.ID = TRH.ID AND TS.TTYPE = TRH.TTYPE AND TS.START_TIMESTAMP = TRH.START_TIMESTAMP /* inner join trd on trd.id = trh.id and trd.ttype = trh.ttype and trd.start_timestamp = trh.start_timestamp */ WHERE D.RECORD_UPDATE_DATE_TIME BETWEEN '8/20/2007' AND '9/8/2007' AND TRH.TTYPE IN (177,197,705,742,758,766) AND D.CODE IN ('HUA69') ) JOIN3 ON JOIN3.ID = JOIN1.ID AND JOIN3.HID = JOIN1.HID AND JOIN3.SEQ_TIME = JOIN1.SEQ_TIME AND JOIN3.SEQ_DATE = JOIN1.SEQ_DATE =========================2.5k results w/ 3 tables joined per subquery=============================== Hash Left Join (cost=4673.17..6517.48 rows=3 width=59) (actual time=204.802..288.454 rows=2552 loops=1) Hash Cond: (((trh.id)::text = (join2.id)::text) AND (trh.hid = join2.hid) AND (ts.seq_time = join2.seq_time) AND (ts.seq_date = join2.seq_date)) -> Hash Left Join (cost=2470.15..4314.39 rows=3 width=67) (actual time=111.784..183.319 rows=2552 loops=1) Hash Cond: (((trh.id)::text = (join3.id)::text) AND (trh.hid = join3.hid) AND (ts.seq_time = join3.seq_time) AND (ts.seq_date = join3.seq_date)) -> Hash Join (cost=299.32..2143.51 rows=3 width=59) (actual time=16.166..76.762 rows=2552 loops=1) Hash Cond: (((trh.id)::text = (d.id)::text) AND (trh.ttype = ts.ttype) AND (trh.start_timestamp = ts.start_timestamp)) -> Seq Scan on trh (cost=0.00..1742.67 rows=9021 width=36) (actual time=0.489..40.565 rows=8888 loops=1) Filter: (ttype = ANY ('{35,75,703,740,764}'::integer[])) -> Hash (cost=284.78..284.78 rows=831 width=63) (actual time=15.620..15.620 rows=969 loops=1) -> Hash Join (cost=37.86..284.78 rows=831 width=63) (actual time=1.332..13.315 rows=969 loops=1) Hash Cond: ((ts.id)::text = (d.id)::text) -> Seq Scan on ts (cost=0.00..226.44 rows=3244 width=40) (actual time=0.117..6.091 rows=3244 loops=1) -> Hash (cost=35.56..35.56 rows=184 width=23) (actual time=1.195..1.195 rows=186 loops=1) -> Seq Scan on d (cost=0.00..35.56 rows=184 width=23) (actual time=0.479..0.854 rows=186 loops=1) Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA69'::text)) -> Hash (cost=2170.77..2170.77 rows=3 width=42) (actual time=95.550..95.550 rows=2488 loops=1) -> Subquery Scan join3 (cost=299.32..2170.77 rows=3 width=42) (actual time=15.951..89.594 rows=2488 loops=1) -> Hash Join (cost=299.32..2170.74 rows=3 width=61) (actual time=15.946..83.598 rows=2488 loops=1) Hash Cond: (((trh.id)::text = (d.id)::text) AND (trh.ttype = ts.ttype) AND (trh.start_timestamp = ts.start_timestamp)) -> Seq Scan on trh (cost=0.00..1775.26 rows=8543 width=36) (actual time=0.416..44.637 rows=8624 loops=1) Filter: (ttype = ANY ('{177,197,705,742,758,766}'::integer[])) -> Hash (cost=284.78..284.78 rows=831 width=63) (actual time=15.472..15.472 rows=969 loops=1) -> Hash Join (cost=37.86..284.78 rows=831 width=63) (actual time=1.311..13.160 rows=969 loops=1) Hash Cond: ((ts.id)::text = (d.id)::text) -> Seq Scan on ts (cost=0.00..226.44 rows=3244 width=40) (actual time=0.108..5.779 rows=3244 loops=1) -> Hash (cost=35.56..35.56 rows=184 width=23) (actual time=1.180..1.180 rows=186 loops=1) -> Seq Scan on d (cost=0.00..35.56 rows=184 width=23) (actual time=0.470..0.850 rows=186 loops=1) Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA69'::text)) -> Hash (cost=2202.96..2202.96 rows=3 width=42) (actual time=92.933..92.933 rows=2704 loops=1) -> Subquery Scan join2 (cost=299.32..2202.96 rows=3 width=42) (actual time=16.333..86.181 rows=2704 loops=1) -> Hash Join (cost=299.32..2202.93 rows=3 width=61) (actual time=16.329..79.362 rows=2704 loops=1) Hash Cond: (((trh.id)::text = (d.id)::text) AND (trh.ttype = ts.ttype) AND (trh.start_timestamp = ts.start_timestamp)) -> Seq Scan on trh (cost=0.00..1807.85 rows=8508 width=36) (actual time=0.438..41.233 rows=8560 loops=1) Filter: (ttype = ANY ('{69,178,198,704,757,741,765}'::integer[])) -> Hash (cost=284.78..284.78 rows=831 width=63) (actual time=15.840..15.840 rows=969 loops=1) -> Hash Join (cost=37.86..284.78 rows=831 width=63) (actual time=1.482..13.557 rows=969 loops=1) Hash Cond: ((ts.id)::text = (d.id)::text) -> Seq Scan on ts (cost=0.00..226.44 rows=3244 width=40) (actual time=0.113..6.124 rows=3244 loops=1) -> Hash (cost=35.56..35.56 rows=184 width=23) (actual time=1.346..1.346 rows=186 loops=1) -> Seq Scan on d (cost=0.00..35.56 rows=184 width=23) (actual time=0.621..0.997 rows=186 loops=1) Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA69'::text)) Total runtime: 291.763 ms =============================== ============ SAME QUERY as ABOVE, but 4 tables joined per subquery -Uncommented the trd table join ====================== Nested Loop Left Join (cost=762.61..2002.16 rows=1 width=59) (actual time=46.998..2120307.759 rows=2552 loops=1) Join Filter: (((join2.id)::text = (test_db.trh.id)::text) AND (join2.hid = test_db.trh.hid) AND (join2.seq_time = test_db.ts.seq_time) AND (join2.seq_date = test_db.ts.seq_date)) -> Nested Loop Left Join (cost=508.41..1334.71 rows=1 width=67) (actual time=31.007..1058040.141 rows=2552 loops=1) Join Filter: (((join3.id)::text = (test_db.trh.id)::text) AND (join3.hid = test_db.trh.hid) AND (join3.seq_time = test_db.ts.seq_time) AND (join3.seq_date = test_db.ts.seq_date)) -> Nested Loop (cost=254.20..667.31 rows=1 width=59) (actual time=15.402..221.441 rows=2552 loops=1) Join Filter: ((test_db.trd.ttype = test_db.trh.ttype) AND (test_db.trd.start_timestamp = test_db.trh.start_timestamp)) -> Hash Join (cost=249.61..512.56 rows=1 width=87) (actual time=15.139..32.858 rows=969 loops=1) Hash Cond: (((test_db.ts.id)::text = (test_db.d.id)::text) AND (test_db.ts.start_timestamp = test_db.trd.start_timestamp) AND (test_db.ts.ttype = test_db.trd.ttype)) -> Seq Scan on ts (cost=0.00..226.44 rows=3244 width=40) (actual time=0.135..6.916 rows=3244 loops=1) -> Hash (cost=235.00..235.00 rows=835 width=47) (actual time=14.933..14.933 rows=1016 loops=1) -> Hash Join (cost=37.86..235.00 rows=835 width=47) (actual time=1.301..12.759 rows=1016 loops=1) Hash Cond: ((test_db.trd.id)::text = (test_db.d.id)::text) -> Seq Scan on trd (cost=0.00..176.57 rows=3257 width=24) (actual time=0.046..4.912 rows=3257 loops=1) -> Hash (cost=35.56..35.56 rows=184 width=23) (actual time=1.230..1.230 rows=186 loops=1) -> Seq Scan on d (cost=0.00..35.56 rows=184 width=23) (actual time=0.507..0.881 rows=186 loops=1) Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA69'::text)) -> Bitmap Heap Scan on trh (cost=4.59..154.00 rows=43 width=36) (actual time=0.041..0.146 rows=16 loops=969) Recheck Cond: ((test_db.d.id)::text = (test_db.trh.id)::text) Filter: (ttype = ANY ('{35,75,703,740,764}'::integer[])) -> Bitmap Index Scan on idx_trh_id (cost=0.00..4.59 rows=43 width=0) (actual time=0.030..0.030 rows=47 loops=969) Index Cond: ((test_db.d.id)::text = (test_db.trh.id)::text) -> Nested Loop (cost=254.20..667.37 rows=1 width=61) (actual time=1.529..402.739 rows=2488 loops=2552) Join Filter: ((test_db.trd.ttype = test_db.trh.ttype) AND (test_db.trd.start_timestamp = test_db.trh.start_timestamp)) -> Hash Join (cost=249.61..512.56 rows=1 width=87) (actual time=0.349..50.926 rows=969 loops=2552) Hash Cond: (((test_db.ts.id)::text = (test_db.d.id)::text) AND (test_db.ts.start_timestamp = test_db.trd.start_timestamp) AND (test_db.ts.ttype = test_db.trd.ttype)) -> Seq Scan on ts (cost=0.00..226.44 rows=3244 width=40) (actual time=0.336..23.042 rows=3244 loops=2552) -> Hash (cost=235.00..235.00 rows=835 width=47) (actual time=15.000..15.000 rows=1016 loops=1) -> Hash Join (cost=37.86..235.00 rows=835 width=47) (actual time=1.540..12.818 rows=1016 loops=1) Hash Cond: ((test_db.trd.id)::text = (test_db.d.id)::text) -> Seq Scan on trd (cost=0.00..176.57 rows=3257 width=24) (actual time=0.040..4.646 rows=3257 loops=1) -> Hash (cost=35.56..35.56 rows=184 width=23) (actual time=1.474..1.474 rows=186 loops=1) -> Seq Scan on d (cost=0.00..35.56 rows=184 width=23) (actual time=0.475..1.137 rows=186 loops=1) Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA69'::text)) -> Bitmap Heap Scan on trh (cost=4.59..154.05 rows=43 width=36) (actual time=0.098..0.260 rows=16 loops=2472888) Recheck Cond: ((test_db.d.id)::text = (test_db.trh.id)::text) Filter: (ttype = ANY ('{177,197,705,742,758,766}'::integer[])) -> Bitmap Index Scan on idx_trh_id (cost=0.00..4.59 rows=43 width=0) (actual time=0.058..0.058 rows=47 loops=2472888) Index Cond: ((test_db.d.id)::text = (test_db.trh.id)::text) -> Nested Loop (cost=254.20..667.42 rows=1 width=61) (actual time=0.801..403.268 rows=2704 loops=2552) Join Filter: ((test_db.trd.ttype = test_db.trh.ttype) AND (test_db.trd.start_timestamp = test_db.trh.start_timestamp)) -> Hash Join (cost=249.61..512.56 rows=1 width=87) (actual time=0.526..46.203 rows=969 loops=2552) Hash Cond: (((test_db.ts.id)::text = (test_db.d.id)::text) AND (test_db.ts.start_timestamp = test_db.trd.start_timestamp) AND (test_db.ts.ttype = test_db.trd.ttype)) -> Seq Scan on ts (cost=0.00..226.44 rows=3244 width=40) (actual time=0.511..20.517 rows=3244 loops=2552) -> Hash (cost=235.00..235.00 rows=835 width=47) (actual time=15.262..15.262 rows=1016 loops=1) -> Hash Join (cost=37.86..235.00 rows=835 width=47) (actual time=1.268..12.653 rows=1016 loops=1) Hash Cond: ((test_db.trd.id)::text = (test_db.d.id)::text) -> Seq Scan on trd (cost=0.00..176.57 rows=3257 width=24) (actual time=0.039..4.664 rows=3257 loops=1) -> Hash (cost=35.56..35.56 rows=184 width=23) (actual time=1.205..1.205 rows=186 loops=1) -> Seq Scan on d (cost=0.00..35.56 rows=184 width=23) (actual time=0.477..0.875 rows=186 loops=1) Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA69'::text)) -> Bitmap Heap Scan on trh (cost=4.59..154.11 rows=43 width=36) (actual time=0.124..0.266 rows=16 loops=2472888) Recheck Cond: ((test_db.d.id)::text = (test_db.trh.id)::text) Filter: (ttype = ANY ('{69,178,198,704,757,741,765}'::integer[])) -> Bitmap Index Scan on idx_trh_id (cost=0.00..4.59 rows=43 width=0) (actual time=0.064..0.064 rows=47 loops=2472888) Index Cond: ((test_db.d.id)::text = (test_db.trh.id)::text) Total runtime: 2120315.804 ms ==================== If I were to un-comment the join to table trd, the PG will choke and not come out with results for up to 20+mins (for the above 2.5K results sets retrieved) For 6K results, 2 hours and it's still crunching. re-writing to NOT use subselects and also joining 4 tables will also choke explain analyse select d.id, d.code, trh.hid, trh.start_timestamp, trh.phase_id, log(trh.pber_2) as log_pber_2, log(trh2.pber_3) as log_pber_3,log(trh3.pber_4) as log_pber_4,trd.fval_2, trd2.fval_3,trd3.fval_4 from d inner join trd on trd.id = d.id inner join ( trh inner join ts on (trh.id = ts.id and ts.ttype = trh.ttype and ts.start_timestamp = trh.start_timestamp)) on (d.id = trh.id and trh.id = trd.id and trd.ttype = trh.ttype and trd.start_timestamp = trh.start_timestamp and TRH.TTYPE IN (35,75,703,740,764)) left join ( trh trh2 inner join ts ts2 on (trh2.id = ts2.id and ts2.ttype = trh2.ttype and ts2.start_timestamp = trh2.start_timestamp) inner join trd trd2 on trd2.id = trh2.id and trd2.ttype = trh2.ttype and trd2.start_timestamp = trh2.start_timestamp ) on (d.id = trh2.id and ts2.seq_date = ts.seq_date and ts2.seq_time = ts.seq_time and trh2.hid=trh.hid and TRH2.TTYPE IN (69,178,198,704,757,741,765)) left join ( trh trh3 inner join ts ts3 on (trh3.id = ts3.id and ts3.ttype = trh3.ttype and ts3.start_timestamp = trh3.start_timestamp) inner join trd trd3 on trd3.id = trh3.id and trd3.ttype = trh3.ttype and trd3.start_timestamp = trh3.start_timestamp ) on (d.id = trh3.id and ts3.seq_date = ts.seq_date and ts3.seq_time = ts.seq_time and trh3.hid=trh.hid and TRH3.TTYPE IN (177,197,705,742,758,766)) where d.code = 'HUA69'
^ permalink raw reply [nested|flat] 10+ messages in thread

* Re: Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
@ 2007-09-11 18:23  Tom Lane <tgl@sss.pgh.pa.us>
  parent: El-Lotso <el.lotso@gmail.com>
  0 siblings, 1 reply; 10+ messages in thread

From: Tom Lane @ 2007-09-11 18:23 UTC (permalink / raw)
  To: El-Lotso <el.lotso@gmail.com>; +Cc: pgsql-performance; nikeow@yahoo.com

El-Lotso <el.lotso@gmail.com> writes:
> sorry.. I sent this as I was about to go to bed and the explain analyse
> of the query w/ 4 tables joined per subquery came out.

It's those factor-of-1000 misestimates of the join sizes that are
killing you, eg this one:

>               ->  Hash Join  (cost=249.61..512.56 rows=1 width=87) (actual time=15.139..32.858 rows=969 loops=1)
>                     Hash Cond: (((test_db.ts.id)::text = (test_db.d.id)::text) AND (test_db.ts.start_timestamp = test_db.trd.start_timestamp) AND (test_db.ts.ttype = test_db.trd.ttype))
>                     ->  Seq Scan on ts  (cost=0.00..226.44 rows=3244 width=40) (actual time=0.135..6.916 rows=3244 loops=1)
>                     ->  Hash  (cost=235.00..235.00 rows=835 width=47) (actual time=14.933..14.933 rows=1016 loops=1)

The single-row-result estimate persuades it to use a nestloop at the
next level up, and then when the output is actually 969 rows, that
means 969 executions of the other side of the upper join.

The two input size estimates are reasonably close to reality, so
the problem seems to be in the estimate of selectivity of the
join condition.  First off, do you have up-to-date statistics
for all the columns being joined here?  It might be that
increasing the statistics targets for those columns would help.

But what I'm a bit worried about is the idea that the join
conditions are correlated or even outright redundant; the
planner will not know that, and will make an unrealistic
estimate of their combined selectivity.  If that's the
case, you might need to redesign the table schema to
eliminate the redundancy before you'll get good plans.

			regards, tom lane



^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
@ 2007-09-12 02:15  El-Lotso <el.lotso@gmail.com>
  parent: Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 2 replies; 10+ messages in thread

From: El-Lotso @ 2007-09-12 02:15 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance

On Tue, 2007-09-11 at 14:23 -0400, Tom Lane wrote:
> El-Lotso <el.lotso@gmail.com> writes:
> > sorry.. I sent this as I was about to go to bed and the explain analyse
> > of the query w/ 4 tables joined per subquery came out.
> 
> It's those factor-of-1000 misestimates of the join sizes that are
> killing you, eg this one:
> 
> >               ->  Hash Join  (cost=249.61..512.56 rows=1 width=87) (actual time=15.139..32.858 rows=969 loops=1)
> >                     Hash Cond: (((test_db.ts.id)::text = (test_db.d.id)::text) AND (test_db.ts.start_timestamp = test_db.trd.start_timestamp) AND (test_db.ts.ttype = test_db.trd.ttype))
> >                     ->  Seq Scan on ts  (cost=0.00..226.44 rows=3244 width=40) (actual time=0.135..6.916 rows=3244 loops=1)
> >                     ->  Hash  (cost=235.00..235.00 rows=835 width=47) (actual time=14.933..14.933 rows=1016 loops=1)
> 
> The single-row-result estimate persuades it to use a nestloop at the
> next level up, and then when the output is actually 969 rows, that
> means 969 executions of the other side of the upper join.

Yep.. that's consistent with the larger results output. more rows = more
loops

> 
> The two input size estimates are reasonably close to reality, so
> the problem seems to be in the estimate of selectivity of the
> join condition.  First off, do you have up-to-date statistics
> for all the columns being joined here?  It might be that
> increasing the statistics targets for those columns would help.

I've already upped the stats level to 1000, reindex, vacuum, analysed
etc but nothing has basically changed. The issue here is mainly because
for each id, there is between 2 to 8 hid.

eg:
table d
seq : 1234567 / code : CED89

table trh
seq : 123456
hid : 0/1/2/3/4/5/6/7

and the prob is also compounded by the different ttypes available which
causes the use of the subqueries.

end of the day.. this data output is desired

ID	HID
===========
1234567  |0
1234567  |1
1234567  |2
1234567  |3
1234567  |4
1234567  |5
1234567  |6
1234567  |7

the d table has the unique id whereas the other tables has all the
subsets. Like a family tree.. Starts at 2, (mom/pop) then to children +
children's grandchildren (pair1) children's grandchildren(pair2) 

d to trh is a one to many relationship

> But what I'm a bit worried about is the idea that the join
> conditions are correlated or even outright redundant; the
> planner will not know that, and will make an unrealistic
> estimate of their combined selectivity.  If that's the
> case, you might need to redesign the table schema to
> eliminate the redundancy before you'll get good plans.

I'm not I understand (actually, i don't) the above comment. I've already
made then from subqueries to actual joins (collapse it) and still no
dice.

btw, this same schema runs fine on SQL server. (which I'm pulling data
from and pumping into PG)

I'm downgrading to 8.1.9 to see if it helps too.

appreciate any pointers at all.




^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
@ 2007-09-12 02:48  El-Lotso <el.lotso@gmail.com>
  parent: El-Lotso <el.lotso@gmail.com>
  1 sibling, 0 replies; 10+ messages in thread

From: El-Lotso @ 2007-09-12 02:48 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance

On Wed, 2007-09-12 at 10:15 +0800, El-Lotso wrote:
> I'm downgrading to 8.1.9 to see if it helps too.\

Nope : Doesn't help at all.. the number of rows at the nested loop and
hash joins are still 1 to 500 ratio. This plan is slightly different in
that PG is choosing seq_scans

Nested Loop Left Join  (cost=2604.28..4135.15 rows=1 width=59) (actual time=249.973..15778.157 rows=528 loops=1)
  Join Filter: ((("inner".id)::text = ("outer".id)::text) AND ("inner".hid = "outer".hid) AND ("inner".seq_time = "outer".seq_time) AND ("inner".seq_date = "outer".seq_date))
  ->  Nested Loop Left Join  (cost=1400.08..2766.23 rows=1 width=67) (actual time=168.375..8002.573 rows=528 loops=1)
        Join Filter: ((("inner".id)::text = ("outer".id)::text) AND ("inner".hid = "outer".hid) AND ("inner".seq_time = "outer".seq_time) AND ("inner".seq_date = "outer".seq_date))
        ->  Hash Join  (cost=127.25..1328.68 rows=1 width=59) (actual time=74.195..84.855 rows=528 loops=1)
              Hash Cond: ((("outer".id)::text = ("inner".id)::text) AND ("outer".ttype = "inner".ttype) AND ("outer".start_timestamp = "inner".start_timestamp))
              ->  Seq Scan on trh  (cost=0.00..1060.18 rows=9416 width=36) (actual time=0.022..53.830 rows=9416 loops=1)
                    Filter: ((ttype = 35) OR (ttype = 75) OR (ttype = 703) OR (ttype = 740) OR (ttype = 764))
              ->  Hash  (cost=125.53..125.53 rows=230 width=63) (actual time=12.487..12.487 rows=192 loops=1)
                    ->  Hash Join  (cost=18.69..125.53 rows=230 width=63) (actual time=11.043..12.007 rows=192 loops=1)
                          Hash Cond: (("outer".id)::text = ("inner".id)::text)
                          ->  Seq Scan on ts  (cost=0.00..87.36 rows=3436 width=40) (actual time=0.003..5.436 rows=3436 loops=1)
                          ->  Hash  (cost=18.57..18.57 rows=48 width=23) (actual time=0.876..0.876 rows=48 loops=1)
                                ->  Seq Scan on d  (cost=0.00..18.57 rows=48 width=23) (actual time=0.019..0.771 rows=48 loops=1)
                                      Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA75'::text))
        ->  Hash Join  (cost=1272.83..1437.52 rows=1 width=61) (actual time=11.784..14.216 rows=504 loops=528)
              Hash Cond: ((("outer".id)::text = ("inner".id)::text) AND ("outer".ttype = "inner".ttype) AND ("outer".start_timestamp = "inner".start_timestamp))
              ->  Seq Scan on ts  (cost=0.00..87.36 rows=3436 width=40) (actual time=0.003..5.744 rows=3436 loops=528)
              ->  Hash  (cost=1268.29..1268.29 rows=606 width=59) (actual time=82.783..82.783 rows=504 loops=1)
                    ->  Hash Join  (cost=18.69..1268.29 rows=606 width=59) (actual time=76.454..81.515 rows=504 loops=1)
                          Hash Cond: (("outer".id)::text = ("inner".id)::text)
                          ->  Seq Scan on trh  (cost=0.00..1198.22 rows=9064 width=36) (actual time=0.051..66.555 rows=9064 loops=1)
                                Filter: ((ttype = 69) OR (ttype = 178) OR (ttype = 198) OR (ttype = 704) OR (ttype = 757) OR (ttype = 741) OR (ttype = 765))
                          ->  Hash  (cost=18.57..18.57 rows=48 width=23) (actual time=0.863..0.863 rows=48 loops=1)
                                ->  Seq Scan on d  (cost=0.00..18.57 rows=48 width=23) (actual time=0.019..0.761 rows=48 loops=1)
                                      Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA75'::text))
  ->  Hash Join  (cost=1204.20..1368.89 rows=1 width=61) (actual time=11.498..13.941 rows=504 loops=528)
        Hash Cond: ((("outer".id)::text = ("inner".id)::text) AND ("outer".ttype = "inner".ttype) AND ("outer".start_timestamp = "inner".start_timestamp))
        ->  Seq Scan on ts  (cost=0.00..87.36 rows=3436 width=40) (actual time=0.003..5.593 rows=3436 loops=528)
        ->  Hash  (cost=1199.62..1199.62 rows=610 width=59) (actual time=70.186..70.186 rows=504 loops=1)
              ->  Hash Join  (cost=18.69..1199.62 rows=610 width=59) (actual time=64.270..68.886 rows=504 loops=1)
                    Hash Cond: (("outer".id)::text = ("inner".id)::text)
                    ->  Seq Scan on trh  (cost=0.00..1129.20 rows=9128 width=36) (actual time=0.020..54.050 rows=9128 loops=1)
                          Filter: ((ttype = 177) OR (ttype = 197) OR (ttype = 705) OR (ttype = 742) OR (ttype = 758) OR (ttype = 766))
                    ->  Hash  (cost=18.57..18.57 rows=48 width=23) (actual time=1.100..1.100 rows=48 loops=1)
                          ->  Seq Scan on d  (cost=0.00..18.57 rows=48 width=23) (actual time=0.019..0.994 rows=48 loops=1)
                                Filter: ((record_update_date_time >= '2007-08-20 00:00:00'::timestamp without time zone) AND (record_update_date_time <= '2007-09-08 00:00:00'::timestamp without time zone) AND ((code)::text = 'HUA75'::text))
Total runtime: 15779.769 ms

Am I screwed? Is a schema redesign really a necessity? This would be a
real pain given the rewrite of _all_ the queries and can't maintain
compatibility in the front-end app between sql server and PG.




^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
@ 2007-09-12 08:09  El-Lotso <el.lotso@gmail.com>
  parent: El-Lotso <el.lotso@gmail.com>
  1 sibling, 2 replies; 10+ messages in thread

From: El-Lotso @ 2007-09-12 08:09 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance

On Wed, 2007-09-12 at 10:15 +0800, El-Lotso wrote:
> On Tue, 2007-09-11 at 14:23 -0400, Tom Lane wrote:
> > El-Lotso <el.lotso@gmail.com> writes:
> > > sorry.. I sent this as I was about to go to bed and the explain analyse
> > > of the query w/ 4 tables joined per subquery came out.
> > 
> > It's those factor-of-1000 misestimates of the join sizes that are
> > killing you, eg this one:
> > 
> > >               ->  Hash Join  (cost=249.61..512.56 rows=1 width=87) (actual time=15.139..32.858 rows=969 loops=1)
> > >                     Hash Cond: (((test_db.ts.id)::text = (test_db.d.id)::text) AND (test_db.ts.start_timestamp = test_db.trd.start_timestamp) AND (test_db.ts.ttype = test_db.trd.ttype))
> > >                     ->  Seq Scan on ts  (cost=0.00..226.44 rows=3244 width=40) (actual time=0.135..6.916 rows=3244 loops=1)
> > >                     ->  Hash  (cost=235.00..235.00 rows=835 width=47) (actual time=14.933..14.933 rows=1016 loops=1)
> > 
> > The single-row-result estimate persuades it to use a nestloop at the
> > next level up, and then when the output is actually 969 rows, that
> > means 969 executions of the other side of the upper join.
> 
> Yep.. that's consistent with the larger results output. more rows = more
> loops


I'm on the verge of giving up... the schema seems simple and yet there's
so much issues with it. Perhaps it's the layout of the data, I don't
know. But based on the ordering/normalisation of the data and the one to
many relationship of some tables, this is giving the planner a headache
(and me a bulge on the head from knockin it against the wall)

I've tried multiple variations, subqueries, not use subqueries, not join
the table, (but to include it as a subquery - which gets re-written to a
join anyway) exists/not exists to no avail.

PG is fast, yes even w/ all the nested loops for up to 48K of results,
(within 4 minutes) but as soon as I put it into a inner join/left
join/multiple temporary(memory) tables it will choke.

select
a.a,b.b,c.c from
(select
x,y,z
from zz)a 
inner join b
on a.a = b.a
left join (select
x,a,z
from xx)
then it will choke.

I'm really at my wits end here. 




^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
@ 2007-09-12 13:14  Nis Jørgensen <nis@superlativ.dk>
  parent: El-Lotso <el.lotso@gmail.com>
  1 sibling, 1 reply; 10+ messages in thread

From: Nis Jørgensen @ 2007-09-12 13:14 UTC (permalink / raw)
  To: pgsql-performance

El-Lotso skrev:

> I'm on the verge of giving up... the schema seems simple and yet there's
> so much issues with it. Perhaps it's the layout of the data, I don't
> know. But based on the ordering/normalisation of the data and the one to
> many relationship of some tables, this is giving the planner a headache
> (and me a bulge on the head from knockin it against the wall)

I think you should look more at the db design, and less on rewriting the
query. Here are some observations:

- Your table structure is quite hard to understand (possibly because you
have changed the names) - if you want help on improving it, you will
need to explain the data to us, and possibly post some sample data.
- You seem to be lacking constraints on the tables. My guess is that
(id,ttype,start_timestamp) is unique in both trh and ts - but I cannot
tell (and neither can the query planner). Foreign key constraints might
help as well. These would also help others to understand your data, and
suggest reformulations of your queries.
- Another guess is that the ttype sets (177,197,705,742,758,766),
(69,178,198,704,757,741,765) are actually indicating some other property
a common "type" of record, and that only one of each will be present for
an id,start_timestamp combination. This may be related to the repeating
fields issue - if a certain ttype indicates that we are interested in a
certain pber_x field (and possibly that the others are empty).
- You have what looks like repeating fields - pber_x, fval_x, index_x -
in your tables. Fixing this might not improve your query, but might be a
good idea for other reasons.
- seq_date and seq_time seems like they may be redundant - are they
different casts of the same data?

All speculation. Hope it helps

Nis




^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
@ 2007-09-12 14:41  Tom Lane <tgl@sss.pgh.pa.us>
  parent: El-Lotso <el.lotso@gmail.com>
  1 sibling, 1 reply; 10+ messages in thread

From: Tom Lane @ 2007-09-12 14:41 UTC (permalink / raw)
  To: El-Lotso <el.lotso@gmail.com>; +Cc: pgsql-performance

El-Lotso <el.lotso@gmail.com> writes:
> I'm really at my wits end here. 

Try to merge the multiple join keys into one, somehow.  I'm not sure why
the planner is overestimating the selectivity of the combined join
conditions, but that's basically where your problem is coming from.

A truly brute-force solution would be "set enable_nestloop = off"
but this is likely to screw performance for other queries.

			regards, tom lane



^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running
@ 2007-09-14 05:51  El-Lotso <el.lotso@gmail.com>
  parent: Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 0 replies; 10+ messages in thread

From: El-Lotso @ 2007-09-14 05:51 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance

On Wed, 2007-09-12 at 10:41 -0400, Tom Lane wrote:
> El-Lotso <el.lotso@gmail.com> writes:
> > I'm really at my wits end here. 
> 
> Try to merge the multiple join keys into one, somehow.  I'm not sure why
> the planner is overestimating the selectivity of the combined join
> conditions, but that's basically where your problem is coming from.

I've tried merging them together.. what previously was

INNER JOIN  TS 
ON TS.ID = TRH.ID AND
TS.TTYPE = TRH.TTYPE AND
TS.START_TIMESTAMP = TRH.START_TIMESTAMP 

has become 
inner join TS
on ts.id_ttype_startstamp = trh.id_ttype_startstamp

where id_ttype_startstamp = (id || '-'||ttype || '-' || start_timestamp)

It's working somewhat better but everything is not as rosy as it should
as the planner is still over/under estimating the # of rows.

FROM org :
Nested Loop Left Join  (cost=10612.48..24857.20 rows=1 width=61) (actual
time=1177.626..462856.007 rows=750 loops=1)

TO merge joined conditions :
Hash Join  (cost=41823.94..45889.49 rows=6101 width=61) (actual
time=3019.609..3037.692 rows=750 loops=1)
  Hash Cond: (trd.trd_join_key = ts.ts_join_key)

Merged Join using the Main table : 3 - 5 million rows
Hash Left Join  (cost=80846.38..121112.36 rows=25 width=244) (actual
time=5088.437..5457.269 rows=750 loops=1)

Note that it still doesn't really help that much, the estimated rows is
still way off the actual number of rows. On one of the querys there the
hid field has a subset of 8 values, it's even worst. And it seems like
the merge condition doesn't help at all.


I'm still trying to merge more join conditions to see if it helps.




> A truly brute-force solution would be "set enable_nestloop = off"
> but this is likely to screw performance for other queries.

I've also tried this... It's not helping much actually.
As mentioned previously, this is a one to many relationship and because
of that, somehow PG just doesn't take it into account.

I'm still not having much luck here. (playing with a subset of the main
table's data _does_ show some promise, but when querying on the main
table w/ 3 million data, everything grinds to a halt)







^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours   and still running
@ 2007-09-14 06:30  Ow Mun Heng <Ow.Mun.Heng@wdc.com>
  parent: Nis Jørgensen <nis@superlativ.dk>
  0 siblings, 0 replies; 10+ messages in thread

From: Ow Mun Heng @ 2007-09-14 06:30 UTC (permalink / raw)
  To: Nis Jørgensen <nis@superlativ.dk>; +Cc: pgsql-performance

On Wed, 2007-09-12 at 15:14 +0200, Nis Jørgensen wrote:
> El-Lotso skrev:
> 
> > I'm on the verge of giving up... the schema seems simple and yet there's
> > so much issues with it. Perhaps it's the layout of the data, I don't
> > know. But based on the ordering/normalisation of the data and the one to
> > many relationship of some tables, this is giving the planner a headache
> > (and me a bulge on the head from knockin it against the wall)
> 
> I think you should look more at the db design, and less on rewriting the
> query. Here are some observations:

I can't help much with the design per-se. So..

> 
> - Your table structure is quite hard to understand (possibly because you
> have changed the names) - if you want help on improving it, you will
> need to explain the data to us, and possibly post some sample data.

If anyone is willing, I can send some sample data to you off-list.

on the trh table, hid is a subset of data for a particular id.

eg: 
PARENT : CHILD 1
PARENT : CHILD 2
PARENT : CHILD 3
PARENT : CHILD 4

uniqueid = merged fields from id / index1 / index2 / start_timestamp(IN EPOCH)
/ phase_id / ttype which is unique on each table  (but not across ALL the tables)


> - You seem to be lacking constraints on the tables. My guess is that
> (id,ttype,start_timestamp) is unique in both trh and ts - but I cannot
> tell (and neither can the query planner). Foreign key constraints might
> help as well. These would also help others to understand your data, and
> suggest reformulations of your queries.

AFAICT, there are no foreign constraints in the original DB design. (and
I'm not even sure how to begin the FK design based on this org design)

the unique_id is as above.
TRH/TRD uniqueid = merged fields from id / index1 / index2 /
start_timestamp(IN EPOCH) / phase_id / ttype 

TS uniqueid = merged fields from id / start_timestamp(IN EPOCH) / ttype 

Problem with this is that the fields in which they are unique is
different across the different tables, so the unique_id is only unique
for that table alone and acts as a primary key so that no dupes exists
in that one table.



> - Another guess is that the ttype sets (177,197,705,742,758,766),
> (69,178,198,704,757,741,765) are actually indicating some other property
> a common "type" of record, and that only one of each will be present for
> an id,start_timestamp combination. This may be related to the repeatingd
> fields issue - if a certain ttype indicates that we are interested in a
> certain pber_x field (and possibly that the others are empty).

yes..

eg:
id     | hid |ttype | start_timestamp  | pber_2 | pber 3 |pber_4
PARENT | 0   |764   | 2007-07-01 00:00 | 4000   | null   | null
PARENT | 0   |765   | 2007-07-01 00:00 | null   | 9000   | null
PARENT | 0   |766   | 2007-07-01 00:00 | null   | null   | 7999
PARENT | 1   |764   | 2007-07-01 00:00 | 4550   | null   | null
PARENT | 1   |765   | 2007-07-01 00:00 | null   | 9220   | null
PARENT | 1   |766   | 2007-07-01 00:00 | null   | null   | 6669


the subqueries are just to take out the fields with the value and leave
the nulls so that we end-up with

id     |hid| start_timestamp  |pber_2 | pber 3 | pber_4
PARENT | 0 | 2007-07-01 00:00 |  4000 |   9000 | 7999
PARENT | 1 | 2007-07-01 00:00 |  4550 |   9220 | 6669

which is basically just joining a table by itself, but there is a caveat
whereby pber_3 and pber_4 is/can only be joined together based on the
seq_date/seq_time in the ts table hence the query..

JOIN1.id = join2.id
and join1.seq_date = join2.seq_date
etc..

but the problem is confounded by the fact that there is numerous hid
values for head id

> - You have what looks like repeating fields - pber_x, fval_x, index_x -
> in your tables. Fixing this might not improve your query, but might be a
> good idea for other reasons.

it's being looked at by some other team to collapse this to something
like this

ttype | pber
764   | 500
765   | 600
766   | 700

so that there are lesser # of columns and no null fields. But the query
will remain the same

> - seq_date and seq_time seems like they may be redundant - are they
> different casts of the same data?

No. They're used to join together the pber_2/3/4 fields as one may
happen between a few hours to days between each other, but each will be
uniquely identified by the seq_date/time

eg : 

id     | pber_2 | seq_date            | seq time
PARENT | 400    | 2007-07-01 00:00:00 | 1980-01-01 20:00:00
PARENT | 410    | 2007-07-10 00:00:00 | 1980-01-01 22:00:00

id     | pber_3 | seq_date            | seq time
PARENT | 900    | 2007-07-01 00:00:00 | 1980-01-01 20:00:00
PARENT | 100    | 2007-07-10 00:00:00 | 1980-01-01 22:00:00

id     | pber_4 | seq_date            | seq time
PARENT | 10000  | 2007-07-01 00:00:00 | 1980-01-01 20:00:00
PARENT | 999    | 2007-07-10 00:00:00 | 1980-01-01 22:00:00


so, the correct value for the fields when joined together will be of the
form

id     |start_timestamp  |seq_date            | seq_time           |pber_2 | pber 3 | pber_4
PARENT |2007-07-01 00:00 |2007-07-01 00:00:00 | 1980-01-01 20:00:00| 400   | 900    | 10000
PARENT |2007-07-01 00:00 |2007-07-10 00:00:00 | 1980-01-01 22:00:00| 410   | 100    | 999

(repeating for each hid subset value)



> All speculation. Hope it helps


anything would help.. I'm more or less willing to try anything to make
things faster else this project is going to the toilet.



^ permalink  raw  reply  [nested|flat] 10+ messages in thread


end of thread, other threads:[~2007-09-14 06:30 UTC | newest]

Thread overview: 10+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2007-09-11 16:57 500rows = 1min/2.5k rows=20min/6K rows 2 hours and still running El-Lotso <el.lotso@gmail.com>
2007-09-11 17:02 ` El-Lotso <el.lotso@gmail.com>
2007-09-11 18:23   ` Tom Lane <tgl@sss.pgh.pa.us>
2007-09-12 02:15     ` El-Lotso <el.lotso@gmail.com>
2007-09-12 02:48       ` El-Lotso <el.lotso@gmail.com>
2007-09-12 08:09       ` El-Lotso <el.lotso@gmail.com>
2007-09-12 13:14         ` Nis Jørgensen <nis@superlativ.dk>
2007-09-14 06:30           ` Re: 500rows = 1min/2.5k rows=20min/6K rows 2 hours   and still running Ow Mun Heng <Ow.Mun.Heng@wdc.com>
2007-09-12 14:41         ` Tom Lane <tgl@sss.pgh.pa.us>
2007-09-14 05:51           ` El-Lotso <el.lotso@gmail.com>

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