Re: slow sort

On 09/11/2013 06:36 AM, Maximilian Tyrtania wrote:
> Hi there,
>
> here is another one from the "why is my query so slow?" category. First post, so please bare with me.
>
> The query (which takes around 6 seconds) is this:
>
> SET work_mem TO '256MB';//else sort spills to disk
>
> SELECT
>     et.subject,
>     COALESCE (createperson.vorname || ' ', '') || createperson.nachname AS "Sender/Empfänger",
>     to_char(es.sentonat, 'DD.MM.YY') AS "versendet am",
>     es.sentonat AS orderbydate,
>     COUNT (ct.*),
>     COALESCE (C . NAME, 'keine Angabe') :: TEXT AS "für Kunde",
>     COUNT (ct.datetimesentonat) :: TEXT || ' von ' || COUNT (ct.*) :: TEXT || ' versendet',
>     1 AS LEVEL,
>     TRUE AS hassubs,
>     FALSE AS opensubs,
>     'emailsendings:' || es. ID :: TEXT AS model_id,
>     NULL :: TEXT AS parent_model_id,
>     es. ID
> FROM
>     emailtemplates et
> JOIN emailsendings es ON et. ID = es.emailtemplate_id
> LEFT JOIN companies C ON C . ID = es.customers_id
> LEFT JOIN personen createperson ON createperson. ID = et.personen_create_id
> LEFT JOIN contacts ct ON ct.emailsendings_id = es. ID WHERE f_record_visible_to_currentuser(et.*::coretable) = true
> GROUP BY
>     1,
>     2,
>     3,
>     4,
>     6,
>     8,
>     9,
>     10,
>     11,
>     12,
>     13
> ORDER BY
>     es.sentonat desc
>
> Explain analyze:
>
> GroupAggregate  (cost=35202.88..45530.77 rows=118033 width=142) (actual time=5119.783..5810.680 rows=898 loops=1)
>    ->  Sort  (cost=35202.88..35497.96 rows=118033 width=142) (actual time=5119.356..5200.457 rows=352744 loops=1)
>          Sort Key: es.sentonat, et.subject, ((COALESCE((createperson.vorname || ' '::text), ''::text) ||
createperson.nachname)),(to_char(es.sentonat, 'DD.MM.YY'::text)), ((COALESCE(c.name, 'keine Angabe'::character
varying))::text),(1), (true), (false), (('emailsendings:'::text || (es.id)::text)), (NULL::text), es.id 
>          Sort Method:  quicksort  Memory: 198999kB
>          ->  Nested Loop Left Join  (cost=0.00..25259.29 rows=118033 width=142) (actual time=1.146..1896.382
rows=352744loops=1) 
>                ->  Nested Loop Left Join  (cost=0.00..2783.16 rows=302 width=102) (actual time=1.127..32.577 rows=898
loops=1)
>                      ->  Merge Join  (cost=0.00..2120.06 rows=302 width=86) (actual time=1.125..30.940 rows=898
loops=1)
>                            Merge Cond: (et.id = es.emailtemplate_id)
>                            ->  Nested Loop Left Join  (cost=0.00..2224.95 rows=277 width=74) (actual
time=1.109..27.484rows=830 loops=1) 
>                                  ->  Index Scan using emailtemplates_pkey on emailtemplates et  (cost=0.00..460.71
rows=277width=63) (actual time=1.097..20.541 rows=830 loops=1) 
>                                        Filter: f_record_visible_to_currentuser((et.*)::coretable)
>                                  ->  Index Scan using personen_pkey on personen createperson  (cost=0.00..6.36 rows=1
width=19)(actual time=0.006..0.006 rows=1 loops=830) 
>                                        Index Cond: (createperson.id = et.personen_create_id)
>                            ->  Index Scan using fki_emailsendings_emailtemplate_id_fkey on emailsendings es
(cost=0.00..49.83rows=905 width=20) (actual time=0.011..1.360 rows=898 loops=1) 
>                      ->  Index Scan using firmen_pkey on companies c  (cost=0.00..2.18 rows=1 width=24) (actual
time=0.001..0.001rows=0 loops=898) 
>                            Index Cond: (c.id = es.customers_id)
>                ->  Index Scan using fki_contacts_emailsendings_id_fkey on contacts ct  (cost=0.00..61.55 rows=561
width=44)(actual time=0.019..0.738 rows=393 loops=898) 
>                      Index Cond: (ct.emailsendings_id = es.id)
> Total runtime: 5865.886 ms
>
> I do have an index on es.sentonat. The sentonat-values are all unique, so I don't think I need indexes on all the
fieldsI sort by. But then again, my understanding of this might be entirely wrong. 
>
> Depeszs' explain (http://explain.depesz.com/s/69O) tells me this:
>
> node type    count    sum of times    % of query
> GroupAggregate    1    610.223 ms    10.5 %
> Index Scan    5    690.503 ms    11.9 %
> Merge Join    1    2.096 ms    0.0 %
> Nested Loop Left Join    3    1203.783 ms    20.7 %
> Sort    1    3304.075 ms    56.9 %
>
> , so the sort appears to be the problem. Any pointers would be highly appreciated.
>

I recently had to diagnose and remedy a case such as this.

The short answer is to rewrite your query so you don't have to group by
so many things. Collect your aggregates in a common table expression
query (or possibly more than one, depends what you need) using the
minimum non-aggregated columns to enable you to get correct results and
then later decorate that with all the extra things you need such as
constant columns and columns that are irrelevant to the aggregation.

This gets hard when queries are very complex, and harder still when the
query is written by a query generator. But a good generator should not
just say "grouo by everything that's not aggregated" and think it's
doing a good job. In your case it should be relatively straightforward.

cheers

andrew