pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedQueries containing ORDER BY and LIMIT started to work slowly
11+ messages / 4 participants
[nested] [flat]
* Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-08-29 17:47 Rondat Flyag <rondatflyag@yandex.ru>
0 siblings, 1 reply; 11+ messages in thread
From: Rondat Flyag @ 2023-08-29 17:47 UTC (permalink / raw)
To: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
Table "public.asins_statistics"
Column | Type | Modifiers
-----------------------+-----------------------------+---------------------------------------------------------------
id | integer | not null default nextval('asins_statistics_id_seq'::regclass)
average_cost_amazon | double precision |
average_price_new | double precision |
quantity_sold_new | double precision |
quantity_in_transit | double precision |
quantity_present_new | double precision |
ranks_thirty | integer |
ranks_ninety | integer |
average_profit_new | double precision |
average_roi_new | double precision |
average_selling_time | double precision |
asin_id | integer |
average_cost_aob | double precision |
last_sold | timestamp without time zone |
average_price_used | double precision |
quantity_sold_used | integer |
quantity_present_used | integer |
average_profit_used | double precision |
Indexes:
"asins_statistics_pkey" PRIMARY KEY, btree (id)
Foreign-key constraints:
"asins_statistics_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
Table "public.books"
Column | Type | Modifiers
--------------------------------------------+-----------------------------+----------------------------------------------------
id | integer | not null default nextval('books_id_seq'::regclass)
link | character varying(300) |
asin | character varying(60) |
title | character varying(400) |
isbn | character varying(50) |
newer_edition_available | boolean |
newer_edition_link | character varying(150) |
cover_type | character varying(100) |
block_until | timestamp without time zone |
latest_trade_in_available | boolean |
latest_trade_in_price | double precision |
latest_rank | bigint |
latest_profit_like_new | double precision |
latest_profit_very_good | double precision |
latest_profit_ratio | double precision |
latest_profit_trade_in | double precision |
category_id | integer |
aob_username | character varying(250) |
latest_minimum_price | double precision |
latest_minimum_shipping | double precision |
bsr | integer | default 1000
quantity_in_transit | integer | default 0
latest_minimum_price_like_new | double precision | default '1000000'::double precision
latest_minimum_price_very_good | double precision | default '1000000'::double precision
latest_minimum_shipping_like_new | double precision | default '1000000'::double precision
latest_minimum_shipping_very_good | double precision | default '1000000'::double precision
total_minimum_price_and_shipping | double precision |
recent_minimum_price_and_shipping | double precision |
seventy_five_percentile_price_and_shipping | double precision |
bsr_str | character varying(50) |
bsr_id | integer |
latest_profit_ratio_like_new | double precision |
latest_profit_ratio_very_good | double precision |
Indexes:
"books_pkey" PRIMARY KEY, btree (id)
"books_asin_key" UNIQUE CONSTRAINT, btree (asin)
"books_isbn_key" UNIQUE CONSTRAINT, btree (isbn)
"books_link_key" UNIQUE CONSTRAINT, btree (link)
"index_asin_books" btree (asin)
"index_isbn_books" btree (isbn)
"index_latest_rank_books" btree (latest_rank)
"index_title_books" btree (title)
Table "public.asins"
Column | Type | Modifiers
------------------+-----------------------+----------------------------------------------------
id | integer | not null default nextval('isbns_id_seq'::regclass)
value | character varying(50) |
rank_type | popularitytypeenum |
sell_constraints | character varying(50) |
isbn_thirteen | character varying(20) |
Indexes:
"isbns_pkey" PRIMARY KEY, btree (id)
"isbns_value_key" UNIQUE CONSTRAINT, btree (value)
"index_value_asins" btree (value)
Referenced by:
TABLE "asins_statistics" CONSTRAINT "asins_statistics_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "books_to_replenish" CONSTRAINT "books_to_replenish_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "inventory_item" CONSTRAINT "inventory_item_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "inventory_items" CONSTRAINT "inventory_items_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "orders_on_amazon" CONSTRAINT "orders_on_amazon_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "orders_on_amazon_sold" CONSTRAINT "orders_on_amazon_sold_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=1048379.37..1048428.33 rows=100 width=498) (actual time=5264.193..5264.444 rows=100 loops=1)
Buffers: shared hit=40250 read=332472, temp read=16699 written=28392
-> Merge Join (cost=1048379.37..2291557.51 rows=2539360 width=498) (actual time=5264.191..5264.436 rows=100 loops=1)
Merge Cond: ((books.isbn)::text = (isbns.value)::text)
Buffers: shared hit=40250 read=332472, temp read=16699 written=28392
-> Index Scan using books_isbn_key on books (cost=0.43..1205494.88 rows=1386114 width=333) (actual time=0.020..0.150 rows=100 loops=1)
Buffers: shared hit=103
-> Materialize (cost=1042333.77..1055199.75 rows=2573197 width=155) (actual time=5263.901..5263.960 rows=100 loops=1)
Buffers: shared hit=40147 read=332472, temp read=16699 written=28392
-> Sort (cost=1042333.77..1048766.76 rows=2573197 width=155) (actual time=5263.895..5263.949 rows=100 loops=1)
Sort Key: isbns.value
Sort Method: external merge Disk: 136864kB
Buffers: shared hit=40147 read=332472, temp read=16699 written=28392
-> Hash Join (cost=55734.14..566061.44 rows=2573197 width=155) (actual time=403.962..1994.884 rows=1404582 loops=1)
Hash Cond: (isbns_statistics.isbn_id = isbns.id)
Buffers: shared hit=40147 read=332472, temp read=11281 written=11279
-> Seq Scan on isbns_statistics (cost=0.00..385193.97 rows=2573197 width=120) (actual time=0.024..779.717 rows=1404582 loops=1)
Buffers: shared hit=26990 read=332472
-> Hash (cost=27202.84..27202.84 rows=1404584 width=35) (actual time=402.431..402.431 rows=1404584 loops=1)
Buckets: 1048576 Batches: 2 Memory Usage: 51393kB
Buffers: shared hit=13157, temp written=4363
-> Seq Scan on isbns (cost=0.00..27202.84 rows=1404584 width=35) (actual time=0.027..152.568 rows=1404584 loops=1)
Buffers: shared hit=13157
Planning time: 1.160 ms
Execution time: 5279.983 ms
(25 rows)
Attachments:
[text/plain] asins_statistics_schema.txt (1.6K, ../../32431693330715@mail.yandex.ru/2-asins_statistics_schema.txt)
download | inline:
Table "public.asins_statistics"
Column | Type | Modifiers
-----------------------+-----------------------------+---------------------------------------------------------------
id | integer | not null default nextval('asins_statistics_id_seq'::regclass)
average_cost_amazon | double precision |
average_price_new | double precision |
quantity_sold_new | double precision |
quantity_in_transit | double precision |
quantity_present_new | double precision |
ranks_thirty | integer |
ranks_ninety | integer |
average_profit_new | double precision |
average_roi_new | double precision |
average_selling_time | double precision |
asin_id | integer |
average_cost_aob | double precision |
last_sold | timestamp without time zone |
average_price_used | double precision |
quantity_sold_used | integer |
quantity_present_used | integer |
average_profit_used | double precision |
Indexes:
"asins_statistics_pkey" PRIMARY KEY, btree (id)
Foreign-key constraints:
"asins_statistics_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
[text/plain] books_schema.txt (3.4K, ../../32431693330715@mail.yandex.ru/3-books_schema.txt)
download | inline:
Table "public.books"
Column | Type | Modifiers
--------------------------------------------+-----------------------------+----------------------------------------------------
id | integer | not null default nextval('books_id_seq'::regclass)
link | character varying(300) |
asin | character varying(60) |
title | character varying(400) |
isbn | character varying(50) |
newer_edition_available | boolean |
newer_edition_link | character varying(150) |
cover_type | character varying(100) |
block_until | timestamp without time zone |
latest_trade_in_available | boolean |
latest_trade_in_price | double precision |
latest_rank | bigint |
latest_profit_like_new | double precision |
latest_profit_very_good | double precision |
latest_profit_ratio | double precision |
latest_profit_trade_in | double precision |
category_id | integer |
aob_username | character varying(250) |
latest_minimum_price | double precision |
latest_minimum_shipping | double precision |
bsr | integer | default 1000
quantity_in_transit | integer | default 0
latest_minimum_price_like_new | double precision | default '1000000'::double precision
latest_minimum_price_very_good | double precision | default '1000000'::double precision
latest_minimum_shipping_like_new | double precision | default '1000000'::double precision
latest_minimum_shipping_very_good | double precision | default '1000000'::double precision
total_minimum_price_and_shipping | double precision |
recent_minimum_price_and_shipping | double precision |
seventy_five_percentile_price_and_shipping | double precision |
bsr_str | character varying(50) |
bsr_id | integer |
latest_profit_ratio_like_new | double precision |
latest_profit_ratio_very_good | double precision |
Indexes:
"books_pkey" PRIMARY KEY, btree (id)
"books_asin_key" UNIQUE CONSTRAINT, btree (asin)
"books_isbn_key" UNIQUE CONSTRAINT, btree (isbn)
"books_link_key" UNIQUE CONSTRAINT, btree (link)
"index_asin_books" btree (asin)
"index_isbn_books" btree (isbn)
"index_latest_rank_books" btree (latest_rank)
"index_title_books" btree (title)
[text/plain] asins_schema.txt (1.5K, ../../32431693330715@mail.yandex.ru/4-asins_schema.txt)
download | inline:
Table "public.asins"
Column | Type | Modifiers
------------------+-----------------------+----------------------------------------------------
id | integer | not null default nextval('isbns_id_seq'::regclass)
value | character varying(50) |
rank_type | popularitytypeenum |
sell_constraints | character varying(50) |
isbn_thirteen | character varying(20) |
Indexes:
"isbns_pkey" PRIMARY KEY, btree (id)
"isbns_value_key" UNIQUE CONSTRAINT, btree (value)
"index_value_asins" btree (value)
Referenced by:
TABLE "asins_statistics" CONSTRAINT "asins_statistics_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "books_to_replenish" CONSTRAINT "books_to_replenish_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "inventory_item" CONSTRAINT "inventory_item_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "inventory_items" CONSTRAINT "inventory_items_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "orders_on_amazon" CONSTRAINT "orders_on_amazon_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
TABLE "orders_on_amazon_sold" CONSTRAINT "orders_on_amazon_sold_asin_id_fkey" FOREIGN KEY (asin_id) REFERENCES asins(id) ON DELETE CASCADE
[text/plain] query_plan.txt (2.7K, ../../32431693330715@mail.yandex.ru/5-query_plan.txt)
download | inline:
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=1048379.37..1048428.33 rows=100 width=498) (actual time=5264.193..5264.444 rows=100 loops=1)
Buffers: shared hit=40250 read=332472, temp read=16699 written=28392
-> Merge Join (cost=1048379.37..2291557.51 rows=2539360 width=498) (actual time=5264.191..5264.436 rows=100 loops=1)
Merge Cond: ((books.isbn)::text = (isbns.value)::text)
Buffers: shared hit=40250 read=332472, temp read=16699 written=28392
-> Index Scan using books_isbn_key on books (cost=0.43..1205494.88 rows=1386114 width=333) (actual time=0.020..0.150 rows=100 loops=1)
Buffers: shared hit=103
-> Materialize (cost=1042333.77..1055199.75 rows=2573197 width=155) (actual time=5263.901..5263.960 rows=100 loops=1)
Buffers: shared hit=40147 read=332472, temp read=16699 written=28392
-> Sort (cost=1042333.77..1048766.76 rows=2573197 width=155) (actual time=5263.895..5263.949 rows=100 loops=1)
Sort Key: isbns.value
Sort Method: external merge Disk: 136864kB
Buffers: shared hit=40147 read=332472, temp read=16699 written=28392
-> Hash Join (cost=55734.14..566061.44 rows=2573197 width=155) (actual time=403.962..1994.884 rows=1404582 loops=1)
Hash Cond: (isbns_statistics.isbn_id = isbns.id)
Buffers: shared hit=40147 read=332472, temp read=11281 written=11279
-> Seq Scan on isbns_statistics (cost=0.00..385193.97 rows=2573197 width=120) (actual time=0.024..779.717 rows=1404582 loops=1)
Buffers: shared hit=26990 read=332472
-> Hash (cost=27202.84..27202.84 rows=1404584 width=35) (actual time=402.431..402.431 rows=1404584 loops=1)
Buckets: 1048576 Batches: 2 Memory Usage: 51393kB
Buffers: shared hit=13157, temp written=4363
-> Seq Scan on isbns (cost=0.00..27202.84 rows=1404584 width=35) (actual time=0.027..152.568 rows=1404584 loops=1)
Buffers: shared hit=13157
Planning time: 1.160 ms
Execution time: 5279.983 ms
(25 rows)
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-08-29 18:42 Jeff Janes <jeff.janes@gmail.com>
parent: Rondat Flyag <rondatflyag@yandex.ru>
0 siblings, 1 reply; 11+ messages in thread
From: Jeff Janes @ 2023-08-29 18:42 UTC (permalink / raw)
To: Rondat Flyag <rondatflyag@yandex.ru>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
On Tue, Aug 29, 2023 at 1:47 PM Rondat Flyag <rondatflyag@yandex.ru> wrote:
> I have a legacy system that uses `Posgresql 9.6` and `Ubuntu 16.04`.
> Everything was fine several days ago even with standard Postgresql
> settings. I dumped a database with the compression option (maximum
> compression level -Z 9) in order to have a smaller size (`pg_dump
> --compress=9 database_name > database_name.sql`). After that I got a lot of
> problems.
>
You describe taking a dump of the database, but don't describe doing
anything with it. Did you replace your system with one restored from that
dump? If so, did vacuum and analyze afterwards?
Cheers,
Jeff
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-08-29 18:55 Rondat Flyag <rondatflyag@yandex.ru>
parent: Jeff Janes <jeff.janes@gmail.com>
0 siblings, 2 replies; 11+ messages in thread
From: Rondat Flyag @ 2023-08-29 18:55 UTC (permalink / raw)
To: Jeff Janes <jeff.janes@gmail.com>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
<div>I took the dump just to store it on another storage (external HDD). I didn't do anything with it.</div><div> </div><div>29.08.2023, 21:42, "Jeff Janes" <jeff.janes@gmail.com>:</div><blockquote><div><div> </div> <div><div>On Tue, Aug 29, 2023 at 1:47 PM Rondat Flyag <<a href="mailto:rondatflyag@yandex.ru" rel="noopener noreferrer">rondatflyag@yandex.ru</a>> wrote:</div><blockquote style="border-left-color:rgb( 204 , 204 , 204 );border-left-style:solid;border-left-width:1px;margin:0px 0px 0px 0.8ex;padding-left:1ex"><div>I have a legacy system that uses `Posgresql 9.6` and `Ubuntu 16.04`. Everything was fine several days ago even with standard Postgresql settings. I dumped a database with the compression option (maximum compression level -Z 9) in order to have a smaller size (`pg_dump --compress=9 database_name > database_name.sql`). After that I got a lot of problems.</div></blockquote><div> </div><div>You describe taking a dump of the database, but don't describe doing anything with it. Did you replace your system with one restored from that dump? If so, did vacuum and analyze afterwards?</div><div> </div><div>Cheers,</div><div> </div><div>Jeff</div></div></div></blockquote>
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-08-29 20:11 Jeff Janes <jeff.janes@gmail.com>
parent: Rondat Flyag <rondatflyag@yandex.ru>
1 sibling, 1 reply; 11+ messages in thread
From: Jeff Janes @ 2023-08-29 20:11 UTC (permalink / raw)
To: Rondat Flyag <rondatflyag@yandex.ru>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
On Tue, Aug 29, 2023 at 2:55 PM Rondat Flyag <rondatflyag@yandex.ru> wrote:
> I took the dump just to store it on another storage (external HDD). I
> didn't do anything with it.
>
I don't see how that could cause the problem, it is probably just a
coincidence. Maybe taking the dump held a long-lived snapshot open which
caused some bloat. But if that was enough to push your system over the
edge, it was probably too close to the edge to start with.
Do you have a plan for the query while it was fast? If not, maybe you can
force it back to the old plan by setting enable_seqscan=off or perhaps
enable_sort=off, to let you capture the old plan for comparison.
The estimate for the seq scan of isbns_statistics is off by almost a
factor of 2. A seq scan with no filters and which can not stop early
should not be hard to estimate accurately, so this suggests autovac is not
keeping up. VACUUM ANALYZE all of the involved tables and see if that
fixes things.
Cheers,
Jeff
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-08-29 21:06 Rick Otten <rottenwindfish@gmail.com>
parent: Rondat Flyag <rondatflyag@yandex.ru>
1 sibling, 1 reply; 11+ messages in thread
From: Rick Otten @ 2023-08-29 21:06 UTC (permalink / raw)
To: Rondat Flyag <rondatflyag@yandex.ru>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
On Tue, Aug 29, 2023 at 3:57 PM Rondat Flyag <rondatflyag@yandex.ru> wrote:
> I took the dump just to store it on another storage (external HDD). I
> didn't do anything with it.
>
> 29.08.2023, 21:42, "Jeff Janes" <jeff.janes@gmail.com>:
>
>
>
> On Tue, Aug 29, 2023 at 1:47 PM Rondat Flyag <rondatflyag@yandex.ru>
> wrote:
>
> I have a legacy system that uses `Posgresql 9.6` and `Ubuntu 16.04`.
> Everything was fine several days ago even with standard Postgresql
> settings. I dumped a database with the compression option (maximum
> compression level -Z 9) in order to have a smaller size (`pg_dump
> --compress=9 database_name > database_name.sql`). After that I got a lot of
> problems.
>
>
> You describe taking a dump of the database, but don't describe doing
> anything with it. Did you replace your system with one restored from that
> dump? If so, did vacuum and analyze afterwards?
>
> Cheers,
>
> Jeff
>
>
Since this is a very old system and backups are fairly I/O intensive, it is
possible you have a disk going bad? Sometimes after doing a bunch of I/O
on an old disk, it will accelerate its decline. You could be about to lose
it altogether.
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-08-30 17:31 Rondat Flyag <rondatflyag@yandex.ru>
parent: Jeff Janes <jeff.janes@gmail.com>
0 siblings, 2 replies; 11+ messages in thread
From: Rondat Flyag @ 2023-08-30 17:31 UTC (permalink / raw)
To: Jeff Janes <jeff.janes@gmail.com>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=766983.18..767070.52 rows=100 width=498) (actual time=5508.261..5508.532 rows=100 loops=1)
Buffers: shared hit=30249 read=342473, temp read=16856 written=28392
-> Merge Join (cost=766983.18..2008284.16 rows=1421289 width=498) (actual time=5508.260..5508.527 rows=100 loops=1)
Merge Cond: ((books.asin)::text = (asins.value)::text)
Buffers: shared hit=30249 read=342473, temp read=16856 written=28392
-> Index Scan using books_asin_key on books (cost=0.43..1216522.35 rows=1403453 width=333) (actual time=0.007..0.150 rows=100 loops=1)
Buffers: shared hit=103
-> Materialize (cost=766980.48..774092.68 rows=1422439 width=155) (actual time=5508.248..5508.304 rows=100 loops=1)
Buffers: shared hit=30146 read=342473, temp read=16856 written=28392
-> Sort (cost=766980.48..770536.58 rows=1422439 width=155) (actual time=5508.245..5508.293 rows=100 loops=1)
Sort Key: asins.value
Sort Method: external merge Disk: 136864kB
Buffers: shared hit=30146 read=342473, temp read=16856 written=28392
-> Hash Join (cost=55734.25..509782.68 rows=1422439 width=155) (actual time=412.394..2071.400 rows=1404582 loops=1)
Hash Cond: (asins_statistics.asin_id = asins.id)
Buffers: shared hit=30146 read=342473, temp read=11281 written=11279
-> Seq Scan on asins_statistics (cost=0.00..373686.39 rows=1422439 width=120) (actual time=0.005..782.893 rows=1404582 loops=1)
Buffers: shared hit=16989 read=342473
-> Hash (cost=27202.89..27202.89 rows=1404589 width=35) (actual time=412.025..412.026 rows=1404589 loops=1)
Buckets: 1048576 Batches: 2 Memory Usage: 51393kB
Buffers: shared hit=13157, temp written=4363
-> Seq Scan on asins (cost=0.00..27202.89 rows=1404589 width=35) (actual time=0.010..151.754 rows=1404589 loops=1)
Buffers: shared hit=13157
Planning time: 0.770 ms
Execution time: 5525.959 ms
(25 rows)
SET enable_seqscan = OFF;
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=10001314403.06..10001314490.39 rows=100 width=498) (actual time=6171.243..6171.489 rows=100 loops=1)
Buffers: shared hit=1030733 read=346050, temp read=22327 written=34044
-> Merge Join (cost=10001314403.06..10002555704.04 rows=1421289 width=498) (actual time=6171.241..6171.478 rows=100 loops=1)
Merge Cond: ((books.asin)::text = (asins.value)::text)
Buffers: shared hit=1030733 read=346050, temp read=22327 written=34044
-> Index Scan using books_asin_key on books (cost=0.43..1216522.35 rows=1403453 width=333) (actual time=0.019..0.144 rows=100 loops=1)
Buffers: shared hit=103
-> Materialize (cost=10001314400.36..10001321512.55 rows=1422439 width=155) (actual time=6171.213..6171.265 rows=100 loops=1)
Buffers: shared hit=1030630 read=346050, temp read=22327 written=34044
-> Sort (cost=10001314400.36..10001317956.46 rows=1422439 width=155) (actual time=6171.133..6171.178 rows=100 loops=1)
Sort Key: asins.value
Sort Method: external merge Disk: 136864kB
Buffers: shared hit=1030630 read=346050, temp read=22327 written=34044
-> Hash Join (cost=10000416471.30..10001057202.55 rows=1422439 width=155) (actual time=1074.832..2719.409 rows=1404582 loops=1)
Hash Cond: (asins.id = asins_statistics.asin_id)
Buffers: shared hit=1030630 read=346050, temp read=16937 written=16931
-> Index Scan using isbns_pkey on asins (cost=0.43..574466.58 rows=1404589 width=35) (actual time=0.012..688.506 rows=1404589 loops=1)
Buffers: shared hit=1015561 read=1657
-> Hash (cost=10000373686.39..10000373686.39 rows=1422439 width=120) (actual time=1065.611..1065.611 rows=1404582 loops=1)
Buckets: 524288 Batches: 4 Memory Usage: 35931kB
Buffers: shared hit=15069 read=344393, temp written=10377
-> Seq Scan on asins_statistics (cost=10000000000.00..10000373686.39 rows=1422439 width=120) (actual time=0.025..795.542 rows=1404582 loops=1)
Buffers: shared hit=15069 read=344393
Planning time: 1.128 ms
Execution time: 6189.046 ms
(25 rows)
SET enable_sort = OFF;
Query takes a lot of time.
Attachments:
[text/plain] query_plans.txt (5.3K, ../../203321693416472@mail.yandex.ru/2-query_plans.txt)
download | inline:
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=766983.18..767070.52 rows=100 width=498) (actual time=5508.261..5508.532 rows=100 loops=1)
Buffers: shared hit=30249 read=342473, temp read=16856 written=28392
-> Merge Join (cost=766983.18..2008284.16 rows=1421289 width=498) (actual time=5508.260..5508.527 rows=100 loops=1)
Merge Cond: ((books.asin)::text = (asins.value)::text)
Buffers: shared hit=30249 read=342473, temp read=16856 written=28392
-> Index Scan using books_asin_key on books (cost=0.43..1216522.35 rows=1403453 width=333) (actual time=0.007..0.150 rows=100 loops=1)
Buffers: shared hit=103
-> Materialize (cost=766980.48..774092.68 rows=1422439 width=155) (actual time=5508.248..5508.304 rows=100 loops=1)
Buffers: shared hit=30146 read=342473, temp read=16856 written=28392
-> Sort (cost=766980.48..770536.58 rows=1422439 width=155) (actual time=5508.245..5508.293 rows=100 loops=1)
Sort Key: asins.value
Sort Method: external merge Disk: 136864kB
Buffers: shared hit=30146 read=342473, temp read=16856 written=28392
-> Hash Join (cost=55734.25..509782.68 rows=1422439 width=155) (actual time=412.394..2071.400 rows=1404582 loops=1)
Hash Cond: (asins_statistics.asin_id = asins.id)
Buffers: shared hit=30146 read=342473, temp read=11281 written=11279
-> Seq Scan on asins_statistics (cost=0.00..373686.39 rows=1422439 width=120) (actual time=0.005..782.893 rows=1404582 loops=1)
Buffers: shared hit=16989 read=342473
-> Hash (cost=27202.89..27202.89 rows=1404589 width=35) (actual time=412.025..412.026 rows=1404589 loops=1)
Buckets: 1048576 Batches: 2 Memory Usage: 51393kB
Buffers: shared hit=13157, temp written=4363
-> Seq Scan on asins (cost=0.00..27202.89 rows=1404589 width=35) (actual time=0.010..151.754 rows=1404589 loops=1)
Buffers: shared hit=13157
Planning time: 0.770 ms
Execution time: 5525.959 ms
(25 rows)
SET enable_seqscan = OFF;
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=10001314403.06..10001314490.39 rows=100 width=498) (actual time=6171.243..6171.489 rows=100 loops=1)
Buffers: shared hit=1030733 read=346050, temp read=22327 written=34044
-> Merge Join (cost=10001314403.06..10002555704.04 rows=1421289 width=498) (actual time=6171.241..6171.478 rows=100 loops=1)
Merge Cond: ((books.asin)::text = (asins.value)::text)
Buffers: shared hit=1030733 read=346050, temp read=22327 written=34044
-> Index Scan using books_asin_key on books (cost=0.43..1216522.35 rows=1403453 width=333) (actual time=0.019..0.144 rows=100 loops=1)
Buffers: shared hit=103
-> Materialize (cost=10001314400.36..10001321512.55 rows=1422439 width=155) (actual time=6171.213..6171.265 rows=100 loops=1)
Buffers: shared hit=1030630 read=346050, temp read=22327 written=34044
-> Sort (cost=10001314400.36..10001317956.46 rows=1422439 width=155) (actual time=6171.133..6171.178 rows=100 loops=1)
Sort Key: asins.value
Sort Method: external merge Disk: 136864kB
Buffers: shared hit=1030630 read=346050, temp read=22327 written=34044
-> Hash Join (cost=10000416471.30..10001057202.55 rows=1422439 width=155) (actual time=1074.832..2719.409 rows=1404582 loops=1)
Hash Cond: (asins.id = asins_statistics.asin_id)
Buffers: shared hit=1030630 read=346050, temp read=16937 written=16931
-> Index Scan using isbns_pkey on asins (cost=0.43..574466.58 rows=1404589 width=35) (actual time=0.012..688.506 rows=1404589 loops=1)
Buffers: shared hit=1015561 read=1657
-> Hash (cost=10000373686.39..10000373686.39 rows=1422439 width=120) (actual time=1065.611..1065.611 rows=1404582 loops=1)
Buckets: 524288 Batches: 4 Memory Usage: 35931kB
Buffers: shared hit=15069 read=344393, temp written=10377
-> Seq Scan on asins_statistics (cost=10000000000.00..10000373686.39 rows=1422439 width=120) (actual time=0.025..795.542 rows=1404582 loops=1)
Buffers: shared hit=15069 read=344393
Planning time: 1.128 ms
Execution time: 6189.046 ms
(25 rows)
SET enable_sort = OFF;
Query takes a lot of time.
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-08-30 17:46 Rondat Flyag <rondatflyag@yandex.ru>
parent: Rick Otten <rottenwindfish@gmail.com>
0 siblings, 0 replies; 11+ messages in thread
From: Rondat Flyag @ 2023-08-30 17:46 UTC (permalink / raw)
To: Rick Otten <rottenwindfish@gmail.com>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
<div>Thanks for the response.</div><div>Sure, I thought about it and even bought another drive. The current drive is SSD, as far as I'm concerned write operations degrade SSDs.</div><div> </div><div>Even so, why other queries work fine? Why the query joining two tables instead of three works fine?</div><div> </div><div>Cheers,</div><div>Serg</div><div> </div><div>30.08.2023, 00:07, "Rick Otten" <rottenwindfish@gmail.com>:</div><blockquote><div><div> </div> <div><div>On Tue, Aug 29, 2023 at 3:57 PM Rondat Flyag <<a href="mailto:rondatflyag@yandex.ru" rel="noopener noreferrer">rondatflyag@yandex.ru</a>> wrote:</div><blockquote style="border-left-color:rgb( 204 , 204 , 204 );border-left-style:solid;border-left-width:1px;margin:0px 0px 0px 0.8ex;padding-left:1ex"><div>I took the dump just to store it on another storage (external HDD). I didn't do anything with it.</div><div> </div><div>29.08.2023, 21:42, "Jeff Janes" <<a href="mailto:jeff.janes@gmail.com" rel="noopener noreferrer" target="_blank">jeff.janes@gmail.com</a>>:</div><blockquote><div><div> </div> <div><div>On Tue, Aug 29, 2023 at 1:47 PM Rondat Flyag <<a href="mailto:rondatflyag@yandex.ru" rel="noopener noreferrer" target="_blank">rondatflyag@yandex.ru</a>> wrote:</div><blockquote style="border-left-color:rgb( 204 , 204 , 204 );border-left-style:solid;border-left-width:1px;margin:0px 0px 0px 0.8ex;padding-left:1ex"><div>I have a legacy system that uses `Posgresql 9.6` and `Ubuntu 16.04`. Everything was fine several days ago even with standard Postgresql settings. I dumped a database with the compression option (maximum compression level -Z 9) in order to have a smaller size (`pg_dump --compress=9 database_name > database_name.sql`). After that I got a lot of problems.</div></blockquote><div> </div><div>You describe taking a dump of the database, but don't describe doing anything with it. Did you replace your system with one restored from that dump? If so, did vacuum and analyze afterwards?</div><div> </div><div>Cheers,</div><div> </div><div>Jeff</div></div></div></blockquote></blockquote><div> </div><div>Since this is a very old system and backups are fairly I/O intensive, it is possible you have a disk going bad? Sometimes after doing a bunch of I/O on an old disk, it will accelerate its decline. You could be about to lose it altogether.</div><div> </div></div></div></blockquote>
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-08-30 21:43 David Rowley <dgrowleyml@gmail.com>
parent: Rondat Flyag <rondatflyag@yandex.ru>
1 sibling, 1 reply; 11+ messages in thread
From: David Rowley @ 2023-08-30 21:43 UTC (permalink / raw)
To: Rondat Flyag <rondatflyag@yandex.ru>; +Cc: Jeff Janes <jeff.janes@gmail.com>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
On Thu, 31 Aug 2023 at 06:32, Rondat Flyag <rondatflyag@yandex.ru> wrote:
> I tried VACUUM ANALYZE for three tables, but without success. I also tried to set enable_seqscan=off and the query took even more time. If I set enable_sort=off then the query takes a lot of time and I cancel it.
>
> Please see the attached query plans.
It's a little hard to comment here as I don't see what the plan was
before when you were happy with the performance. I also see the
queries you mentioned in the initial email don't match the plans.
There's no table called "isbns" in the query. I guess this is "asins"?
Likely you could get a faster plan if there was an index on
asins_statistics (asin_id). That would allow a query plan that scans
the isbns_value_key index and performs a parameterised nested loop on
asins_statistics using the asins_statistics (asin_id) index. Looking
at your schema, I don't see that index, so it's pretty hard to guess
why the plan used to be faster. Even if the books/asins merge join
used to take place first, there'd have been no efficient way to join
to the asins_statistics table and preserve the Merge Join's order (I'm
assuming non-parameterized nested loops would be inefficient in this
case). Doing that would have also required the asins_statistics
(asin_id) index. Are you sure that index wasn't dropped?
However, likely it's a waste of time to try to figure out what the
plan used to be. Better to focus on trying to make it faster. I
suggest you create the asins_statistics (asin_id) index. However, I
can't say with any level of confidence that the planner would opt to
use that index if it did exist. Lowering random_page_cost or
increasing effective_cache_size would increase the chances of that.
David
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-08-31 16:52 Jeff Janes <jeff.janes@gmail.com>
parent: Rondat Flyag <rondatflyag@yandex.ru>
1 sibling, 1 reply; 11+ messages in thread
From: Jeff Janes @ 2023-08-31 16:52 UTC (permalink / raw)
To: Rondat Flyag <rondatflyag@yandex.ru>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
On Wed, Aug 30, 2023 at 1:31 PM Rondat Flyag <rondatflyag@yandex.ru> wrote:
> Hi and thank you for the response.
>
> I tried VACUUM ANALYZE for three tables, but without success. I also tried
> to set enable_seqscan=off and the query took even more time. If I set
> enable_sort=off then the query takes a lot of time and I cancel it.
>
Maybe you could restore (to a temp server, not the production) a physical
backup taken from before the change happened, and get an old plan that
way. I'm guessing that somehow an index got dropped around the same time
you took the dump. That might be a lot of work, and maybe it would just be
easier to optimize the current query while ignoring the past. But you
seem to be interested in a root-cause analysis, and I don't see any other
way to do one of those.
What I would expect to be the winning plan would be something sort-free
like:
Limit
merge join
index scan yielding books in asin order (already being done)
nested loop
index scan yielding asins in value order
index scan probing asins_statistics driven
by asins_statistics.asin_id = asins.id
Or possibly a 2nd nested loop rather than the merge join just below the
limit, but with the rest the same
In addition to the "books" index already evident in your current plan, you
would also need an index leading with asins_statistics.asin_id, and one
leading with asins.value. But if all those indexes exists, it is hard to
see why setting enable_seqscan=off wouldn't have forced them to be used.
Cheers,
Jeff
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-09-01 13:41 Rondat Flyag <rondatflyag@yandex.ru>
parent: David Rowley <dgrowleyml@gmail.com>
0 siblings, 0 replies; 11+ messages in thread
From: Rondat Flyag @ 2023-09-01 13:41 UTC (permalink / raw)
To: David Rowley <dgrowleyml@gmail.com>; +Cc: Jeff Janes <jeff.janes@gmail.com>; pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
<div>Hi David.</div><div> </div><div>Thank you so much for your help. The problem was in the dropped asins_statistics(asin_id) index. I had set it, but it was dropped somehow during the dump. I set it again andeverything works fine now.</div><div>Thank you again.</div><div> </div><div>P.S. There are two close terms: ASIN and ISBN. I use ASIN in my tables, but ISBN is well-known to people. I changed ASIN to ISBN in the text files, but forgot to replace the last time.This is why the names didn't correspond.</div><div> </div><div>Cheers,</div><div>Serg</div><div> </div><div>31.08.2023, 00:43, "David Rowley" <dgrowleyml@gmail.com>:</div><blockquote><p>On Thu, 31 Aug 2023 at 06:32, Rondat Flyag <<a href="mailto:rondatflyag@yandex.ru" rel="noopener noreferrer">rondatflyag@yandex.ru</a>> wrote:</p><blockquote> I tried VACUUM ANALYZE for three tables, but without success. I also tried to set enable_seqscan=off and the query took even more time. If I set enable_sort=off then the query takes a lot of time and I cancel it.<br /><br /> Please see the attached query plans.</blockquote><p><br />It's a little hard to comment here as I don't see what the plan was<br />before when you were happy with the performance. I also see the<br />queries you mentioned in the initial email don't match the plans.<br />There's no table called "isbns" in the query. I guess this is "asins"?<br /><br />Likely you could get a faster plan if there was an index on<br />asins_statistics (asin_id). That would allow a query plan that scans<br />the isbns_value_key index and performs a parameterised nested loop on<br />asins_statistics using the asins_statistics (asin_id) index. Looking<br />at your schema, I don't see that index, so it's pretty hard to guess<br />why the plan used to be faster. Even if the books/asins merge join<br />used to take place first, there'd have been no efficient way to join<br />to the asins_statistics table and preserve the Merge Join's order (I'm<br />assuming non-parameterized nested loops would be inefficient in this<br />case). Doing that would have also required the asins_statistics<br />(asin_id) index. Are you sure that index wasn't dropped?<br /><br />However, likely it's a waste of time to try to figure out what the<br />plan used to be. Better to focus on trying to make it faster. I<br />suggest you create the asins_statistics (asin_id) index. However, I<br />can't say with any level of confidence that the planner would opt to<br />use that index if it did exist. Lowering random_page_cost or<br />increasing effective_cache_size would increase the chances of that.<br /><br />David</p></blockquote>
^ permalink raw reply [nested|flat] 11+ messages in thread
* Re: Queries containing ORDER BY and LIMIT started to work slowly
@ 2023-09-01 13:45 Rondat Flyag <rondatflyag@yandex.ru>
parent: Jeff Janes <jeff.janes@gmail.com>
0 siblings, 0 replies; 11+ messages in thread
From: Rondat Flyag @ 2023-09-01 13:45 UTC (permalink / raw)
To: Jeff Janes <jeff.janes@gmail.com>; +Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
<div>Hello Jeff.</div><div>Thank you too for your efforts and help. The problem was in the dropped index for asins_statistics(asin_id). It existed, but was dropped during the dump I suppose. I created it again and everything is fine now.</div><div> </div><div>Cheers,</div><div>Serg</div><div> </div><div>31.08.2023, 19:52, "Jeff Janes" <jeff.janes@gmail.com>:</div><blockquote><div><div>On Wed, Aug 30, 2023 at 1:31 PM Rondat Flyag <<a href="mailto:rondatflyag@yandex.ru" rel="noopener noreferrer">rondatflyag@yandex.ru</a>> wrote:</div><div><blockquote style="border-left-color:rgb( 204 , 204 , 204 );border-left-style:solid;border-left-width:1px;margin:0px 0px 0px 0.8ex;padding-left:1ex"><div>Hi and thank you for the response.</div><div> </div><div>I tried VACUUM ANALYZE for three tables, but without success. I also tried to set enable_seqscan=off and the query took even more time. If I set enable_sort=off then the query takes a lot of time and I cancel it.</div></blockquote><div> </div><div>Maybe you could restore (to a temp server, not the production) a physical backup taken from before the change happened, and get an old plan that way. I'm guessing that somehow an index got dropped around the same time you took the dump. That might be a lot of work, and maybe it would just be easier to optimize the current query while ignoring the past. But you seem to be interested in a root-cause analysis, and I don't see any other way to do one of those.</div><div> </div><div>What I would expect to be the winning plan would be something sort-free like:</div><div> </div><div>Limit</div><div> merge join</div><div> index scan yielding books in asin order (already being done)</div><div> nested loop</div><div> index scan yielding asins in value order</div><div> index scan probing asins_statistics driven by asins_statistics.asin_id = <a href="http://asins.id/"; rel="noopener noreferrer">asins.id</a></div><div> </div><div>Or possibly a 2nd nested loop rather than the merge join just below the limit, but with the rest the same</div><div> </div><div>In addition to the "books" index already evident in your current plan, you would also need an index leading with asins_statistics.asin_id, and one leading with asins.value. But if all those indexes exists, it is hard to see why setting enable_seqscan=off wouldn't have forced them to be used.</div><div> </div><div> Cheers,</div><div> </div><div>Jeff</div></div></div></blockquote>
^ permalink raw reply [nested|flat] 11+ messages in thread
end of thread, other threads:[~2023-09-01 13:45 UTC | newest]
Thread overview: 11+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2023-08-29 17:47 Queries containing ORDER BY and LIMIT started to work slowly Rondat Flyag <rondatflyag@yandex.ru>
2023-08-29 18:42 ` Jeff Janes <jeff.janes@gmail.com>
2023-08-29 18:55 ` Rondat Flyag <rondatflyag@yandex.ru>
2023-08-29 20:11 ` Jeff Janes <jeff.janes@gmail.com>
2023-08-30 17:31 ` Rondat Flyag <rondatflyag@yandex.ru>
2023-08-30 21:43 ` David Rowley <dgrowleyml@gmail.com>
2023-09-01 13:41 ` Rondat Flyag <rondatflyag@yandex.ru>
2023-08-31 16:52 ` Jeff Janes <jeff.janes@gmail.com>
2023-09-01 13:45 ` Rondat Flyag <rondatflyag@yandex.ru>
2023-08-29 21:06 ` Rick Otten <rottenwindfish@gmail.com>
2023-08-30 17:46 ` Rondat Flyag <rondatflyag@yandex.ru>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox