Postgres 9.4 using primary key index in almost all queries leading to degraded performance

From: Rahul Sharma <rahul(dot)sharma1(at)oyorooms(dot)com>
To: pgsql-general(at)postgresql(dot)org
Cc: Jagbir Singh <jagbir(dot)singh1(at)oyorooms(dot)com>, Sonender Singh <sonender(dot)singh(at)oyorooms(dot)com>, Rishikesh kumar <rishikesh(dot)kumar(at)oyorooms(dot)com>, Ishank Singh <ishank(dot)singh(at)oyorooms(dot)com>
Subject: Postgres 9.4 using primary key index in almost all queries leading to degraded performance
Date: 2018-01-13 06:37:17
Message-ID: CAEA5Rf8HSfd92cKHskOu-mUo-B9Fazvj3eQaRbV2cE2qkmCkLA@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

Hi,

We're currently testing out upgrade of our Postgres database from 9.3.14 to
9.4.9. We are using Amazon RDS. We've encountered an issue in testing
phase where after the upgrade, CPU utilization hovers around 100%. We dug
deep to find that the queries which executed in a few milliseconds on
Postgres 9.3.14 are taking a lot of time to complete on 9.4.9. We've
noticed a pattern under which the query planner (in almost all queries) is
using primary key index for scanning the table while ignoring other
alternatives like explicit sorting or using another efficient index present
on the table.

I'm sharing a few queries along with the query plans of Postgres 9.3 and
9.4.

*1. First Query:*

EXPLAIN ANALYZE SELECT user_device_identifiers.id as
user_device_identifier_id, device_identifiers.partner_id as partner_id FROM
user_device_identifiers INNER JOIN device_identifiers ON
device_identifiers.id = user_device_identifiers.device_identifier_id WHERE
(user_device_identifiers.status = 1 AND
user_device_identifiers.authentication_token
= '2y_mHHruh69pPpNo2GFn') ORDER BY user_device_identifiers.id ASC LIMIT 1;

Query plan of Postgres 9.3:

Limit (cost=17.06..17.06 rows=1 width=8) (actual time=5.654..5.655 rows=1
loops=1)
-> Sort (cost=17.06..17.06 rows=1 width=8) (actual time=5.653..5.653
rows=1 loops=1)
Sort Key: user_device_identifiers.id
Sort Method: quicksort Memory: 25kB
-> Nested Loop (cost=1.00..17.05 rows=1 width=8) (actual
time=5.637..5.640 rows=1 loops=1)
-> Index Scan using
index_user_device_identifiers_on_authentication_token
on user_device_identifiers (cost=0.56..8.58 rows=1 width=8) (actual
time=3.114..3.114 rows=1 loops=1)
Index Cond: ((authentication_token)::text =
'2y_mHHruh69pPpNo2GFn'::text)
Filter: (status = 1)
-> Index Scan using device_identifiers_pkey on
device_identifiers (cost=0.43..8.46 rows=1 width=8) (actual
time=2.519..2.520 rows=1 loops=1)
Index Cond: (id = user_device_identifiers.
device_identifier_id)
Total runtime: 5.686 ms
(11 rows)

Query plan of Postgres 9.4:

Limit (cost=0.87..4181.94 rows=1 width=8) (actual
time=93014.991..93014.992 rows=1 loops=1)
-> Nested Loop (cost=0.87..1551177.78 rows=371 width=8) (actual
time=93014.990..93014.990 rows=1 loops=1)
-> Index Scan using a_pkey on a (cost=0.43..1548042.20 rows=371
width=8) (actual time=93014.968..93014.968 rows=1 loops=1)
Filter: ((col_int = 1) AND ((col_text)::text = 'pqrs'::text))
Rows Removed by Filter: 16114217
-> Index Scan using b_pkey on b (cost=0.43..8.44 rows=1 width=8)
(actual time=0.014..0.014 rows=1 loops=1)
Index Cond: (id = a.b_id)
Planning time: 0.291 ms
Execution time: 93015.041 ms

*2nd Query:*

EXPLAIN ANALYZE SELECT hotels.id FROM hotels INNER JOIN hotel_restrictions
ON hotel_restrictions.hotel_id = hotels.id INNER JOIN restrictions ON
restrictions.id = hotel_restrictions.restriction_id WHERE
(hotel_restrictions.status = 1) AND restrictions.id = 12 AND
(((hotel_restrictions.from_time < '2018-01-10' and
hotel_restrictions.to_time >='2018-01-09') OR
(hotel_restrictions.from_time is null AND hotel_restrictions.to_time is
null)) and (not (excluded_days @> (select array((select distinct extract
(dow from generate_series(case when '2018-01-09'::date >
hotel_restrictions.from_time then '2018-01-09'::date else
hotel_restrictions.from_time end,case when '2018-01-10'::date <=
hotel_restrictions.to_time then '2018-01-09'::date else
hotel_restrictions.to_time end,'1 day'::interval))::integer)))) or
excluded_days is null));

Query plan of Postgres 9.3:

Nested Loop (cost=26828.12..138106.67 rows=6597 width=4) (actual
time=52.956..157.053 rows=4972 loops=1)
-> Seq Scan on restrictions (cost=0.00..1.56 rows=1 width=4) (actual
time=0.007..0.014 rows=1 loops=1)
Filter: (id = 12)
Rows Removed by Filter: 44
-> Nested Loop (cost=26828.12..138039.14 rows=6597 width=8) (actual
time=52.947..154.531 rows=4972 loops=1)
-> Bitmap Heap Scan on hotel_restrictions
(cost=26827.70..130501.88 rows=6597 width=8) (actual time=52.932..120.653
rows=4972 loops=1)
Recheck Cond: (((to_time >= '2018-01-09'::date) AND
(restriction_id = 12) AND (from_time < '2018-01-10'::date) AND (status =
1)) OR ((to_time IS NULL) AND (restriction_id = 12) AND (from_time IS NULL)
AND (status = 1)))
Filter: ((NOT (excluded_days @> (SubPlan 2))) OR
(excluded_days IS NULL))
Rows Removed by Filter: 359
-> BitmapOr (cost=26827.70..26827.70 rows=6600 width=0)
(actual time=52.253..52.253 rows=0 loops=1)
-> Bitmap Index Scan on
hotel_restrictions_multi_column_index
(cost=0.00..26819.67 rows=6580 width=0) (actual time=52.242..52.242
rows=5568 loops=1)
Index Cond: ((to_time >= '2018-01-09'::date) AND
(restriction_id = 12) AND (from_time < '2018-01-10'::date) AND (status = 1))
-> Bitmap Index Scan on
hotel_restrictions_multi_column_index
(cost=0.00..4.73 rows=20 width=0) (actual time=0.009..0.009 rows=0 loops=1)
Index Cond: ((to_time IS NULL) AND
(restriction_id = 12) AND (from_time IS NULL) AND (status = 1))
SubPlan 2
-> Result (cost=12.54..12.55 rows=1 width=0) (actual
time=0.009..0.009 rows=1 loops=5331)
InitPlan 1 (returns $2)
-> HashAggregate (cost=7.52..12.54 rows=1000
width=0) (actual time=0.006..0.006 rows=1 loops=5331)
-> Result (cost=0.00..5.02 rows=1000
width=0) (actual time=0.003..0.004 rows=1 loops=5331)
-> Index Only Scan using hotels_pkey on hotels (cost=0.41..1.13
rows=1 width=4) (actual time=0.005..0.005 rows=1 loops=4972)
Index Cond: (id = hotel_restrictions.hotel_id)
Heap Fetches: 2336
Total runtime: 158.571 ms
(23 rows)

Query plan of Postgres 9.4:

Nested Loop (cost=593.29..625.92 rows=1 width=4) (actual
time=207.395..581946.198 rows=4928 loops=1)
-> Nested Loop (cost=593.14..617.75 rows=1 width=8) (actual
time=207.385..581591.597 rows=4928 loops=1)
-> Index Only Scan using hotels_pkey on hotels (cost=0.38..8.39
rows=1 width=4)
(actual time=0.012..315.263 rows=16197 loops=1)
Heap Fetches: 3062
-> Bitmap Heap Scan on hotel_restrictions (cost=592.77..609.35
rows=1 width=8)
(actual time=35.845..35.852 rows=0 loops=16197)
Recheck Cond: ((restriction_id = 12) AND (status = 1) AND
(hotel_id = hotel
s.id))
Filter: ((((from_time < '2018-01-10'::date) AND (to_time >=
'2018-01-09'::date)) OR ((from_time IS NULL) AND (to_time IS NULL))) AND
((NOT (excluded_days @> (SubPlan
2))) OR (excluded_days IS NULL)))
Rows Removed by Filter: 2
Heap Blocks: exact=33625
-> BitmapAnd (cost=592.77..592.77 rows=1 width=0) (actual
time=35.626..35.626 rows=0 loops=16197)
-> Bitmap Index Scan on hotel_restrictions_multi_
column_status_restriction_id_index (cost=0.00..5.78 rows=135 width=0)
(actual time=30.129..30.129 rows=43908
loops=16197)
Index Cond: ((restriction_id = 12) AND (status =
1))
-> Bitmap Index Scan on
index_hotel_restrictions_on_hotel_id
(cost=0.00..586.73 rows=26973 width=0) (actual time=0.223..0.223 rows=290
loops=16197)
Index Cond: (hotel_id = hotels.id)
SubPlan 2
-> Result (cost=12.54..12.55 rows=1 width=0) (actual
time=0.087..0.087 rows=1 loops=5290)
InitPlan 1 (returns $2)
-> HashAggregate (cost=7.52..12.54 rows=1000
width=0) (actual time=0.036..0.036 rows=1 loops=5290)
Group Key: (date_part('dow'::text,
generate_series((CASE WHEN ('2018-01-09'::date >
hotel_restrictions.from_time) THEN '2018-01-09'::date ELSE hotel_r
estrictions.from_time END)::timestamp with time zone, (CASE WHEN
('2018-01-10'::date <= hotel_restrictions.to_time) THEN '2018-01-09'::date
ELSE hotel_restrictions.to_time END)::tim
estamp with time zone, '1 day'::interval)))::integer
-> Result (cost=0.00..5.02 rows=1000
width=0) (actual time=0.018..0.019 rows=1 loops=5290)
-> Index Only Scan using restrictions_pkey on restrictions
(cost=0.14..8.16 rows=1 width=4) (actual time=0.056..0.057 rows=1
loops=4928)
Index Cond: (id = 12)
Heap Fetches: 0
Planning time: 0.716 ms
Execution time: 581961.388 ms

*3. Query 3*

EXPLAIN ANALYZE SELECT referral_aliases.* FROM referral_aliases WHERE
referral_aliases.user_id = 651659 AND (meta_data ->> 'type' = 'phase_4')
ORDER BYreferral_aliases.id DESC LIMIT 1;

Query plan of Postgres 9.3:

Limit (cost=10.37..10.37 rows=1 width=71) (actual time=0.035..0.035
rows=1 loops=1)
-> Sort (cost=10.37..10.37 rows=1 width=71) (actual time=0.035..0.035
rows=1 loops=1)
Sort Key: id
Sort Method: quicksort Memory: 25kB
-> Index Scan using rahul_temp_refalias on referral_aliases
(cost=0.43..10.36 rows=1 width=71) (actual time=0.025..0.026 rows=1 loops=1)
Index Cond: (user_id = 651659)
Filter: ((meta_data ->> 'type'::text) = 'phase_4'::text)
Total runtime: 0.064 ms
(8 rows)

Query plan of Postgres 9.4:

Limit (cost=0.44..3669.38 rows=1 width=93) (actual
time=26581.387..26581.388 rows=1 loops=1)
-> Index Scan Backward using referral_aliases_pkey on referral_aliases
(cost=0.44..1794114.76 rows=489 width=93) (actual time=26581.384..26581.384
rows=1 loops=1)
Filter: ((user_id = 651659) AND ((meta_data ->> 'type'::text) =
'phase_4'::text))
Rows Removed by Filter: 8574282
Planning time: 0.127 ms
Execution time: 26581.418 ms
(6 rows)

We've tried tweaking several parameters like *effective_cache*,
*enable_indexscan*, *enable_indexonlyscan*, *enable_seqscan*, but to no
results. We've also checked that the *enable_sort* parameter is on in our
parameter group. We also tried doing full vacuum on the tables used in
above queries.

Could you please suggest something so that we can get Postgres 9.4 to
change it's query plan in these cases?

Thanks,
Rahul

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Nicolas Paris 2018-01-13 09:50:55 psql format result as markdown tables
Previous Message Keith 2018-01-13 04:39:26 Re: Updating a pre-10 partitioned table to use PG 10 partitioning