Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1u1lqm-007moC-0G for pgsql-general@arkaria.postgresql.org; Mon, 07 Apr 2025 12:45:16 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.94.2) (envelope-from ) id 1u1lqk-00FwyD-E9 for pgsql-general@arkaria.postgresql.org; Mon, 07 Apr 2025 12:45:14 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1u1lqj-00Fwy4-UC for pgsql-general@lists.postgresql.org; Mon, 07 Apr 2025 12:45:14 +0000 Received: from mail-ua1-x935.google.com ([2607:f8b0:4864:20::935]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.96) (envelope-from ) id 1u1lqi-003v4S-0L for pgsql-general@lists.postgresql.org; Mon, 07 Apr 2025 12:45:13 +0000 Received: by mail-ua1-x935.google.com with SMTP id a1e0cc1a2514c-86929964ed3so3951663241.0 for ; Mon, 07 Apr 2025 05:45:11 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=dbtune.com; s=google; t=1744029910; x=1744634710; darn=lists.postgresql.org; h=to:subject:message-id:date:from:mime-version:from:to:cc:subject :date:message-id:reply-to; bh=2RX/7M3y1ZHBpdCUa1gCbhdJ8be+dJHeRMiuh/w1q00=; b=GfPm1PsSyAxXqsG7eW/FwdcwmBbT/RFsDEKm7yOHGERF/u9wb9p1yNwQhKrKsBasB9 7t+V7ojhyJUIDnzosOTdljIsBLxoc95n3+qjB7Jl4bhf7IpvrJmcB85IvoOYq85D/yXl eFhBvJqAPrlfLWWFRKSXwQlzAB9wNWui6aJJtf01CMRe3Dl59NDNbA91qM2kSOxbSBb1 TFH4n8GzIls/pGV3Q5AO9IoKXD62aBCSZoY1dsd/DHri01UQNAN7PSlLEY8cAhnk7Nh4 jakiREb6GOG04gY1Cue8SmEro5aCmb1hxsKcOEOkanp/6FdGeK8RGuQbXn5ld8fRVA+C 2DyA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1744029910; x=1744634710; h=to:subject:message-id:date:from:mime-version:x-gm-message-state :from:to:cc:subject:date:message-id:reply-to; bh=2RX/7M3y1ZHBpdCUa1gCbhdJ8be+dJHeRMiuh/w1q00=; b=ZJ5Y9i1l2GRY2UZBz0Ka4pTtfGunojWIqmV3QqsRwJQivD6OSEALTf7SIiahTFpxWJ 51N0iLDO/LDQyQYy2usdZCf1QOZKyb2gwbTpyfJqdmwLtWceydqUs3N14Bxo7/VJgFXo 6XacWapFwi4zdjm08o952NyO1x33xmixNaLzajSIiDlDpJKYNkgZsjupJs6QIjujQDjo sgnsRzmf0r0vQJhHJCls4fSxtERyMl6xYPmfV4MH2X0dWZjajWLSRUK2rYdkoWKWWffN VXOOTLwnZZiu41xGgcVbF+b3l6PbOoGY99SUL57Zku4zjntWTAQWGuKdjR1+/cpIujMG lCVg== X-Gm-Message-State: AOJu0Yyc5vi4hVvimHXDeLss3Qdk4yzGxFxENGXX/LFxCvOFoNuB8dhW YoLEoOUvKcdL2c27Yeoe/lfJFT7utBspjn5IuyQMslWJWX8FSPQJFswMMD3AcFNLCsUkUH8IWzq dATvKgei3JuzooD6EDr5boNKiXNgcjiKZrUJdywTe+my4qcnXfyI= X-Gm-Gg: ASbGncso+f8rbVjD+4lLYoCSw+ZgbYeWSYwcfoj/x6aiAutDbH+AS+wBShLH7sBWlBt /Cf1aTiYStSrzlwhqaKV9byw3DtsJX8YbhvYBKEVwvMcK4KpjzRlOq62q+aRdolnr9I9DVOhgQB H1MxZzZ2My/ASo735J820v5Lf6TWNg X-Google-Smtp-Source: AGHT+IE8YkcTnEmc03H6HQWJ3X4zgZppkLHhExzBy2yBn1v34Uhdh6Pg9qt4br132MLUvhZgrOjbSWFS0LfL7SXVfcM= X-Received: by 2002:a05:6102:f89:b0:4c4:e451:6f24 with SMTP id ada2fe7eead31-4c856a62181mr8452360137.22.1744029910165; Mon, 07 Apr 2025 05:45:10 -0700 (PDT) MIME-Version: 1.0 From: Costa Alexoglou Date: Mon, 7 Apr 2025 14:44:58 +0200 X-Gm-Features: ATxdqUFoT0vlhkR9Rpm5JQYFQi57H51AJeqSBnXqoNdT9nJM37kIRxccen0TfGw Message-ID: Subject: Performance regression when adding LIMIT 1 to a query To: pgsql-general@lists.postgresql.org Content-Type: multipart/alternative; boundary="000000000000460c1f06322f9bb9" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --000000000000460c1f06322f9bb9 Content-Type: text/plain; charset="UTF-8" Hey folks, I faced an interesting regression and would love to have some help understanding why this happened. The postgres version if it's of any use is PostgreSQL 16.3 . The following query: ``` EXPLAIN ANALYZE SELECT "databases_metrics"."metrics" FROM "databases_metrics" WHERE ( "databases_metrics"."created_at" >= '2023-03-15 10:00:00+00:00'::timestamptz AND "databases_metrics"."db_instance_id" = 'c4c97a60-b88e-4cd3-a2f1-random-uuid'::UUID AND "databases_metrics"."created_at" <= '2025-04-03 10:00:00+00:00'::timestamptz AND ( metrics -> 'perf_average_query_runtime' IS NOT NULL ) ) ORDER BY "databases_metrics"."id" ASC; ``` with a plan: ``` Gather Merge (cost=115584.47..118515.35 rows=25120 width=824) (actual time=46.004..74.267 rows=29653 loops=1) Workers Planned: 2 Workers Launched: 2 -> Sort (cost=114584.45..114615.85 rows=12560 width=824) (actual time=41.200..47.322 rows=9884 loops=3) Sort Key: id Sort Method: external merge Disk: 16360kB Worker 0: Sort Method: external merge Disk: 15552kB Worker 1: Sort Method: external merge Disk: 14536kB -> Parallel Bitmap Heap Scan on databases_metrics (cost=990.77..109175.83 rows=12560 width=824) (actual time=3.326..14.295 rows=9884 loops=3) Recheck Cond: ((db_instance_id = 'c4c97a60-b88e-4cd3-a2f1-random-uuid'::uuid) AND (created_at >= '2023-03-15 10:00:00+00'::timestamp with time zone) AND (created_at <= '2025-04-03 10:00:00+00'::timestamp with time zone))"}, Filter: ((metrics -> 'perf_average_query_runtime'::text) IS NOT NULL) Rows Removed by Filter: 68 Heap Blocks: exact=4272 -> Bitmap Index Scan on idx_databases_metrics_instance_date_custom_created_debugging (cost=0.00..983.24 rows=30294 width=0) (actual time=3.786.786 rows=29856 loops=1)"}, Index Cond: ((db_instance_id = 'c4c97a60-b88e-4cd3-a2f1-random-uuid'::uuid) AND (created_at >= '2023-03-15 10:00:00+00'::timestamp with time zone) AND (created_at <= '2025-04-03 10:00:00+00'::timestamp with time zone))"}, Planning Time: 0.126 ms Execution Time: 79.334 ms ``` Results in an execution time of `79.334ms` which is ok. Then if I only add a `LIMIT 1` at the end of the query, I get dramatically slower execution: ``` EXPLAIN ANALYZE SELECT "databases_metrics"."metrics" FROM "databases_metrics" WHERE ( "databases_metrics"."created_at" >= '2023-03-15 10:00:00+00:00'::timestamptz AND "databases_metrics"."db_instance_id" = 'c4c97a60-b88e-4cd3-a2f1-random-uuid'::UUID AND "databases_metrics"."created_at" <= '2025-04-03 10:00:00+00:00'::timestamptz AND ( metrics -> 'perf_average_query_runtime' IS NOT NULL ) ) ORDER BY "databases_metrics"."id" ASC LIMIT 1; ``` With a plan: ``` Limit (cost=0.43..229.66 rows=1 width=824) (actual time=7538.004..7538.005 rows=1 loops=1) -> Index Scan using databases_metrics_pkey on databases_metrics (cost=0.43..6909156.38 rows=30142 width=824) (actual time=7538.002..7538.003 rows=1 loops=1) Filter: ((created_at >= '2023-03-15 10:00:00+00'::timestamp with time zone) AND (created_at <= '2025-04-03 10:00:00+00'::timestamp with time zone) A((metrics -> 'perf_average_query_runtime'::text) IS NOT NULL) AND (db_instance_id = 'c4c97a60-b88e-4cd3-a2f1-random-uuid'::uuid))"}, Rows Removed by Filter: 10244795 Planning Time: 0.128 ms Execution Time: 7538.032 ms ``` Any clue why this may be happening? --000000000000460c1f06322f9bb9 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
Hey folks,

I faced an interesting=C2=A0= regression and would love to have some help understanding why this happened= .

The postgres version if it's of any use is=C2=A0PostgreSQL 16.= 3 .

The following query:
```
EXPLAIN ANALYZE=
SELECT "databases_metrics"."metrics"
FROM
=C2= =A0 "databases_metrics"
WHERE
=C2=A0 (
=C2=A0 =C2=A0 &qu= ot;databases_metrics"."created_at" >=3D '2023-03-15 1= 0:00:00+00:00'::timestamptz
=C2=A0 =C2=A0 AND "databases_metric= s"."db_instance_id" =3D 'c4c97a60-b88e-4cd3-a2f1-random-= uuid'::UUID
=C2=A0 =C2=A0 AND "databases_metrics"."cr= eated_at" <=3D '2025-04-03 10:00:00+00:00'::timestamptz
= =C2=A0 =C2=A0 AND (
=C2=A0 =C2=A0 =C2=A0 metrics -> 'perf_average= _query_runtime' IS NOT NULL
=C2=A0 =C2=A0 )
=C2=A0 )
ORDER BY<= br>=C2=A0 "databases_metrics"."id" ASC;
```
with a plan:
```
Gather Merge =C2=A0(cost=3D115584.47..118515.3= 5 rows=3D25120 width=3D824) (actual time=3D46.004..74.267 rows=3D29653 loop= s=3D1)
=C2=A0 Workers Planned: 2
=C2=A0 Workers Launched: 2
=C2=A0= -> =C2=A0Sort =C2=A0(cost=3D114584.45..114615.85 rows=3D12560 width=3D8= 24) (actual time=3D41.200..47.322 rows=3D9884 loops=3D3)
=C2=A0 =C2=A0 = =C2=A0 =C2=A0 Sort Key: id
=C2=A0 =C2=A0 =C2=A0 =C2=A0 Sort Method: exte= rnal merge =C2=A0Disk: 16360kB
=C2=A0 =C2=A0 =C2=A0 =C2=A0 Worker 0: =C2= =A0Sort Method: external merge =C2=A0Disk: 15552kB
=C2=A0 =C2=A0 =C2=A0 = =C2=A0 Worker 1: =C2=A0Sort Method: external merge =C2=A0Disk: 14536kB
= =C2=A0 =C2=A0 =C2=A0 =C2=A0 -> =C2=A0Parallel Bitmap Heap Scan on databa= ses_metrics =C2=A0(cost=3D990.77..109175.83 rows=3D12560 width=3D824) (actu= al time=3D3.326..14.295 rows=3D9884 loops=3D3)
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 Recheck Cond: ((db_instance_id =3D 'c4c97a60-b= 88e-4cd3-a2f1-random-uuid'::uuid) AND (created_at >=3D '2023-03-= 15 10:00:00+00'::timestamp with time zone) AND (created_at <=3D '= ;2025-04-03 10:00:00+00'::timestamp with time zone))"},
=C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 Filter: ((metrics -> 'perf= _average_query_runtime'::text) IS NOT NULL)
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 Rows Removed by Filter: 68
=C2=A0 =C2=A0 =C2=A0= =C2=A0 =C2=A0 =C2=A0 =C2=A0 Heap Blocks: exact=3D4272
=C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 -> =C2=A0Bitmap Index Scan on idx_databa= ses_metrics_instance_date_custom_created_debugging =C2=A0(cost=3D0.00..983.= 24 rows=3D30294 width=3D0) (actual time=3D3.786.786 rows=3D29856 loops=3D1)= "},
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 Index Cond: ((db_instance_id =3D 'c4c97a60-b88e-4cd3-a2f1-random= -uuid'::uuid) AND (created_at >=3D '2023-03-15 10:00:00+00':= :timestamp with time zone) AND (created_at <=3D '2025-04-03 10:00:00= +00'::timestamp with time zone))"},
Planning Time: 0.126 ms
= Execution Time: 79.334 ms
```

Results in an execution time of `79= .334ms` which is ok.


Then if I only add a `LIMIT 1` at the end o= f the query, I get dramatically slower execution:

= ```
EXPLAIN ANALYZE
SELECT "databases_metrics"."metric= s"
FROM
=C2=A0 "databases_metrics"
WHERE
=C2=A0 = (
=C2=A0 =C2=A0 "databases_metrics"."created_at" >= ;=3D '2023-03-15 10:00:00+00:00'::timestamptz
=C2=A0 =C2=A0 AND = "databases_metrics"."db_instance_id" =3D 'c4c97a60-= b88e-4cd3-a2f1-random-uuid'::UUID
=C2=A0 =C2=A0 AND "databases_= metrics"."created_at" <=3D '2025-04-03 10:00:00+00:00= '::timestamptz
=C2=A0 =C2=A0 AND (
=C2=A0 =C2=A0 =C2=A0 metrics -= > 'perf_average_query_runtime' IS NOT NULL
=C2=A0 =C2=A0 )=C2=A0 )
ORDER BY
=C2=A0 "databases_metrics"."id"= ; ASC LIMIT 1;
```

With a plan:
```
Limit =C2=A0(cost=3D0.4= 3..229.66 rows=3D1 width=3D824) (actual time=3D7538.004..7538.005 rows=3D1 = loops=3D1)
=C2=A0 -> =C2=A0Index Scan using databases_metrics_pkey on= databases_metrics =C2=A0(cost=3D0.43..6909156.38 rows=3D30142 width=3D824)= (actual time=3D7538.002..7538.003 rows=3D1 loops=3D1)
=C2=A0 =C2=A0 =C2= =A0 =C2=A0 Filter: ((created_at >=3D '2023-03-15 10:00:00+00'::t= imestamp with time zone) AND (created_at <=3D '2025-04-03 10:00:00+0= 0'::timestamp with time zone) A((metrics -> 'perf_average_query_= runtime'::text) IS NOT NULL) AND (db_instance_id =3D 'c4c97a60-b88e= -4cd3-a2f1-random-uuid'::uuid))"},
=C2=A0 =C2=A0 =C2=A0 =C2=A0 = Rows Removed by Filter: 10244795
Planning Time: 0.128 ms
Execution Ti= me: 7538.032 ms
```

Any clue why this may be happening?
--000000000000460c1f06322f9bb9--