Received: from localhost (unknown [200.46.204.187]) by postgresql.org (Postfix) with ESMTP id 8BDF99FA0DC for ; Wed, 5 Sep 2007 04:57:24 -0300 (ADT) Received: from postgresql.org ([200.46.204.71]) by localhost (mx1.hub.org [200.46.204.187]) (amavisd-maia, port 10024) with ESMTP id 68834-01 for ; Wed, 5 Sep 2007 04:57:16 -0300 (ADT) X-Greylist: domain auto-whitelisted by SQLgrey-1.7.5 Received: from fk-out-0910.google.com (fk-out-0910.google.com [209.85.128.185]) by postgresql.org (Postfix) with ESMTP id CC0B29F9C30 for ; Wed, 5 Sep 2007 04:57:18 -0300 (ADT) Received: by fk-out-0910.google.com with SMTP id b27so2043726fka for ; Wed, 05 Sep 2007 00:57:17 -0700 (PDT) DKIM-Signature: a=rsa-sha1; c=relaxed/relaxed; d=gmail.com; s=beta; h=domainkey-signature:received:received:message-id:date:from:user-agent:mime-version:to:subject:references:in-reply-to:content-type; b=OQTX18AbZ0o6nFFNAHlHZ2gO7kFpbOSfeNmVdgkpOw30RPdBXIAUqXa4DwAQxVt2TvXpzmQJ9zRiB8CTlWwQO83M8yf2OZhkyWiysaSvztbl7PnMR7nxbDyYZa2Y/ecg9bcjRr+n0Unr+kiqrlZOtikIgDj6CjkkHP7MSsQn+yM= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=beta; h=received:message-id:date:from:user-agent:mime-version:to:subject:references:in-reply-to:content-type; b=bvFDXboxTnmAHFOjW0fMekbKigvWt6ijmI+tc8Xwg1TEUmILDw5XKQFja3IHhTaHDhZACT3p8IIQlwFpCkd1Xr6AcePZzHPWFn29qU+fw7R1+jaXGQpcTkLuqeL8LD5K1UImvFb8wC32+xd70B648ecSFhIFMtU4wgt/D0zO2Ho= Received: by 10.82.146.14 with SMTP id t14mr8432386bud.1188979037090; Wed, 05 Sep 2007 00:57:17 -0700 (PDT) Received: from ?10.0.0.75? ( [213.170.101.138]) by mx.google.com with ESMTPS id a1sm793510ugf.2007.09.05.00.57.14 (version=SSLv3 cipher=RC4-MD5); Wed, 05 Sep 2007 00:57:15 -0700 (PDT) Message-ID: <46DE6159.4030305@gmail.com> Date: Wed, 05 Sep 2007 11:57:13 +0400 From: Aleksandr Vinokurov User-Agent: Thunderbird 2.0.0.6 (Windows/20070728) MIME-Version: 1.0 To: pgsql-sql@postgresql.org Subject: Re: 8.0.1 to 8.0.13 upgrade added 15% lack of time of query execution References: <46DD3570.5090801@gmail.com> In-Reply-To: <46DD3570.5090801@gmail.com> Content-Type: multipart/mixed; boundary="------------090103030405020406050806" X-Virus-Scanned: Maia Mailguard 1.0.1 X-Archive-Number: 200709/45 X-Sequence-Number: 29258 This is a multi-part message in MIME format. --------------090103030405020406050806 Content-Type: text/plain; charset=windows-1251; format=flowed Content-Transfer-Encoding: 7bit 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. --------------090103030405020406050806 Content-Type: text/plain; name="8.0.1.txt" Content-Transfer-Encoding: 7bit Content-Disposition: inline; filename="8.0.1.txt" 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=26139 loops=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.306 rows=26139 loops=1) -> Subquery Scan lgm (cost=112179.18..112179.88 rows=56 width=114) (actual time=33833.584..33853.948 rows=439 loops=1) -> Sort (cost=112179.18..112179.32 rows=56 width=116) (actual time=33833.546..33834.852 rows=439 loops=1) Sort Key: luid.log_date -> HashAggregate (cost=112176.57..112177.55 rows=56 width=116) (actual time=33826.827..33831.630 rows=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) (actual time=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.11 rows=790 width=94) (actual time=20709.280..20742.897 rows=100 loops=1) -> Subquery Scan cuh (cost=109926.12..110297.49 rows=100 width=62) (actual time=20708.952..20737.891 rows=100 loops=1) -> Unique (cost=109926.12..110296.49 rows=100 width=62) (actual time=20708.920..20737.145 rows=100 loops=1) -> Sort (cost=109926.12..110111.30 rows=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.78 rows=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.57 rows=100 width=30) (actual time=0.869..0.948 rows=100 loops=1) Sort Key: log.name -> Seq Scan on 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.05 rows=444446 width=32) (actual time=19251.556..19819.983 rows=442847 loops=1) Sort Key: uh.name -> Subquery Scan 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.154 rows=442203 loops=1) Filter: ("action" <> 1) -> Index Scan using indx_date_action12_uid_user_his on 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_history gmh (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.74 rows=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 --------------090103030405020406050806--