Received: from magus.postgresql.org (magus.postgresql.org [87.238.57.229]) by mail.postgresql.org (Postfix) with ESMTP id 874E911DF228 for ; Thu, 31 May 2012 19:30:11 -0300 (ADT) Received: from na3sys009aog112.obsmtp.com ([74.125.149.207]) by magus.postgresql.org with smtp (Exim 4.72) (envelope-from ) id 1SaDsd-0005AO-Bn for pgsql-performance@postgresql.org; Thu, 31 May 2012 22:30:10 +0000 Received: from mail-pb0-f47.google.com ([209.85.160.47]) (using TLSv1) by na3sys009aob112.postini.com ([74.125.148.12]) with SMTP ID DSNKT8fw4Tm9oczf3MZ0V8iN6C01vkh6lSXB@postini.com; Thu, 31 May 2012 15:30:07 PDT Received: by pbbrq2 with SMTP id rq2so2033098pbb.20 for ; Thu, 31 May 2012 15:29:51 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20120113; h=message-id:date:from:user-agent:mime-version:to:subject :content-type:x-gm-message-state; bh=OPZt68DubhAyHu7pFi3IM4uitBkYPyWdMhbETr2Mv84=; b=j+jX2/mNxRgSy0YGXSqZnpu+Dbpxdl8o+gsZDIOfRSMzZE7qpy3z2aUFvatn9FdzKb Inz5XoKhgweUqNZVXpccx+mDWRX/8FhcGwktf6ftxj4t/vr0xFJPdl+nu2RrdbmTOjXa uYF+vQr7IJQDZAx720P8ugXReqsz1+FzNNn/nMUr4zcvbOIWkwIIEFDxR4+AnkaQeBMl 2pCDZyMeJvwS7dSPRlmTGWbVesajlMiIUd/au4/u6tevGW3dyDuBPJA8BMD1A8SHovh5 rQZscCzpBpVDVKLkqJYzY0v3JEuA/69HaptURxoSVVzW4BRtFLsyqpplisqomEYW7m+I 8w6w== Received: by 10.68.242.162 with SMTP id wr2mr3854170pbc.125.1338503391739; Thu, 31 May 2012 15:29:51 -0700 (PDT) Received: from [172.20.9.121] (eth59-167-133-99.static.internode.on.net. [59.167.133.99]) by mx.google.com with ESMTPS id or8sm454914pbb.12.2012.05.31.15.29.49 (version=TLSv1/SSLv3 cipher=OTHER); Thu, 31 May 2012 15:29:50 -0700 (PDT) Message-ID: <4FC7F0DB.40600@atlassian.com> Date: Fri, 01 Jun 2012 08:29:47 +1000 From: Trevor Campbell User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:12.0) Gecko/20120430 Thunderbird/12.0.1 MIME-Version: 1.0 To: pgsql-performance@postgresql.org Subject: Trouble with plan statistics for behaviour for query. Content-Type: multipart/alternative; boundary="------------010705080706000001090200" X-Gm-Message-State: ALoCoQlXBF4ZXUTShMHViruwqJ4Bkgc6AIh1hnn6exnZ0f4LB8InpNbPOyA/ejq7U/NqRV0xn+oj X-Pg-Spam-Score: -4.2 (----) X-Archive-Number: 201205/196 X-Sequence-Number: 47020 This is a multi-part message in MIME format. --------------010705080706000001090200 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit We are having trouble with a particular query being slow in a strange manner. The query is a join over two large tables that are suitably indexed. select CG.ID, CG.ISSUEID, CG.AUTHOR, CG.CREATED, CI.ID, CI.FIELDTYPE, CI.FIELD, CI.OLDVALUE, CI.OLDSTRING, CI.NEWVALUE, CI.NEWSTRING from PUBLIC.CHANGEGROUP CG inner join PUBLIC.CHANGEITEM CI on CG.ID = CI.GROUPID where CG.ISSUEID=? order by CG.CREATED asc, CI.ID asc For some tasks we run this particular query a very large number of times and it has a significant performance impact when it runs slowly. If we run ANALYSE over the CHANGEITEM table then the performance picks up by a factor of 5 or more. The problem is that a day later the performance will have dropped back to its previously slow state. The reason this is so hard to understand is that the activity on this table is very low, with no updates and only a relatively small number of inserts each day, < 0.1% of the table size. Explain output: Sort (cost=86.90..86.93 rows=11 width=118) (actual time=0.086..0.087 rows=14 loops=1) Sort Key: cg.created, ci.id Sort Method: quicksort Memory: 26kB -> Nested Loop (cost=0.00..86.71 rows=11 width=118) (actual time=0.022..0.061 rows=14 loops=1) -> Index Scan using chggroup_issue on changegroup cg (cost=0.00..17.91 rows=8 width=33) (actual time=0.012..0.015 rows=7 loops=1) Index Cond: (issueid = 81001::numeric) -> Index Scan using chgitem_chggrp on changeitem ci (cost=0.00..8.58 rows=2 width=91) (actual time=0.005..0.005 rows=2 loops=7) Index Cond: (groupid = cg.id) Total runtime: 0.116 ms The explain output always seems the same even when the performance is poor, but I can't be sure of that. Overall it seems like PostgreSQL just forgets about the statistics it has gathered after a short while. Schema details: CREATE TABLE changegroup ( id numeric(18,0) NOT NULL, issueid numeric(18,0), author character varying(255), created timestamp with time zone, CONSTRAINT pk_changegroup PRIMARY KEY (id ) ) WITH ( OIDS=FALSE ); CREATE INDEX chggroup_issue ON changegroup USING btree (issueid ); CREATE TABLE changeitem ( id numeric(18,0) NOT NULL, groupid numeric(18,0), fieldtype character varying(255), field character varying(255), oldvalue text, oldstring text, newvalue text, newstring text, CONSTRAINT pk_changeitem PRIMARY KEY (id ) ) WITH ( OIDS=FALSE ); CREATE INDEX chgitem_chggrp ON changeitem USING btree (groupid ); CREATE INDEX chgitem_field ON changeitem USING btree (field COLLATE pg_catalog."default" ); Table sizes changegroup : 2,000,000 rows changeitem : 2,500,000 rows The changegroup table has on average about 4 rows per issueid value, which is the query parameter. We run autovacuum and autoanalyse, but as the activity in the table is low these are rarely if ever invoked on these tables. Environment. Testing using PostgreSQL 9.1.3 on x86_64-redhat-linux-gnu, although this is a problem across a variety of postgres versions. --------------010705080706000001090200 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit We are having trouble with a particular query being slow in a strange manner.

The query is a join over two large tables that are suitably indexed.

select CG.ID, CG.ISSUEID, CG.AUTHOR, CG.CREATED, CI.ID, CI.FIELDTYPE, CI.FIELD, CI.OLDVALUE, CI.OLDSTRING, CI.NEWVALUE, CI.NEWSTRING
   from PUBLIC.CHANGEGROUP CG inner join PUBLIC.CHANGEITEM CI on CG.ID = CI.GROUPID where CG.ISSUEID=? order by CG.CREATED asc, CI.ID asc

For some tasks we run this particular query a very large number of times and it has a significant performance impact when it runs slowly.

If we run ANALYSE over the CHANGEITEM table then the performance picks up by a factor of 5 or more.  The problem is that a day later the performance will have dropped back to its previously slow state.

The reason this is so hard to understand is that the activity on this table is very low, with no updates and only a relatively small number of inserts each day, < 0.1% of the table size.

Explain output:
Sort  (cost=86.90..86.93 rows=11 width=118) (actual time=0.086..0.087 rows=14 loops=1)
  Sort Key: cg.created, ci.id
  Sort Method: quicksort  Memory: 26kB
  ->  Nested Loop  (cost=0.00..86.71 rows=11 width=118) (actual time=0.022..0.061 rows=14 loops=1)
        ->  Index Scan using chggroup_issue on changegroup cg  (cost=0.00..17.91 rows=8 width=33) (actual time=0.012..0.015 rows=7 loops=1)
              Index Cond: (issueid = 81001::numeric)
        ->  Index Scan using chgitem_chggrp on changeitem ci  (cost=0.00..8.58 rows=2 width=91) (actual time=0.005..0.005 rows=2 loops=7)
              Index Cond: (groupid = cg.id)
Total runtime: 0.116 ms

The explain output always seems the same even when the performance is poor, but I can't be sure of that.

Overall it seems like PostgreSQL just forgets about the statistics it has gathered after a short while.

Schema details:
CREATE TABLE changegroup
(
  id numeric(18,0) NOT NULL,
  issueid numeric(18,0),
  author character varying(255),
  created timestamp with time zone,
  CONSTRAINT pk_changegroup PRIMARY KEY (id )
)
WITH (
  OIDS=FALSE
);
CREATE INDEX chggroup_issue
  ON changegroup
  USING btree
  (issueid );

CREATE TABLE changeitem
(
  id numeric(18,0) NOT NULL,
  groupid numeric(18,0),
  fieldtype character varying(255),
  field character varying(255),
  oldvalue text,
  oldstring text,
  newvalue text,
  newstring text,
  CONSTRAINT pk_changeitem PRIMARY KEY (id )
)
WITH (
  OIDS=FALSE
);

CREATE INDEX chgitem_chggrp
  ON changeitem
  USING btree
  (groupid );

CREATE INDEX chgitem_field
  ON changeitem
  USING btree
  (field COLLATE pg_catalog."default" );

Table sizes
changegroup  :  2,000,000 rows
changeitem    :  2,500,000  rows

The changegroup table has on average about 4 rows per issueid value, which is the query parameter.

We run autovacuum and autoanalyse, but as the activity in the table is low these are rarely if ever invoked on these tables.

Environment.
Testing using PostgreSQL 9.1.3 on x86_64-redhat-linux-gnu,  although this is a problem across a variety of postgres versions.

--------------010705080706000001090200--