[PERFORM] Worse perfomance on 8.2.0 than on 7.4.14
Hi I have a simple query which uses 32ms on 7.4.14 and 1015ms on 8.2.0. I guess 7.4.14 creates a better execution plan than 8.2.0 for this query but i don't know how to get it to select a better one. Explain analyse output will be found near the end of the e-mail. (I have simplified my real query to get it as simple as possible. The original query contain 6 tables and was acceptable on 7.4.2, but took far too long on 8.1.4) I have made a test setup to compare 7.4.14, 8.1.4 and 8.2.0. 8.1.4 and 8.2.0 uses the same execution plan and same time to execute. postgresql.conf values i changed is 7.4.14 Raised shared_buffers from 32MB to 128MB Raised temp_buffers from 8MB to 32MB 8.2.0 Raised shared_buffers from 32MB to 128MB Raised temp_buffers from 8MB to 32MB Raised work_mem from 1MB to 8MB (It did however not have any influence of speed for the view_subset query shown below.) vacuum analyze has been executed. Computer: Dell PowerEdge 2950 openSUSE Linux 10.1 Intel(R) Xeon 3.00GHz 4GB memory xfs filesystem on SAS disks Table public.step_result_subset Column| Type | Modifiers -+-+--- id | integer | not null uut_result | integer | step_parent | integer | Indexes: step_result_subset_pkey PRIMARY KEY, btree (id) step_result_subset_parent_key btree (step_parent) step_result_uut_result_idx btree (uut_result) Table contain 17 179 506 rows, and is ~400M when exported to file Table public.uut_result_subset Column | Type | Modifiers -+-+--- id | integer | not null start_date_time | timestamp without time zone | Indexes: uut_result_subset_pkey PRIMARY KEY, btree (id) uut_result_subset_start_date_time_idx btree (start_date_time) Table contain ~176 555 rows, and is ~4.7M when exportd to file Query is defined as view: create view view_subset as select ur.id as ur_id, sr.id as sr_id from uut_result_subset as ur inner join step_result_subset as sr on ur.id=sr.uut_result where ur.start_date_time '2006-12-11' and sr.step_parent=0; Explain analyze is run several times to get a stable result so i guess the numbers presented is with as much as possible data in memory buffers. Column step_result_subset.step_parent contain 0 in as many rows as there are rows in table uut_result_subset. (In my data set this will be 176 500 rows, Other values for step_result_subset.step_parent is present 1003 times and lower.) Query: select * from view_subset; run against 7.4.14 server. QUERY PLAN Nested Loop (cost=0.00..1400.86 rows=17 width=8) (actual time=0.161..26.287 rows=68 loops=1) - Index Scan using uut_result_subset_start_date_time_idx on uut_result_subset ur (cost=0.00..63.28 rows=18 width=4) (actual time=0.052..0.195 rows=68 loops=1) Index Cond: (start_date_time '2006-12-11 00:00:00'::timestamp without time zone) - Index Scan using step_result_uut_result_idx on step_result_subset sr (cost=0.00..74.28 rows=2 width=8) (actual time=0.149..0.379 rows=1 loops=68) Index Cond: (outer.id = sr.uut_result) Filter: (step_parent = 0) Total runtime: 26.379 ms Query: select * from view_subset; run against 8.4.0 server. QUERY PLAN -- Hash Join (cost=339.61..77103.61 rows=96 width=8) (actual time=5.249..1010.669 rows=68 loops=1) Hash Cond: (sr.uut_result = ur.id) - Index Scan using step_result_subset_parent_key on step_result_subset sr (cost=0.00..76047.23 rows=143163 width=8) (actual time=0.082..905.326 rows=176449 loops=1) Index Cond: (step_parent = 0) - Hash (cost=339.31..339.31 rows=118 width=4) (actual time=0.149..0.149 rows=68 loops=1) - Bitmap Heap Scan on uut_result_subset ur (cost=4.90..339.31 rows=118 width=4) (actual time=0.060..0.099 rows=68 loops=1) Recheck Cond: (start_date_time '2006-12-11 00:00:00'::timestamp without time zone) - Bitmap Index Scan on uut_result_subset_start_date_time_idx (cost=0.00..4.90 rows=118 width=0) (actual time=0.050..0.050 rows=68 loops=1) Index Cond: (start_date_time '2006-12-11 00:00:00'::timestamp without time zone) Total runtime: 1010.775 ms Thanks for tips. Best regards Rolf Østvik ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings
Re: [PERFORM] Worse perfomance on 8.2.0 than on 7.4.14
I have a simple query which uses 32ms on 7.4.14 and 1015ms on 8.2.0. I guess 7.4.14 creates a better execution plan than 8.2.0 for this query but i don't know how to get it to select a better one. Explain analyse output will be found near the end of the e-mail. Explain analyze is run several times to get a stable result so i guess the numbers presented is with as much as possible data in memory buffers. Query: select * from view_subset; run against 7.4.14 server. QUERY PLAN Nested Loop (cost=0.00..1400.86 rows=17 width=8) (actual time=0.161..26.287 rows=68 loops=1) - Index Scan using uut_result_subset_start_date_time_idx on uut_result_subset ur (cost=0.00..63.28 rows=18 width=4) (actual time=0.052..0.195 rows=68 loops=1) Index Cond: (start_date_time '2006-12-11 00:00:00'::timestamp without time zone) - Index Scan using step_result_uut_result_idx on step_result_subset sr (cost=0.00..74.28 rows=2 width=8) (actual time=0.149..0.379 rows=1 loops=68) Index Cond: (outer.id = sr.uut_result) Filter: (step_parent = 0) Total runtime: 26.379 ms Query: select * from view_subset; run against 8.4.0 server. QUERY PLAN -- Hash Join (cost=339.61..77103.61 rows=96 width=8) (actual time=5.249..1010.669 rows=68 loops=1) Hash Cond: (sr.uut_result = ur.id) - Index Scan using step_result_subset_parent_key on step_result_subset sr (cost=0.00..76047.23 rows=143163 width=8) (actual time=0.082..905.326 rows=176449 loops=1) Index Cond: (step_parent = 0) - Hash (cost=339.31..339.31 rows=118 width=4) (actual time=0.149..0.149 rows=68 loops=1) - Bitmap Heap Scan on uut_result_subset ur (cost=4.90..339.31 rows=118 width=4) (actual time=0.060..0.099 rows=68 loops=1) Recheck Cond: (start_date_time '2006-12-11 00:00:00'::timestamp without time zone) - Bitmap Index Scan on uut_result_subset_start_date_time_idx (cost=0.00..4.90 rows=118 width=0) (actual time=0.050..0.050 rows=68 loops=1) Index Cond: (start_date_time '2006-12-11 00:00:00'::timestamp without time zone) Total runtime: 1010.775 ms Did you lower random_page_cost in 8.2 (which defaults to 4.0)? If not try 2. regards Claus ---(end of broadcast)--- TIP 6: explain analyze is your friend
Re: [PERFORM] Worse perfomance on 8.2.0 than on 7.4.14
On 31-Dec-06, at 6:33 AM, Rolf Østvik wrote: Hi I have a simple query which uses 32ms on 7.4.14 and 1015ms on 8.2.0. I guess 7.4.14 creates a better execution plan than 8.2.0 for this query but i don't know how to get it to select a better one. Explain analyse output will be found near the end of the e-mail. (I have simplified my real query to get it as simple as possible. The original query contain 6 tables and was acceptable on 7.4.2, but took far too long on 8.1.4) I have made a test setup to compare 7.4.14, 8.1.4 and 8.2.0. 8.1.4 and 8.2.0 uses the same execution plan and same time to execute. postgresql.conf values i changed is 7.4.14 Raised shared_buffers from 32MB to 128MB Raised temp_buffers from 8MB to 32MB 8.2.0 Raised shared_buffers from 32MB to 128MB Raised temp_buffers from 8MB to 32MB Raised work_mem from 1MB to 8MB set effective_cache to 3G shared buffers should be 1G on this computer for 8.2 Dave (It did however not have any influence of speed for the view_subset query shown below.) vacuum analyze has been executed. Computer: Dell PowerEdge 2950 openSUSE Linux 10.1 Intel(R) Xeon 3.00GHz 4GB memory xfs filesystem on SAS disks Table public.step_result_subset Column| Type | Modifiers -+-+--- id | integer | not null uut_result | integer | step_parent | integer | Indexes: step_result_subset_pkey PRIMARY KEY, btree (id) step_result_subset_parent_key btree (step_parent) step_result_uut_result_idx btree (uut_result) Table contain 17 179 506 rows, and is ~400M when exported to file Table public.uut_result_subset Column |Type | Modifiers -+-+--- id | integer | not null start_date_time | timestamp without time zone | Indexes: uut_result_subset_pkey PRIMARY KEY, btree (id) uut_result_subset_start_date_time_idx btree (start_date_time) Table contain ~176 555 rows, and is ~4.7M when exportd to file Query is defined as view: create view view_subset as select ur.id as ur_id, sr.id as sr_id from uut_result_subset as ur inner join step_result_subset as sr on ur.id=sr.uut_result where ur.start_date_time '2006-12-11' and sr.step_parent=0; Explain analyze is run several times to get a stable result so i guess the numbers presented is with as much as possible data in memory buffers. Column step_result_subset.step_parent contain 0 in as many rows as there are rows in table uut_result_subset. (In my data set this will be 176 500 rows, Other values for step_result_subset.step_parent is present 1003 times and lower.) Query: select * from view_subset; run against 7.4.14 server. QUERY PLAN -- -- Nested Loop (cost=0.00..1400.86 rows=17 width=8) (actual time=0.161..26.287 rows=68 loops=1) - Index Scan using uut_result_subset_start_date_time_idx on uut_result_subset ur (cost=0.00..63.28 rows=18 width=4) (actual time=0.052..0.195 rows=68 loops=1) Index Cond: (start_date_time '2006-12-11 00:00:00'::timestamp without time zone) - Index Scan using step_result_uut_result_idx on step_result_subset sr (cost=0.00..74.28 rows=2 width=8) (actual time=0.149..0.379 rows=1 loops=68) Index Cond: (outer.id = sr.uut_result) Filter: (step_parent = 0) Total runtime: 26.379 ms Query: select * from view_subset; run against 8.4.0 server. QUERY PLAN -- Hash Join (cost=339.61..77103.61 rows=96 width=8) (actual time=5.249..1010.669 rows=68 loops=1) Hash Cond: (sr.uut_result = ur.id) - Index Scan using step_result_subset_parent_key on step_result_subset sr (cost=0.00..76047.23 rows=143163 width=8) (actual time=0.082..905.326 rows=176449 loops=1) Index Cond: (step_parent = 0) - Hash (cost=339.31..339.31 rows=118 width=4) (actual time=0.149..0.149 rows=68 loops=1) - Bitmap Heap Scan on uut_result_subset ur (cost=4.90..339.31 rows=118 width=4) (actual time=0.060..0.099 rows=68 loops=1) Recheck Cond: (start_date_time '2006-12-11 00:00:00'::timestamp without time zone) - Bitmap Index Scan on uut_result_subset_start_date_time_idx (cost=0.00..4.90 rows=118 width=0) (actual time=0.050..0.050 rows=68 loops=1) Index Cond: (start_date_time '2006-12-11 00:00:00'::timestamp without time zone) Total runtime: 1010.775 ms Thanks for tips. Best regards Rolf Østvik ---(end of broadcast)--- TIP 5: don't forget to increase your free space map settings ---(end of broadcast)--- TIP 3: Have you checked our extensive FAQ?
Re: [PERFORM] Worse perfomance on 8.2.0 than on 7.4.14
Rolf Østvik skrev: I have a simple query which uses 32ms on 7.4.14 and 1015ms on 8.2.0. I guess 7.4.14 creates a better execution plan than 8.2.0 for this query but Try to turn off planner options in 8.2 to make it generate the same plan as 7.4. Then run EXPLAIN ANALYZE on that query that generate the same plan as in 7.4 and we can compare the costs and maybe understand what go wrong. For example, try set enable_hashjoin to false; set enable_bitmapscan to false; but you might need to turn off more things to get it to generate the 7.4 plan. /Dennis ---(end of broadcast)--- TIP 6: explain analyze is your friend
Re: [PERFORM] Worse perfomance on 8.2.0 than on 7.4.14
Rolf =?iso-8859-1?q?=D8stvik?= [EMAIL PROTECTED] writes: I have a simple query which uses 32ms on 7.4.14 and 1015ms on 8.2.0. There's something awfully strange about that 8.2 plan --- if it knew that it'd have to scan all of uut_result_subset (which it should have known, if the stats were up-to-date), why did it use an indexscan rather than a seqscan? Are you sure you haven't tweaked any parameters you didn't tell us about, such as setting enable_seqscan = off? regards, tom lane ---(end of broadcast)--- TIP 9: In versions below 8.0, the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
