Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1Zr2I7-0004DA-GJ for pgsql-performance@arkaria.postgresql.org; Tue, 27 Oct 2015 11:19:47 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84) (envelope-from ) id 1Zr2I6-0002Kq-TT for pgsql-performance@arkaria.postgresql.org; Tue, 27 Oct 2015 11:19:46 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84) (envelope-from ) id 1Zr2GR-0000Sa-Hn for pgsql-performance@postgresql.org; Tue, 27 Oct 2015 11:18:03 +0000 Received: from newmail.postgrespro.ru ([93.174.131.138] helo=mail.postgrespro.ru) by magus.postgresql.org with esmtp (Exim 4.84) (envelope-from ) id 1Zr2GO-0006Da-5E for pgsql-performance@postgresql.org; Tue, 27 Oct 2015 11:18:03 +0000 Received: from [192.168.27.120] (unknown [192.168.27.1]) by mail.postgrespro.ru (Postfix) with ESMTPSA id 48A5521C3FB0; Tue, 27 Oct 2015 14:17:59 +0300 (MSK) Subject: Re: Query planner wants to use seq scan To: Bertrand Paquet References: <562F5B41.7060603@postgrespro.ru> Cc: pgsql-performance@postgresql.org From: Alex Ignatov Message-ID: <562F5D66.5010305@postgrespro.ru> Date: Tue, 27 Oct 2015 14:17:58 +0300 User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:38.0) Gecko/20100101 Thunderbird/38.3.0 MIME-Version: 1.0 In-Reply-To: Content-Type: multipart/alternative; boundary="------------020603050801090806010804" X-Pg-Spam-Score: -1.9 (-) List-Archive: List-Help: List-ID: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: X-Mailing-List: pgsql-performance Precedence: bulk Sender: pgsql-performance-owner@postgresql.org This is a multi-part message in MIME format. --------------020603050801090806010804 Content-Type: text/plain; charset=utf-8; format=flowed Content-Transfer-Encoding: 7bit On 27.10.2015 14:10, Bertrand Paquet wrote: > Yes, I have run VACUUM ANALYZE, no effect. > > Bertrand > > 2015-10-27 12:08 GMT+01:00 Alex Ignatov >: > > On 27.10.2015 12:35, Bertrand Paquet wrote: > > Hi all, > > We have a slow query. After analyzing, the planner decision > seems to be discutable : the query is faster when disabling > seqscan. See below the two query plan, and an extract from > pg_stats. > > Any idea about what to change to help the planner ? > > An information which can be useful : the number on distinct > value on organization_id is very very low, may be the planner > does not known that, and take the wrong decision. > > Regards, > > Bertrand > > # explain analyze SELECT 1 AS one FROM > "external_sync_messages" WHERE > "external_sync_messages"."organization_id" = 1612 AND > ("external_sync_messages"."status" NOT IN ('sent_to_proxy', > 'in_progress', 'ok')) AND > "external_sync_messages"."handled_by" IS NULL LIMIT 1; > > QUERY PLAN > > -------------------------------------------------------------------------------------------------------------------------------------------- > > Limit (cost=0.00..12.39 rows=1 width=0) (actual > time=232.212..232.213 rows=1 loops=1) > > -> Seq Scan on external_sync_messages (cost=0.00..79104.69 > rows=6385 width=0) (actual time=232.209..232.209 rows=1 loops=1) > > Filter: ((handled_by IS NULL) AND (organization_id = > 1612) AND ((status)::text <> ALL > ('{sent_to_proxy,in_progress,ok}'::text[]))) > > Rows Removed by Filter: 600140 > > Planning time: 0.490 ms > > Execution time: 232.246 ms > > (6 rows) > > # set enable_seqscan = off; > > SET > > # explain analyze SELECT 1 AS one FROM > "external_sync_messages" WHERE > "external_sync_messages"."organization_id" = 1612 AND > ("external_sync_messages"."status" NOT IN ('sent_to_proxy', > 'in_progress', 'ok')) AND > "external_sync_messages"."handled_by" IS NULL LIMIT 1; > > QUERY PLAN > > -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- > > Limit (cost=0.42..39.88 rows=1 width=0) (actual > time=0.030..0.030 rows=1 loops=1) > > -> Index Scan using > index_external_sync_messages_on_organization_id on > external_sync_messages (cost=0.42..251934.05 rows=6385 > width=0) (actual time=0.028..0.028 rows=1 loops=1) > > Index Cond: (organization_id = 1612) > > Filter: ((handled_by IS NULL) AND ((status)::text <> > ALL ('{sent_to_proxy,in_progress,ok}'::text[]))) > > Planning time: 0.103 ms > > Execution time: 0.052 ms > > (6 rows) > > # SELECT attname, inherited, n_distinct, > array_to_string(most_common_vals, E'\n') as most_common_vals > FROM pg_stats WHERE tablename = 'external_sync_messages' and > attname IN ('status', 'organization_id', 'handled_by'); > > attname | inherited | n_distinct | most_common_vals > > -----------------+-----------+------------+------------------ > > handled_by | f | 3 | 3 + > > | | | 236140 + > > | | | 54413 > > organization_id | f | 22 | 1612 + > > | | | 287 + > > | | | 967 + > > | | | 1223 + > > | | | 1123 + > > | | | 1930 + > > | | | 841 + > > | | | 1814 + > > | | | 711 + > > | | | 1513 + > > | | | 1794 + > > | | | 1246 + > > | | | 1673 + > > | | | 1552 + > > | | | 1747 + > > | | | 2611 + > > | | | 2217 + > > | | | 2448 + > > | | | 2133 + > > | | | 1861 + > > | | | 2616 + > > | | | 2796 > > status | f | 6 | ok + > > | | | ignored + > > | | | channel_error + > > | | | in_progress + > > | | | error + > > | | | sent_to_proxy > > (3 rows) > > # select count(*) from external_sync_messages; > > count > > -------- > > 992912 > > (1 row) > > > Hello, Bertrand! > May be statistics on external_sync_messages is wrong? i.e planner > give us rows=6385 but seq scan give us Rows Removed by Filter: 600140 > Maybe you should recalc it by VACUUM ANALYZE it? > > -- > Alex Ignatov > Postgres Professional: http://www.postgrespro.com > The Russian Postgres Company > > What is the result of select relname,n_live_tup,n_dead_tup, last_vacuum, last_autovacuum, last_analyze, last_autoanalyze from pg_stat_user_tables where relname='external_sync_messages' ? -- Alex Ignatov Postgres Professional: http://www.postgrespro.com The Russian Postgres Company --------------020603050801090806010804 Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: 8bit On 27.10.2015 14:10, Bertrand Paquet wrote:
Yes, I have run VACUUM ANALYZE, no effect.

Bertrand

2015-10-27 12:08 GMT+01:00 Alex Ignatov <a.ignatov@postgrespro.ru>:
On 27.10.2015 12:35, Bertrand Paquet wrote:
Hi all,

We have a slow query. After analyzing, the planner decision seems to be discutable : the query is faster when disabling seqscan. See below the two query plan, and an extract from pg_stats.

Any idea about what to change to help the planner ?

An information which can be useful : the number on distinct value on organization_id is very very low, may be the planner does not known that, and take the wrong decision.

Regards,

Bertrand

# explain analyze SELECT  1 AS one FROM "external_sync_messages"  WHERE "external_sync_messages"."organization_id" = 1612 AND ("external_sync_messages"."status" NOT IN ('sent_to_proxy', 'in_progress', 'ok')) AND "external_sync_messages"."handled_by" IS NULL LIMIT 1;

                              QUERY PLAN

--------------------------------------------------------------------------------------------------------------------------------------------

 Limit  (cost=0.00..12.39 rows=1 width=0) (actual time=232.212..232.213 rows=1 loops=1)

   ->  Seq Scan on external_sync_messages  (cost=0.00..79104.69 rows=6385 width=0) (actual time=232.209..232.209 rows=1 loops=1)

         Filter: ((handled_by IS NULL) AND (organization_id = 1612) AND ((status)::text <> ALL ('{sent_to_proxy,in_progress,ok}'::text[])))

         Rows Removed by Filter: 600140

 Planning time: 0.490 ms

 Execution time: 232.246 ms

(6 rows)

# set enable_seqscan = off;

SET

# explain analyze SELECT  1 AS one FROM "external_sync_messages"  WHERE "external_sync_messages"."organization_id" = 1612 AND ("external_sync_messages"."status" NOT IN ('sent_to_proxy', 'in_progress', 'ok')) AND "external_sync_messages"."handled_by" IS NULL LIMIT 1;

                                                    QUERY PLAN

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

 Limit  (cost=0.42..39.88 rows=1 width=0) (actual time=0.030..0.030 rows=1 loops=1)

   ->  Index Scan using index_external_sync_messages_on_organization_id on external_sync_messages  (cost=0.42..251934.05 rows=6385 width=0) (actual time=0.028..0.028 rows=1 loops=1)

         Index Cond: (organization_id = 1612)

         Filter: ((handled_by IS NULL) AND ((status)::text <> ALL ('{sent_to_proxy,in_progress,ok}'::text[])))

 Planning time: 0.103 ms

 Execution time: 0.052 ms

(6 rows)

# SELECT attname, inherited, n_distinct, array_to_string(most_common_vals, E'\n') as most_common_vals FROM pg_stats WHERE tablename = 'external_sync_messages' and attname IN ('status', 'organization_id', 'handled_by');

     attname     | inherited | n_distinct | most_common_vals

-----------------+-----------+------------+------------------

 handled_by      | f         |       3 | 3               +

                 |           |         | 236140          +

                 |           |         | 54413

 organization_id | f         |     22 | 1612            +

                 |           |         | 287             +

                 |           |         | 967             +

                 |           |         | 1223            +

                 |           |         | 1123            +

                 |           |         | 1930            +

                 |           |         | 841             +

                 |           |         | 1814            +

                 |           |         | 711             +

                 |           |         | 1513            +

                 |           |         | 1794            +

                 |           |         | 1246            +

                 |           |         | 1673            +

                 |           |         | 1552            +

                 |           |         | 1747            +

                 |           |         | 2611            +

                 |           |         | 2217            +

                 |           |         | 2448            +

                 |           |         | 2133            +

                 |           |         | 1861            +

                 |           |         | 2616            +

                 |           |         | 2796

 status          | f         |       6 | ok              +

                 |           |         | ignored         +

                 |           |         | channel_error   +

                 |           |         | in_progress     +

                 |           |         | error           +

                 |           |         | sent_to_proxy

(3 rows)

# select count(*) from external_sync_messages;

 count

--------

 992912

(1 row)


Hello, Bertrand!
May be statistics on external_sync_messages is wrong? i.e planner give us rows=6385 but seq scan give us Rows Removed by Filter: 600140
Maybe you should recalc it by VACUUM ANALYZE it?

--
Alex Ignatov
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company


What is the result of
select relname,n_live_tup,n_dead_tup, last_vacuum, last_autovacuum, last_analyze, last_autoanalyze from pg_stat_user_tables where relname='external_sync_messages' ?

-- 
Alex Ignatov
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company
--------------020603050801090806010804--