Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.84_2) (envelope-from ) id 1bthyS-0000ZF-6l for pgsql-performance@arkaria.postgresql.org; Mon, 10 Oct 2016 21:19:04 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84_2) (envelope-from ) id 1bthyR-0002w4-7l for pgsql-performance@arkaria.postgresql.org; Mon, 10 Oct 2016 21:19:03 +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_2) (envelope-from ) id 1bthwk-0000yW-IA for pgsql-performance@postgresql.org; Mon, 10 Oct 2016 21:17:18 +0000 Received: from mail-lf0-x230.google.com ([2a00:1450:4010:c07::230]) by magus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.84_2) (envelope-from ) id 1bthwd-0000mN-RB for pgsql-performance@postgresql.org; Mon, 10 Oct 2016 21:17:17 +0000 Received: by mail-lf0-x230.google.com with SMTP id b81so3064891lfe.1 for ; Mon, 10 Oct 2016 14:17:11 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=subject:to:references:from:message-id:date:user-agent:mime-version :in-reply-to:content-transfer-encoding; bh=ihQLgrvVvhLTz5Al+g7X/sxuzjoNfvEnuZLz5YkXizY=; b=B+uDh7Lc1IGO2boNb/eQ54Qp2tZVx53UcsYilC3X7LYRohMvyPPhnG9KilApL0nRYy OOK/Z7wjuKX8MoUbKkWoQRCv0XdnygWdWfF4KCCgLpVYQSjXifOWWONtFqH2gzFAKqqo FTvVOm8/KFOA6nqDoAjJnWN2mVlw3nz7Ttxim/r3PETeGd5DXPcIxH50AaquqVfLNnTG IQ6u4pFwyBPRaQz8SwRCRxBH58i1gBaV7F8CjHwmuWOr00NdzQx/Z/ZE13M7J9hKnEOD dYa1BoqUgbjIwUi0a+tb6tvbE4LcKnwEipn+tgWNAvOzCTGBpYO+eRyHl4cOXlTO/ivH E/Fw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:subject:to:references:from:message-id:date :user-agent:mime-version:in-reply-to:content-transfer-encoding; bh=ihQLgrvVvhLTz5Al+g7X/sxuzjoNfvEnuZLz5YkXizY=; b=JWyh9wtxLCzJ5qU3HXcbFNLvac4FRychlersJkVvMtz6q89lc8uKZOf6H28OB3waM6 sXgkD3gntnidLyNzoxPwExb6rm8F8Z5XhFPHnvn4vctAos0D0VOPGYJh2NPtD/E5Nq17 g2qE7VPNnVIvkSbEQtGxwT3V264X0fuR9yPxHEmPqMnEjY5sG+vpFBWp4RuU2gICSKai qisgj8SPuF0Tuwz9TIiQFOhOC+aSIihty2z+iPsvUisRLAHPoy9bHOg/lEbkxiaaPzmn YMQ6yRWx6RoPng3MnDNpXDrRMIrdtWrqYxVdd1+qW50eEz4OD32nX+M/Xk6DyvtJDIk3 s8bA== X-Gm-Message-State: AA6/9RlMqDsQnhojAe3L6TnNvlzp6ToJSbqEHo8PPVjDMz9XeeAVwZJyJFVP1jWLf/OQ4g== X-Received: by 10.46.69.70 with SMTP id s67mr149669lja.42.1476134230401; Mon, 10 Oct 2016 14:17:10 -0700 (PDT) Received: from [192.168.0.106] (89-74-203-139.dynamic.chello.pl. [89.74.203.139]) by smtp.googlemail.com with ESMTPSA id e63sm241lfi.26.2016.10.10.14.17.09 for (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Mon, 10 Oct 2016 14:17:09 -0700 (PDT) Subject: Re: Why query plan is different? To: postgres performance list References: From: Andrzej Zawadzki Message-ID: <8aa28a9c-95c1-a8bb-e542-e7e4fd499c27@gmail.com> Date: Mon, 10 Oct 2016 23:17:09 +0200 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101 Thunderbird/45.4.0 MIME-Version: 1.0 In-Reply-To: Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: 8bit X-Pg-Spam-Score: -0.3 (/) 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
On 10.10.2016 17:31, Andrzej Zawadzki wrote:
Hi,
Today, I noticed strange situation:

The same query run on different servers has very different plan:

Q: SELECT b.* FROM kredytob b  WHERE pesel = '22222222222'  ORDER BY b.id DESC LIMIT 1

Slow plan:

"Limit  (cost=0.43..28712.33 rows=1 width=4) (actual time=2574.041..2574.044 rows=1 loops=1)"
"  Output: id"
"  Buffers: shared hit=316132 read=110001"
"  ->  Index Scan Backward using kredytob_pkey on public.kredytob b  (cost=0.43..3244444.80 rows=113 width=4) (actual time=2574.034..2574.034 rows=1 loops=1)"
"        Output: id"
"        Filter: (b.pesel = '22222222222'::bpchar)"
"        Rows Removed by Filter: 433609"
"        Buffers: shared hit=316132 read=110001"
"Planning time: 0.414 ms"
"Execution time: 2574.139 ms"


Fast plan:
"Limit  (cost=115240.66..115240.66 rows=1 width=4) (actual time=463.275..463.276 rows=1 loops=1)"
"  Output: id"
"  Buffers: shared hit=14661 read=4576"
"  ->  Sort  (cost=115240.66..115240.94 rows=112 width=4) (actual time=463.271..463.271 rows=1 loops=1)"
"        Output: id"
"        Sort Key: b.id DESC"
"        Sort Method: top-N heapsort  Memory: 25kB"
"        Buffers: shared hit=14661 read=4576"
"        ->  Index Scan using kredytob_pesel_typkred_opclass_idx on public.kredytob b  (cost=0.43..115240.10 rows=112 width=4) (actual time=311.347..463.183 rows=5 loops=1)"
"              Output: id"
"              Index Cond: (b.pesel = '22222222222'::bpchar)"
"              Buffers: shared hit=14661 read=4576"
"Planning time: 0.383 ms"
"Execution time: 463.324 ms"

Data is almost equal - "slow" has a few more rows in table. ("Fast" is a copy from 1 am today).
Why runtime is slower?

I made another INDEX, without opclass:

CREATE INDEX kredytob_pesel_typkred_idx
  ON public.kredytob
  USING btree
  (pesel COLLATE pg_catalog."default", typkred);

after that: analyze kredytob;

And now:
"Limit  (cost=333.31..333.31 rows=1 width=4) (actual time=0.100..0.102 rows=1 loops=1)"
"  Output: id"
"  Buffers: shared hit=8"
"  ->  Sort  (cost=333.31..333.59 rows=114 width=4) (actual time=0.095..0.095 rows=1 loops=1)"
"        Output: id"
"        Sort Key: b.id DESC"
"        Sort Method: top-N heapsort  Memory: 25kB"
"        Buffers: shared hit=8"
"        ->  Index Scan using kredytob_pesel_typkred_idx on public.kredytob b  (cost=0.43..332.74 rows=114 width=4) (actual time=0.046..0.065 rows=5 loops=1)"
"              Output: id"
"              Index Cond: (b.pesel = '22222222222'::bpchar)"
"              Buffers: shared hit=8"
"Planning time: 0.438 ms"
"Execution time: 0.154 ms"

So, what is a reason that "SLOW" server doesn't like opclass index?

--
Andrzej