Re: Problem with grouping, uses Sort and GroupAggregate, HashAggregate is better(?) - Mailing list pgsql-performance

On 14-Jan-07, at 10:34 AM, Rolf Østvik (HA/EXA) wrote:

> Computer:
>     Dell PowerEdge 2950
>     openSUSE Linux 10.1
>     Intel(R) Xeon 3.00GHz
>     4GB memory
>     xfs filesystem on SAS disks
>
>> -----Original Message-----
>> From: pgsql-performance-owner@postgresql.org
>> [mailto:pgsql-performance-owner@postgresql.org] On Behalf Of
>> Rolf Østvik (HA/EXA)
>> Sent: Sunday, January 14, 2007 1:44 PM
>> To: pgsql-performance@postgresql.org
>> Subject: [PERFORM] Problem with grouping, uses Sort and
>> GroupAggregate, HashAggregate is better(?)
>>
>> (now with a more sensible subject)
>>
>> I have been trying to change a many parameters on server versions
>> 7.4.15, 8.1.4, 8.2.0 and 8.2.1. I still hope a have managed to keep
>> my head straigth and that i do not present to much faulty
>> information.
>>
>> The cost estimates generated by the different server versions differ.
>> I have a query which (as far as i can tell) have some strange
>> differences
>> between 8.2.0 8.2.1. I can provide information about that if
>> anyone want
>> it.
>>
>> Generally these parameters are used.
>> default_statistics_target = 10
>>     (4 selected columns is set to 1000)
>>     (I have tested with 1000 as default value
>>        but that did not have an impact)
>>     (analyzed whenever value was changed)
>> shared_buffers = 64000 (512MB)

double shared_buffers
>> work_mem/sort_mem = variable, see different run's
>> effective_cache_size = 128000 (1G)

triple effective_cache (which does not actually use memory but tells
the planner what it should expect to see in the buffers)

>> random_page_cost = 2
>> cpu_index_tuple_cost = 0.001
>> cpu_operator_cost    = 0.025
>> cpu_tuple_cost       = 0.01
>>
>> I have tested with different values for random_page_cost and
>> cpu_*_cost but it have not made a difference.
>> I have tried with random_page cost between 1 and 8,
>> and cpu_*_cost with standard value and 50x bigger)

This is a dubious setting to play with. random_page_cost is the ratio
of random_seeks vs sequential seeks, 4 is generally the right number,
unless you are using a *very* fast disk, or ram disk.
>>


>> Query is:
>> explain
>>  analyze
>>     select
>>       ur.id as ur_id,
>>       ur.unit_ref,
>>       ur.execution_time,
>>       u.serial_number,
>>       to_char(ur.start_date_time, 'YYYY-MM-DD'),
>>       count(*) as num_test
>>     from
>>       uut_result as ur
>>        inner join units as u
>>         on ur.unit_ref=u.ref
>>        inner join step_result as sr
>>         on ur.id=sr.uut_result
>>     where
>>       ur.id between 174000 and 174000+999
>>     group by
>>       ur.id,
>>       ur.unit_ref,
>>       ur.execution_time,
>>       u.serial_number,
>>       ur.start_date_time
>> --  order by
>> --    ur.start_date_time
>> ;
>> NB: order by clause is used in some results below.
>>
>> === Run 1:
>> Detect work_mem setting influence (See also Run 2)
>>  - server version 8.2.1
>>  - Query executed without "order by" clause
>>  - work_mem = 8600;
>> QUERY PLAN
>>
>> ---------------------------------------------
>>  GroupAggregate  (cost=44857.70..47976.79 rows=95972
>> width=37) (actual time=1802.716..2017.337 rows=1000 loops=1)
>>    ->  Sort  (cost=44857.70..45097.63 rows=95972 width=37)
>> (actual time=1802.461..1892.743 rows=138810 loops=1)
>>          Sort Key: ur.id, ur.unit_ref, ur.execution_time,
>> u.serial_number, ur.start_date_time
>>          ->  Nested Loop  (cost=0.00..36915.87 rows=95972
>> width=37) (actual time=0.063..268.186 rows=138810 loops=1)
>>                ->  Nested Loop  (cost=0.00..5017.65 rows=981
>> width=37) (actual time=0.047..11.919 rows=1000 loops=1)
>>                      ->  Index Scan using uut_result_pkey on
>> uut_result ur  (cost=0.00..1538.77 rows=1000 width=24)
>> (actual time=0.029..1.727 rows=1000 loops=1)
>>                            Index Cond: ((id >= 174000) AND
>> (id <= 174999))
>>                      ->  Index Scan using units_pkey on units
>> u  (cost=0.00..3.47 rows=1 width=17) (actual
>> time=0.006..0.007 rows=1 loops=1000)
>>                            Index Cond: (ur.unit_ref = u.ref)
>>                ->  Index Scan using uut_result_key on
>> step_result sr  (cost=0.00..30.82 rows=136 width=4) (actual
>> time=0.011..0.125 rows=139 loops=1000)
>>                      Index Cond: (ur.id = sr.uut_result)
>> Total runtime: 2021.833 ms
>> (12 rows)
>>
>>
>> === Run 2:
>> Detect work_mem setting influence (See also Run 1)
>>  - server version 8.2.1
>>  - Query executed without "order by" clause
>>  - work_mem = 8700;
>> QUERY PLAN
>>
>> ---------------------------------------------
>>  HashAggregate  (cost=38355.45..39795.03 rows=95972 width=37)
>> (actual time=436.406..439.867 rows=1000 loops=1)
>>    ->  Nested Loop  (cost=0.00..36915.87 rows=95972 width=37)
>> (actual time=0.066..256.235 rows=138810 loops=1)
>>          ->  Nested Loop  (cost=0.00..5017.65 rows=981
>> width=37) (actual time=0.049..10.858 rows=1000 loops=1)
>>                ->  Index Scan using uut_result_pkey on
>> uut_result ur  (cost=0.00..1538.77 rows=1000 width=24)
>> (actual time=0.031..1.546 rows=1000 loops=1)
>>                      Index Cond: ((id >= 174000) AND (id <= 174999))
>>                ->  Index Scan using units_pkey on units u
>> (cost=0.00..3.47 rows=1 width=17) (actual time=0.005..0.006
>> rows=1 loops=1000)
>>                      Index Cond: (ur.unit_ref = u.ref)
>>          ->  Index Scan using uut_result_key on step_result
>> sr  (cost=0.00..30.82 rows=136 width=4) (actual
>> time=0.011..0.123 rows=139 loops=1000)
>>                Index Cond: (ur.id = sr.uut_result)  Total
>> runtime: 441.193 ms (10 rows)
>>
>> === Comment on Run 1 versus Run 2 (adjusted work_mem) ===
>> The difference in setup is value of work_mem. Bigger work_mem
>> gave different
>> cost estimates and selected HashAggregate instead of GroupAggregate.
>> Result was a reduced runtime. I guess that is as expected.
>>
>> (One remark, the switchover between different plans on
>> version 8.1.5 was for
>> work_mem values of 6800 and 6900)
>>
>> === Run 3 (with order by clause):
>> Test "group by" and "order by" (See also Run 1 and Run 4)
>>  - server version 8.2.1
>>  - Query executed with "order by" clause
>>  - work_mem = 8700
>>    (tried values from 2000 to 128000 with same cost and plan
>> as result)
>> QUERY PLAN
>>
>> ---------------------------------------------
>>  GroupAggregate  (cost=44857.70..47976.79 rows=95972
>> width=37) (actual time=1891.464..2114.462 rows=1000 loops=1)
>>    ->  Sort  (cost=44857.70..45097.63 rows=95972 width=37)
>> (actual time=1891.263..1982.137 rows=138810 loops=1)
>>          Sort Key: ur.start_date_time, ur.id, ur.unit_ref,
>> ur.execution_time, u.serial_number
>>          ->  Nested Loop  (cost=0.00..36915.87 rows=95972
>> width=37) (actual time=0.064..264.358 rows=138810 loops=1)
>>                ->  Nested Loop  (cost=0.00..5017.65 rows=981
>> width=37) (actual time=0.047..12.253 rows=1000 loops=1)
>>                      ->  Index Scan using uut_result_pkey on
>> uut_result ur  (cost=0.00..1538.77 rows=1000 width=24)
>> (actual time=0.029..1.743 rows=1000 loops=1)
>>                            Index Cond: ((id >= 174000) AND
>> (id <= 174999))
>>                      ->  Index Scan using units_pkey on units
>> u  (cost=0.00..3.47 rows=1 width=17) (actual
>> time=0.006..0.007 rows=1 loops=1000)
>>                            Index Cond: (ur.unit_ref = u.ref)
>>                ->  Index Scan using uut_result_key on
>> step_result sr  (cost=0.00..30.82 rows=136 width=4) (actual
>> time=0.011..0.124 rows=139 loops=1000)
>>                      Index Cond: (ur.id = sr.uut_result)
>> Total runtime: 2118.986 ms
>> (12 rows)
>>
>> === Run 4 (with order by clause, on server 8.1.4):
>> Test "group by" and "order by" (See also Run 1 and Run 3)
>>  - server version 8.1.4
>>  - Query executed with "order by" clause
>>  - work_mem = 6900
>>    (same plan select for all work_mem values above 6900)
>> QUERY PLAN
>>
>> ------------------------------------------------------------
>>  Sort  (cost=46578.83..46820.66 rows=96734 width=37) (actual
>> time=505.562..505.988 rows=1000 loops=1)
>>    Sort Key: ur.start_date_time
>>    ->  HashAggregate  (cost=37117.40..38568.41 rows=96734
>> width=37) (actual time=498.697..502.374 rows=1000 loops=1)
>>          ->  Nested Loop  (cost=0.00..35666.39 rows=96734
>> width=37) (actual time=0.058..288.270 rows=138810 loops=1)
>>                ->  Nested Loop  (cost=0.00..5342.20 rows=984
>> width=37) (actual time=0.042..11.773 rows=1000 loops=1)
>>                      ->  Index Scan using uut_result_pkey on
>> uut_result ur  (cost=0.00..1626.46 rows=1003 width=24)
>> (actual time=0.020..1.868 rows=1000 loops=1)
>>                            Index Cond: ((id >= 174000) AND
>> (id <= 174999))
>>                      ->  Index Scan using units_pkey on units
>> u  (cost=0.00..3.69 rows=1 width=17) (actual
>> time=0.006..0.007 rows=1 loops=1000)
>>                            Index Cond: ("outer".unit_ref = u.ref)
>>                ->  Index Scan using uut_result_key on
>> step_result sr  (cost=0.00..29.09 rows=138 width=4) (actual
>> time=0.006..0.146 rows=139 loops=1000)
>>                      Index Cond: ("outer".id = sr.uut_result)
>>  Total runtime: 507.452 ms
>> (12 rows)
>>
>> === Coemment on selected plan for 8.2.1 when using "order by" ===
>> Run 3 (8.2.1 with order by) selects same plan as Run1
>> (without order by).
>> It does hovever exist a better plan for Run3, and 8.1.5
>> manages to select
>> that plan (shown in Run 4).
>> Both versions (8.1.5 and 8.2.1) uses same plan until the
>> uppermost Nested Loop.
>> The big difference is that 8.1.5 then will do HashAggregate,
>> and then sort,
>> while 8.2.1 will does a sort and then a GroupAggregate.
>>
>> I have tried different combinations for statistics_target,
>> cpu_*_cost,
>> work_mem and random page cost without finding a solution.
>>
>> Anyone with an idea on what to do? Feel free to suggest one
>> of the above
>> parameters, i might have overlooked some combination.
>>
>> I am a little unsure on how much extra information is necessery,
>> but i
>> will provide some:
>>
>> The three tables are
>>  units        List of produced items
>>  uut_Result        Summary of test result
>>  step_result    Individuel tests results
>> The system is a production test log. (there are a lot of units which
>>  does not have an entry in uut_result).
>>
>>                                              Table "public.units"
>>       Column      |         Type          |
>>           Modifiers
>> ------------------+-----------------------+-------------------
>> ----------
>> ------------------+-----------------------+-------------------
>> ----------
>> ------------------+-----------------------+----------
>>  ref              | integer               | not null default
>> nextval(('public.units_ref_seq'::text)::regclass)
>>  serial_number    | character varying(30) | not null
>>  product_ref      | integer               | not null
>>  week             | integer               | not null
>>  status           | integer               | not null
>>  comment          | text                  |
>>  last_user        | text                  | default "current_user"()
>>  last_date        | date                  | default
>> ('now'::text)::date
>>  product_info_ref | integer               | not null
>> Indexes:
>>     "units_pkey" PRIMARY KEY, btree (ref)
>>     "units_no_sno_idx" UNIQUE, btree (product_ref, week)
>> WHERE serial_number::text = ''::text
>>     "units_serial_number_idx" UNIQUE, btree (serial_number,
>> product_info_ref) WHERE serial_number::text <> ''::text
>>     "units_product_ref_key" btree (product_ref)
>> Triggers:
>>     ct_unit_update_log AFTER UPDATE ON units FOR EACH ROW
>> EXECUTE PROCEDURE cf_unit_update_log()
>>     ct_units_update_product_info_ref BEFORE INSERT OR UPDATE
>> ON units FOR EACH ROW EXECUTE PROCEDURE
>> cf_units_update_product_info_ref()
>> select count(*) from units => 292 676 rows
>>
>>                                       Table "public.uut_result"
>>       Column       |            Type             |
>>          Modifiers
>> -------------------+-----------------------------+------------
>> ----------
>> -------------------+-----------------------------+------------
>> ----------
>> -------------------+-----------------------------+--------
>>  id                | integer                     | not null
>>  uut_serial_number | text                        |
>>  unit_ref          | integer                     |
>>  order_unit_ref    | integer                     |
>>  user_login_name   | text                        |
>>  start_date_time   | timestamp without time zone |
>>  execution_time    | double precision            |
>>  uut_status        | text                        |
>>  uut_error_code    | integer                     |
>>  uut_error_message | text                        |
>>  last_user         | text                        | default
>> "current_user"()
>>  last_timestamp    | timestamp with time zone    | default
>> ('now'::text)::timestamp(6) with time zone
>>  test_name         | text                        |
>>  teststation_name  | text                        |
>>  teststation_ref   | integer                     |
>>  process_step_ref  | integer                     |
>> Indexes:
>>     "uut_result_pkey" PRIMARY KEY, btree (id)
>>     "uut_result_start_date_time_idx" btree (start_date_time)
>>     "uut_result_test_name" btree (test_name)
>> Triggers:
>>     ct_set_process_step_ref BEFORE INSERT OR UPDATE ON
>> uut_result FOR EACH ROW EXECUTE PROCEDURE
>> cf_set_process_step_ref() select count(*) from uut_result =>
>> 180 111 rows
>>
>>             Table "public.step_result"
>>        Column       |       Type       | Modifiers
>> --------------------+------------------+-----------
>>  id                 | integer          | not null
>>  uut_result         | integer          |
>>  step_parent        | integer          |
>>  step_name          | text             |
>>  step_extra_info    | text             |
>>  step_type          | text             |
>>  status             | text             |
>>  report_text        | text             |
>>  error_code         | integer          |
>>  error_message      | text             |
>>  module_time        | double precision |
>>  total_time         | double precision |
>>  num_loops          | integer          |
>>  num_passed         | integer          |
>>  num_failed         | integer          |
>>  ending_loop_index  | integer          |
>>  loop_index         | integer          |
>>  interactive_exenum | integer          |
>>  step_group         | text             |
>>  step_index         | integer          |
>>  order_number       | integer          |
>>  pass_fail          | integer          |
>>  numeric_value      | double precision |
>>  high_limit         | double precision |
>>  low_limit          | double precision |
>>  comp_operator      | text             |
>>  string_value       | text             |
>>  string_limit       | text             |
>>  button_pressed     | integer          |
>>  response           | text             |
>>  exit_code          | integer          |
>>  num_limits_in_file | integer          |
>>  num_rows_in_file   | integer          |
>>  num_limits_applied | integer          |
>>  sequence_name      | text             |
>>  sequence_file_path | text             |
>> Indexes:
>>     "step_result_pkey" PRIMARY KEY, btree (id)
>>     "step_parent_key" btree (step_parent)
>>     "temp_index_idx" btree (sequence_file_path)
>>     "uut_result_key" btree (uut_result)
>> select count(*) from step_result => 17 624 657 rows
>>
>> Best regards
>> Rolf Østvik
>>
>> ---------------------------(end of
>> broadcast)---------------------------
>> TIP 5: don't forget to increase your free space map settings
>>
>
> ---------------------------(end of
> broadcast)---------------------------
> TIP 5: don't forget to increase your free space map settings
>