To: "pgsql-performance@postgresql.org" <pgsql-performance@postgresql.org>
From: Jim Nasby <Jim.Nasby@BlueTreble.com>
Subject: Poor choice of backward scan
Message-ID: <7ead14dc-2bb1-0f20-dc05-93804d118798@BlueTreble.com>
Date: Wed, 20 Jul 2016 15:56:31 -0500
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:45.0)
 Gecko/20100101 Thunderbird/45.2.0
MIME-Version: 1.0
Content-Type: text/plain; charset="utf-8"; format=flowed
Content-Transfer-Encoding: 8bit
Received-SPF: None (protection.outlook.com: bluetreble.com does not designate
 permitted sender hosts)
SpamDiagnosticOutput: 1:99
SpamDiagnosticMetadata: NSPM
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 20 Jul 2016 20:56:35.4423 (UTC)
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-Transport-CrossTenantHeadersStamped: CY4PR11MB1637
X-Pg-Spam-Score: -1.9 (-)
List-Archive: <http://archives.postgresql.org/pgsql-performance>
List-Help: <mailto:majordomo@postgresql.org?body=help>
List-ID: <pgsql-performance.postgresql.org>
List-Owner: <mailto:pgsql-performance-owner@postgresql.org>
List-Post: <mailto:pgsql-performance@postgresql.org>
List-Subscribe: <mailto:majordomo@postgresql.org?body=sub%20pgsql-performance>
List-Unsubscribe: 
 <mailto:majordomo@postgresql.org?body=unsub%20pgsql-performance>
X-Mailing-List: pgsql-performance
Precedence: bulk
Sender: pgsql-performance-owner@postgresql.org

Came across this from a client today. Was able to work around it with a 
fence, but wanted to report it for the next time Robert generates 
statistics on planner problems. ;) It appears the problem is the planner 
couldn't recognize that even though there's ~400k rows for user 3737558, 
very few of them will actually match the rest of the predicates 
(specifically m_ident).

> data=> explain analyze SELECT id FROM table_name WHERE user_id = ‘36’ and m_ident= 'x12345' AND deleted IS NULL ORDER BY changed DESC LIMIT 1;
>                                                                                QUERY PLAN
> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> Limit  (cost=240.31..240.32 rows=1 width=12) (actual time=0.188..0.189 rows=1 loops=1)
>    ->  Sort  (cost=240.31..240.32 rows=1 width=12) (actual time=0.187..0.187 rows=1 loops=1)
>          Sort Key: changed
>          Sort Method: quicksort  Memory: 25kB
>          ->  Index Scan using table_name__user_id_deleted on table_name  (cost=0.56..240.30 rows=1 width=12) (actual time=0.131..0.178 rows=2 loops=1)
>                Index Cond: ((user_id = 36) AND (deleted IS NULL))
>                Filter: ((m_ident)::text = 'x12345'::text)
>                Rows Removed by Filter: 63
> Planning time: 0.371 ms
> Execution time: 0.357 ms
>
> (10 rows)
>
>
> data=> explain analyze SELECT id FROM table_name WHERE user_id = '3737558' AND m_ident = 'xxx1234' AND deleted IS NULL ORDER BY changed DESC LIMIT 1;
>                                                                               QUERY PLAN
> ----------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Limit  (cost=0.43..177673.83 rows=1 width=12) (actual time=17151.010..17151.010 rows=0 loops=1)
>    ->  Index Scan Backward using table_name___changed on table_name  (cost=0.43..888367.40 rows=5 width=12) (actual time=17151.010..17151.010 rows=0 loops=1)
>          Filter: ((deleted IS NULL) AND (user_id = 3737558) AND ((m_ident)::text = 'xxx1234'::text))
>          Rows Removed by Filter: 16238592
> Planning time: 0.189 ms
>
> Execution time: 17151.042 ms
>
> (6 rows)
>
> With fence...
>
> data=> EXPLAIN ANALYZE SELECT id FROM (SELECT * FROM table_name WHERE user_id = 3737558 AND m_ident = 'xxx1234' AND deleted IS NULL OFFSET 0) a ORDER BY changed DESC LIMIT 1;
>                                                                                   QUERY PLAN
> -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>  Limit  (cost=221150.73..221150.74 rows=1 width=12) (actual time=1391.148..1391.148 rows=0 loops=1)
>    ->  Sort  (cost=221150.73..221150.75 rows=6 width=12) (actual time=1391.147..1391.147 rows=0 loops=1)
>          Sort Key: a.changed
>          Sort Method: quicksort  Memory: 25kB
>          ->  Subquery Scan on a  (cost=4414.63..221150.70 rows=6 width=12) (actual time=1391.115..1391.115 rows=0 loops=1)
>                ->  Bitmap Heap Scan on table_name  (cost=4414.63..221150.64 rows=6 width=170) (actual time=1391.113..1391.113 rows=0 loops=1)
>                      Recheck Cond: ((user_id = 3737558) AND (deleted IS NULL))
>                      Filter: ((m_ident)::text = 'AAL3979'::text)
>                      Rows Removed by Filter: 386150
>                      Heap Blocks: exact=119205
>                      ->  Bitmap Index Scan on table_name__user_id_deleted  (cost=0.00..4414.63 rows=247407 width=0) (actual time=150.593..150.593 rows=397748 loops=1)
>                            Index Cond: ((user_id = 3737558) AND (deleted IS NULL))
>  Planning time: 1.613 ms
>  Execution time: 1392.732 ms
> (14 rows)
>
> Relevant indexes:
>
>     "table_name__enabled_date_end_enabled" btree (date_end, enabled)
>     "table_name__user_id" btree (user_id)
>     "table_name__user_id_deleted" btree (user_id, deleted)
>     "table_name___changed" btree (changed)
-- 
Jim Nasby, Data Architect, Blue Treble Consulting, Austin TX
Experts in Analytics, Data Architecture and PostgreSQL
Data in Trouble? Get it in Treble! http://BlueTreble.com
855-TREBLE2 (855-873-2532)   mobile: 512-569-9461


-- 
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance