Re: 8.0.1 to 8.0.13 upgrade added 15% lack of time of query execution

Sorry,
just noticed that both query plans are actually for the 8.0.13 release.

This one is right: "Total runtime: 93866.526 ms"

Any suggestions? Please.


Aleksandr Vinokurov wrote:
> Both plans with queries echoed are attached to this email.
Timing is on.
explain analyze
        select log_rec_id,
               log_date,
               log_uid,
               log_name,
               array_accum(trim(trailing ' ' from gh_name)) as groups
        from (

        select distinct on (log_rec_id, start_rec_id, fin_rec_id, gm_rec_id)
               log_rec_id,
               log_date,
               log_uid,
               log_name,
               start_rec_id,
               start_date,
               start_action,
               start_uid,
               start_name,
               fin_rec_id,
               fin_date,
               fin_action,
               fin_uid,
               fin_name,
               gm_rec_id,
               gm_date,
               gm_gid,
               gm_uid,
               gh.rec_id as gh_rec_id,
               gh.date as gh_date,
               gh.action as gh_action,
               gh.gid as gh_gid,
               gh.name as gh_name
        from (
                select *
                from group_history
                where action <> 1
        ) as gh
        right join (

        select log_rec_id,
               log_date,
               log_uid,
               log_name,
               start_rec_id,
               start_date,
               start_action,
               start_uid,
               start_name,
               fin_rec_id,
               fin_date,
               fin_action,
               fin_uid,
               fin_name,
               max(gm_rec_id) as gm_rec_id,
               max(gm_date) as gm_date,
               gm_gid,
               gm_uid
        from (

        select
               luid.*,
               gmh.rec_id as gm_rec_id,
               gmh.date as gm_date,
               gmh.gid as gm_gid,
               gmh.uid as gm_uid,
               gmh.action as gm_action
        from group_member_history as gmh
        right join (

        select distinct on (cuh.log_rec_id, cuh.start_rec_id)
               cuh.*, duh.*
        from (
                select rec_id as fin_rec_id,
                       date as fin_date,
                       action as fin_action,
                       uid as fin_uid,
                       name as fin_name
                from "user_history"
                where 1 = 1
                and action <> 0
        ) as duh
                right join (
                        select distinct on (log.rec_id)
                               log.rec_id as log_rec_id,
                               log.date as log_date,
                               log.uid as log_uid,
                               log.name as log_name,
                               uh.rec_id as start_rec_id,
                               uh.date as start_date,
                               uh.action as start_action,
                               uh.uid as start_uid,
                               uh.name as start_name
                        from (
                                select *
                                from "user_history"
                                where 1 = 1
                                and action <> 1
                                order by date
                        ) as uh
                                right join log_example_3 as log
                                on log.name = uh.name
                                and uh.date <= log.date
                        order by log.rec_id, start_date desc
                ) as cuh
                on cuh.start_uid = duh.fin_uid
                and duh.fin_date > cuh.start_date and duh.fin_date <= cuh.log_date
        order by cuh.log_rec_id, cuh.start_rec_id, duh.fin_rec_id

        ) as luid
        on gmh.uid = luid.start_uid
        and gmh.date <= luid.log_date

        ) as lgm
        group by
               log_rec_id,
               log_date,
               log_uid,
               log_name,
               start_rec_id,
               start_date,
               start_action,
               start_uid,
               start_name,
               fin_rec_id,
               fin_date,
               fin_action,
               fin_uid,
               fin_name,
               gm_gid,
               gm_uid
        having count(gm_action) % 2 = 1 or count(gm_action) = 0
        order by log_date

        ) as lgm
        on gh.gid = lgm.gm_gid
        and gh.date <= lgm.log_date
        order by log_rec_id, start_rec_id, fin_rec_id, gm_rec_id, gh.date desc

        ) as lgs
        group by log_rec_id,
               log_date,
               log_uid,
               log_name
        order by log_date;

              QUERY PLAN
                                       

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=114905.79..114905.79 rows=1 width=44) (actual time=93817.815..93817.870 rows=99 loops=1)
   Sort Key: log_date
   ->  HashAggregate  (cost=114905.77..114905.78 rows=1 width=44) (actual time=93817.110..93817.450 rows=99 loops=1)
         ->  Subquery Scan lgs  (cost=114888.70..114905.69 rows=6 width=44) (actual time=93704.252..93812.964 rows=439
loops=1)
               ->  Unique  (cost=114888.70..114905.63 rows=6 width=146) (actual time=93704.229..93811.067 rows=439
loops=1)
                     ->  Sort  (cost=114888.70..114892.08 rows=1355 width=146) (actual time=93704.223..93749.037
rows=26139loops=1) 
                           Sort Key: lgm.log_rec_id, lgm.start_rec_id, lgm.fin_rec_id, lgm.gm_rec_id,
group_history.date
                           ->  Nested Loop Left Join  (cost=112179.18..114818.21 rows=1355 width=146) (actual
time=33848.546..92399.306rows=26139 loops=1) 
                                 ->  Subquery Scan lgm  (cost=112179.18..112179.88 rows=56 width=114) (actual
time=33833.584..33853.948rows=439 loops=1) 
                                       ->  Sort  (cost=112179.18..112179.32 rows=56 width=116) (actual
time=33833.546..33834.852rows=439 loops=1) 
                                             Sort Key: luid.log_date
                                             ->  HashAggregate  (cost=112176.57..112177.55 rows=56 width=116) (actual
time=33826.827..33831.630rows=439 loops=1) 
                                                   Filter: (((count("action") % 2::bigint) = 1) OR (count("action") =
0))
                                                   ->  Nested Loop Left Join  (cost=112022.13..112173.77 rows=56
width=116)(actual time=20817.795..33804.325 rows=649 loops=1) 
                                                         ->  Subquery Scan luid  (cost=112022.13..112028.17 rows=11
width=94)(actual time=20743.169..20748.324 rows=100 loops=1) 
                                                               ->  Unique  (cost=112022.13..112028.06 rows=11 width=94)
(actualtime=20743.147..20744.932 rows=100 loops=1) 
                                                                     ->  Sort  (cost=112022.13..112024.11 rows=790
width=94)(actual time=20743.144..20743.426 rows=100 loops=1) 
                                                                           Sort Key: cuh.log_rec_id, cuh.start_rec_id,
user_history.rec_id
                                                                           ->  Nested Loop Left Join
(cost=109926.12..111984.11rows=790 width=94) (actual time=20709.280..20742.897 rows=100 loops=1) 
                                                                                 ->  Subquery Scan cuh
(cost=109926.12..110297.49rows=100 width=62) (actual time=20708.952..20737.891 rows=100 loops=1) 
                                                                                       ->  Unique
(cost=109926.12..110296.49rows=100 width=62) (actual time=20708.920..20737.145 rows=100 loops=1) 
                                                                                             ->  Sort
(cost=109926.12..110111.30rows=74075 width=62) (actual time=20708.914..20727.984 rows=13370 loops=1) 
                                                                                                   Sort Key:
log.rec_id,uh.date 
                                                                                                   ->  Merge Left Join
(cost=96406.26..101406.78rows=74075 width=62) (actual time=19252.554..20523.253 rows=13370 loops=1) 
                                                                                                         Merge Cond:
("outer".name= "inner".name) 
                                                                                                         Join Filter:
("inner".date<= "outer".date) 
                                                                                                         ->  Sort
(cost=5.32..5.57rows=100 width=30) (actual time=0.869..0.948 rows=100 loops=1) 
                                                                                                               Sort
Key:log.name 
                                                                                                               ->  Seq
Scanon log_example_3 log  (cost=0.00..2.00 rows=100 width=30) (actual time=0.112..0.245 rows=100 loops=1) 
                                                                                                         ->  Sort
(cost=96400.94..97512.05rows=444446 width=32) (actual time=19251.556..19819.983 rows=442847 loops=1) 
                                                                                                               Sort
Key:uh.name 
                                                                                                               ->
SubqueryScan uh  (cost=0.00..25148.24 rows=444446 width=32) (actual time=0.353..3422.179 rows=442203 loops=1) 
                                                                                                                     ->
Index Scan using indx_date_action02_user_history on user_history  (cost=0.00..20703.78 rows=444446 width=32) (actual
time=0.326..2018.154rows=442203 loops=1) 

  Filter: ("action" <> 1) 
                                                                                 ->  Index Scan using
indx_date_action12_uid_user_hison user_history  (cost=0.00..16.73 rows=8 width=32) (actual time=0.038..0.038 rows=0
loops=100)
                                                                                       Index Cond: ((user_history.date
>"outer".start_date) AND (user_history.date <= "outer".log_date) AND ("outer".start_uid = user_history.uid)) 
                                                                                       Filter: ("action" <> 0)
                                                         ->  Index Scan using indx_date_uid_on_group_member_h on
group_member_historygmh  (cost=0.00..13.15 rows=6 width=22) (actual time=80.107..130.251 rows=6 loops=100) 
                                                               Index Cond: ((gmh.date <= "outer".log_date) AND (gmh.uid
="outer".start_uid)) 
                                 ->  Index Scan using indx_date_action02_gid_group_hist on group_history
(cost=0.00..46.74rows=25 width=32) (actual time=16.099..131.682 rows=59 loops=439) 
                                       Index Cond: ((group_history.date <= "outer".log_date) AND (group_history.gid =
"outer".gm_gid))
                                       Filter: ("action" <> 1)
 Total runtime: 93866.526 ms
(43 rows)

Time: 94083.803 ms