1

We have just upgraded our RDS instance to v12.2 from v11.22, and we are seeing some of the queries are performing much slower than v11.6 instance. Would highly appreciate if can get help with this.

new version: PostgreSQL 12.20 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 7.3.1 20180712 (Red Hat 7.3.1-17), 64-bit

old version: PostgreSQL 11.22 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 7.3.1 20180712 (Red Hat 7.3.1-12), 64-bit

For example, with the query:

explain (buffers, analyze)
select
    "partner_id" as "partnerId",
    "instance_id" as "instanceId",
    "advertiser_id" as "advertiserId",
    "campaign_id" as "campaignId",
    "platform",
    coalesce(SUM("total_budget_spent"), 0) as "totalBudgetSpent",
    coalesce(SUM("total_budget_spent_advertiser_currency"), 0) as "totalBudgetSpentAdvertiserCurrency"
from
    "dsp_hourly_campaign_analytics" as "dsp_hourly_campaign_analytics"
where
    ("dsp_hourly_campaign_analytics"."time" >= 1717596340 -- 1609372800
        and "dsp_hourly_campaign_analytics"."time" < 1724256000) and
    "dsp_hourly_campaign_analytics"."platform" in ('KRTB') and
     "dsp_hourly_campaign_analytics"."campaign_id" in ('247257', '247259', '249282', '266304', '272557', '247258', '247256', '255462', '255461', '246096', '275592', '275593', '275668', '275681', '270524', '270557', '269423', '270838')
group by
    "partner_id",
    "instance_id",
    "advertiser_id",
    "campaign_id",
    "platform"
limit 2147483647 offset 0;

on v11, output is:

Limit  (cost=8516.52..8526.36 rows=656 width=104) (actual time=878.502..878.514 rows=13 loops=1)
  Buffers: shared hit=718 read=8521
  I/O Timings: read=851.931
  ->  HashAggregate  (cost=8516.52..8526.36 rows=656 width=104) (actual time=878.501..878.511 rows=13 loops=1)
        Group Key: dsp_hourly_campaign_analytics.partner_id, dsp_hourly_campaign_analytics.instance_id, dsp_hourly_campaign_analytics.advertiser_id, dsp_hourly_campaign_analytics.campaign_id, dsp_hourly_campaign_analytics.platform
        Buffers: shared hit=718 read=8521
        I/O Timings: read=851.931
        ->  Append  (cost=0.00..8401.74 rows=6559 width=56) (actual time=0.087..875.336 rows=6542 loops=1)
              Buffers: shared hit=718 read=8521
              I/O Timings: read=851.931
              ->  Seq Scan on dsp_hourly_campaign_analytics  (cost=0.00..0.00 rows=1 width=2596) (actual time=0.003..0.003 rows=0 loops=1)
                    Filter: (("time" >= 1717596340) AND ("time" < 1724256000) AND ((platform)::text = 'KRTB'::text) AND ((campaign_id)::text = ANY ('{247257,247259,249282,266304,272557,247258,247256,255462,255461,246096,275592,275593,275668,275681,270524,270557,269423,270838}'::text[])))
              ->  Index Scan using dsp_hourly_campaign_analytics_202406_campaign_index_202406 on dsp_hourly_campaign_analytics_202406 dsp_hourly_campaign_analytics_1  (cost=0.43..2559.39 rows=1828 width=56) (actual time=0.084..37.129 rows=3536 loops=1)
                    Index Cond: ((campaign_id)::text = ANY ('{247257,247259,249282,266304,272557,247258,247256,255462,255461,246096,275592,275593,275668,275681,270524,270557,269423,270838}'::text[]))
                    Filter: (("time" >= 1717596340) AND ("time" < 1724256000) AND ((platform)::text = 'KRTB'::text))
                    Rows Removed by Filter: 892
                    Buffers: shared hit=377 read=5493
                    I/O Timings: read=24.067
              ->  Index Scan using dsp_hourly_campaign_analytics_202407_campaign_index_202407 on dsp_hourly_campaign_analytics_202407 dsp_hourly_campaign_analytics_2  (cost=0.43..3682.56 rows=3229 width=56) (actual time=0.541..824.004 rows=2853 loops=1)
                    Index Cond: ((campaign_id)::text = ANY ('{247257,247259,249282,266304,272557,247258,247256,255462,255461,246096,275592,275593,275668,275681,270524,270557,269423,270838}'::text[]))
                    Filter: (("time" >= 1717596340) AND ("time" < 1724256000) AND ((platform)::text = 'KRTB'::text))
                    Buffers: shared hit=170 read=2979
                    I/O Timings: read=814.945
              ->  Index Scan using dsp_hourly_campaign_analytics_202408_campaign_index_202408 on dsp_hourly_campaign_analytics_202408 dsp_hourly_campaign_analytics_3  (cost=0.42..2126.99 rows=1501 width=56) (actual time=0.050..13.398 rows=153 loops=1)
                    Index Cond: ((campaign_id)::text = ANY ('{247257,247259,249282,266304,272557,247258,247256,255462,255461,246096,275592,275593,275668,275681,270524,270557,269423,270838}'::text[]))
                    Filter: (("time" >= 1717596340) AND ("time" < 1724256000) AND ((platform)::text = 'KRTB'::text))
                    Rows Removed by Filter: 13
                    Buffers: shared hit=171 read=49
                    I/O Timings: read=12.919
Planning Time: 28.975 ms
Execution Time: 878.663 ms

but on v12, plan seems not as performant, output below:

Limit  (cost=8413.26..8422.96 rows=647 width=104) (actual time=8997.791..8997.807 rows=11 loops=1)
  Buffers: shared hit=180 read=6096
  I/O Timings: read=8953.020
  ->  HashAggregate  (cost=8413.26..8422.96 rows=647 width=104) (actual time=8997.789..8997.804 rows=11 loops=1)
        Group Key: dsp_hourly_campaign_analytics.partner_id, dsp_hourly_campaign_analytics.instance_id, dsp_hourly_campaign_analytics.advertiser_id, dsp_hourly_campaign_analytics.campaign_id, dsp_hourly_campaign_analytics.platform
        Buffers: shared hit=180 read=6096
        I/O Timings: read=8953.020
        ->  Append  (cost=0.00..8300.00 rows=6472 width=56) (actual time=1.994..8990.356 rows=5656 loops=1)
              Buffers: shared hit=180 read=6096
              I/O Timings: read=8953.020
              ->  Seq Scan on dsp_hourly_campaign_analytics  (cost=0.00..0.00 rows=1 width=2596) (actual time=0.008..0.008 rows=0 loops=1)
                    Filter: (("time" >= 1717596340) AND ("time" < 1724256000) AND ((platform)::text = 'KRTB'::text) AND ((campaign_id)::text = ANY ('{247257,247259,249282,266304,272557,247258,247256,255462,255461,246096,275592,275593,275668,275681,270524,270557,269423,270838}'::text[])))
              ->  Index Scan using dsp_hourly_campaign_analytics_202406_campaign_index_202406 on dsp_hourly_campaign_analytics_202406 dsp_hourly_campaign_analytics_1  (cost=0.43..3421.11 rows=2471 width=56) (actual time=1.985..3781.430 rows=2666 loops=1)
                    Index Cond: ((campaign_id)::text = ANY ('{247257,247259,249282,266304,272557,247258,247256,255462,255461,246096,275592,275593,275668,275681,270524,270557,269423,270838}'::text[]))
                    Filter: (("time" >= 1717596340) AND ("time" < 1724256000) AND ((platform)::text = 'KRTB'::text))
                    Rows Removed by Filter: 440
                    Buffers: shared hit=75 read=3088
                    I/O Timings: read=3761.303
              ->  Index Scan using dsp_hourly_campaign_analytics_202407_campaign_index_202407 on dsp_hourly_campaign_analytics_202407 dsp_hourly_campaign_analytics_2  (cost=0.43..2730.11 rows=2386 width=56) (actual time=2.510..4979.345 rows=2837 loops=1)
                    Index Cond: ((campaign_id)::text = ANY ('{247257,247259,249282,266304,272557,247258,247256,255462,255461,246096,275592,275593,275668,275681,270524,270557,269423,270838}'::text[]))
                    Filter: (("time" >= 1717596340) AND ("time" < 1724256000) AND ((platform)::text = 'KRTB'::text))
                    Buffers: shared hit=62 read=2835
                    I/O Timings: read=4964.716
              ->  Index Scan using dsp_hourly_campaign_analytics_202408_campaign_index_202408 on dsp_hourly_campaign_analytics_202408 dsp_hourly_campaign_analytics_3  (cost=0.42..2116.42 rows=1614 width=56) (actual time=21.175..227.975 rows=153 loops=1)
                    Index Cond: ((campaign_id)::text = ANY ('{247257,247259,249282,266304,272557,247258,247256,255462,255461,246096,275592,275593,275668,275681,270524,270557,269423,270838}'::text[]))
                    Filter: (("time" >= 1717596340) AND ("time" < 1724256000) AND ((platform)::text = 'KRTB'::text))
                    Rows Removed by Filter: 9
                    Buffers: shared hit=43 read=173
                    I/O Timings: read=227.000
Planning Time: 7.668 ms
Execution Time: 8997.911 ms

The tables are organized into partitions based on inherit like below:

CREATE TABLE public.dsp_hourly_campaign_analytics_202402 (
    CONSTRAINT dsp_hourly_campaign_analytics_202402_time_check CHECK ((("time" >= 1706745600) AND ("time" < 1709251200)))
)
INHERITS (public.dsp_hourly_campaign_analytics);
CREATE INDEX dsp_hourly_campaign_analytics_202402_advertiser_index_202402 ON public.dsp_hourly_campaign_analytics_202402 USING btree (advertiser_id);
CREATE INDEX dsp_hourly_campaign_analytics_202402_campaign_index_202402 ON public.dsp_hourly_campaign_analytics_202402 USING btree (campaign_id);
CREATE INDEX dsp_hourly_campaign_analytics_202402_instance_index_202402 ON public.dsp_hourly_campaign_analytics_202402 USING btree (instance_id);
CREATE INDEX dsp_hourly_campaign_analytics_202402_partner_index_202402 ON public.dsp_hourly_campaign_analytics_202402 USING btree (partner_id);
CREATE UNIQUE INDEX dsp_hourly_campaign_analytics_202402_pkey_202402 ON public.dsp_hourly_campaign_analytics_202402 USING btree ("time", advertiser_id, campaign_id, platform, publisher_channel, publisher_platform);
CREATE INDEX dsp_hourly_campaign_analytics_202402_platform_index_202402 ON public.dsp_hourly_campaign_analytics_202402 USING btree (platform);
CREATE INDEX idx_dsp_hourly_campaign_analytics_202402_time ON public.dsp_hourly_campaign_analytics_202402 USING btree ("time");
Improve this question
5
  • 1
    Looks to me like it just much worse caching at the OS level. Similar amounts of data are read, but it takes far longer to do it. If you repeat the exact same query back to back, does the performance difference go away?
    – jjanes
    Commented Aug 27 at 16:24
  • Hi @jjanes, thanks for a prompt response! I have just run the "explain (analyze, buffers)" query above again. not much different, v12 actual time got a bit improved, but still far worse compared to v11. v12, total cost: Limit (cost=8413.26..8422.96 rows=647 width=104) (actual time=5895.697..5895.714 rows=11 loops=1)
    – Vinh Lam
    Commented Aug 27 at 16:59
  • It is hard to explain this as a purely PostgreSQL software issue. I would say that either your hardware got downgraded, or maybe RDS hacking of the community code has gone awry. Did you do a pg_upgrade, or dump/restore, or something else? Maybe the upgrade process consumed all your IO burst credits and they haven't recovered yet?
    – jjanes
    Commented Aug 27 at 19:18
  • After upgrading (using pg_upgrade), we did run analyzing all tables, and used pg_dump to migrate data from Production to QA environment. There is nothing else special. It has been a few days already, so not sure how long does it take for the IO burst to recover. How can we check if our IO burst credits is fine?
    – Vinh Lam
    Commented Aug 28 at 2:18
  • Not my field of expertise, but I would expect burst credits to have recovered in a few days. Unless you keep trying the test over and over, so they are constantly depleted them again. I am confused about the QA environment though. Is that where the problem is happening, or is it happening in Production, or both? Are you sure you didn't accidentally reduce your machine size or you "class" of IO when you did the upgrade?
    – jjanes
    Commented Aug 28 at 14:56

0

Reset to default

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.