Обсуждение: slow delete

Поиск

Список

Период

Сортировка

slow delete

От

Les

Дата:

15 августа 2023 г., 23:23:26

I have created a table called _td with about 43 000 rows. I have tried to use this as a primary key id list to delete records from my product.product_file table, but I could not do it. It uses 100% of one CPU and it takes forever. Then I changed the query to delete 100 records only, and measure the speed:

EXPLAIN (ANALYZE, COSTS, VERBOSE, BUFFERS, FORMAT JSON)
delete from product.product_file where id in (
select pf2_id from _td limit 100
)

It still takes 11 seconds. It means 110 msec / record, and that is unacceptable.

I'm going to post the whole query plan at the end of this email, but I would like to highlight the "Triggers" part:

"Triggers": [
 {
"Trigger Name": "RI_ConstraintTrigger_a_26535",
"Constraint Name": "fk_pfft_product",
"Relation": "product_file",
"Time": 4.600,
"Calls": 90
 },
 {
"Trigger Name": "RI_ConstraintTrigger_a_26837",
"Constraint Name": "fk_product_file_src",
"Relation": "product_file",
"Time": 5.795,
"Calls": 90
 },
 {
"Trigger Name": "RI_ConstraintTrigger_a_75463",
"Constraint Name": "fk_pfq_src_product_file",
"Relation": "product_file",
"Time": 11179.429,
"Calls": 90
 },
 {
"Trigger Name": "_trg_002_aiu_audit_row",
"Relation": "product_file",
"Time": 49.410,
"Calls": 90
 }
 ]

It seems that two foreign key constraints use 10.395 seconds out of the total 11.24 seconds. But I don't see why it takes that much?

The product.product_file table has 477 000 rows:

CREATE TABLE product.product_file (
 id uuid NOT NULL,
 c_tim timestamptz NOT NULL DEFAULT CURRENT_TIMESTAMP,
 c_uid uuid NULL,
 c_sid uuid NULL,
 m_tim timestamptz NOT NULL DEFAULT CURRENT_TIMESTAMP,
 m_uid uuid NULL,
 m_sid uuid NULL,
 product_id uuid NOT NULL,
 product_file_type_id uuid NOT NULL,
 file_id uuid NOT NULL,
 product_file_status_id uuid NOT NULL,
 dl_url text NULL,
 src_product_file_id uuid NULL,
CONSTRAINT product_file_pkey PRIMARY KEY (id),
CONSTRAINT fk_pf_file FOREIGN KEY (file_id) REFERENCES media.file(id),
CONSTRAINT fk_pf_file_type FOREIGN KEY (product_file_type_id) REFERENCES product.product_file_type(id),
CONSTRAINT fk_pf_product FOREIGN KEY (product_id) REFERENCES product.product(id) ON DELETE CASCADE,
CONSTRAINT fk_product_file_src FOREIGN KEY (src_product_file_id) REFERENCES product.product_file(id),
CONSTRAINT fk_product_file_status FOREIGN KEY (product_file_status_id) REFERENCES product.product_file_status(id)
);
CREATE INDEX idx_product_file_dl_url ON product.product_file USING btree (dl_url) INCLUDE (product_id) WHERE (dl_url IS NOT NULL);
CREATE INDEX idx_product_file_file_product ON product.product_file USING btree (file_id, product_id);
CREATE INDEX idx_product_file_product_file ON product.product_file USING btree (product_id, file_id);
CREATE INDEX idx_product_file_src ON product.product_file USING btree (src_product_file_id) WHERE (src_product_file_id IS NOT NULL);

The one with fk_pfft_product looks like this, it has about 5000 records in it:

CREATE TABLE product.product_file_tag (
 id uuid NOT NULL,
 c_tim timestamptz NOT NULL DEFAULT CURRENT_TIMESTAMP,
 c_uid uuid NULL,
 c_sid uuid NULL,
 m_tim timestamptz NOT NULL DEFAULT CURRENT_TIMESTAMP,
 m_uid uuid NULL,
 m_sid uuid NULL,
 product_file_id uuid NOT NULL,
 file_tag_id uuid NOT NULL,
CONSTRAINT product_file_tag_pkey PRIMARY KEY (id),
CONSTRAINT fk_pfft_file_tag FOREIGN KEY (file_tag_id) REFERENCES product.file_tag(id) ON DELETE CASCADE DEFERRABLE,
CONSTRAINT fk_pfft_product FOREIGN KEY (product_file_id) REFERENCES product.product_file(id) ON DELETE CASCADE DEFERRABLE
);
CREATE UNIQUE INDEX uidx_product_file_file_tag ON product.product_file_tag USING btree (product_file_id, file_tag_id);

The other constraint has zero actual references, this returns zero:

select count(*) from product.product_file where src_product_file_id in (
select pf2_id from _td 
); -- 0 

I was trying to figure out how a foreign key constraint with zero actual references can cost 100 msec / record, but I failed.

Can somebody please explain what is wrong here?

The plan is also visualized here: http://tatiyants.com/pev/#/plans/plan_1692129126258

[
 {
"Plan": {
"Node Type": "ModifyTable",
"Operation": "Delete",
"Parallel Aware": false,
"Async Capable": false,
"Relation Name": "product_file",
"Schema": "product",
"Alias": "product_file",
"Startup Cost": 4.21,
"Total Cost": 840.79,
"Plan Rows": 0,
"Plan Width": 0,
"Actual Startup Time": 0.567,
"Actual Total Time": 0.568,
"Actual Rows": 0,
"Actual Loops": 1,
"Shared Hit Blocks": 582,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 10,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
 {
"Node Type": "Nested Loop",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Async Capable": false,
"Join Type": "Inner",
"Startup Cost": 4.21,
"Total Cost": 840.79,
"Plan Rows": 100,
"Plan Width": 46,
"Actual Startup Time": 0.161,
"Actual Total Time": 0.451,
"Actual Rows": 90,
"Actual Loops": 1,
"Output": ["product_file.ctid", "\"ANY_subquery\".*"],
"Inner Unique": true,
"Shared Hit Blocks": 402,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 10,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
 {
"Node Type": "Aggregate",
"Strategy": "Hashed",
"Partial Mode": "Simple",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Async Capable": false,
"Startup Cost": 3.79,
"Total Cost": 4.79,
"Plan Rows": 100,
"Plan Width": 56,
"Actual Startup Time": 0.118,
"Actual Total Time": 0.136,
"Actual Rows": 100,
"Actual Loops": 1,
"Output": ["\"ANY_subquery\".*", "\"ANY_subquery\".pf2_id"],
"Group Key": ["\"ANY_subquery\".pf2_id"],
"Planned Partitions": 0,
"HashAgg Batches": 1,
"Peak Memory Usage": 32,
"Disk Usage": 0,
"Shared Hit Blocks": 2,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
 {
"Node Type": "Subquery Scan",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Async Capable": false,
"Alias": "ANY_subquery",
"Startup Cost": 0.00,
"Total Cost": 3.54,
"Plan Rows": 100,
"Plan Width": 56,
"Actual Startup Time": 0.030,
"Actual Total Time": 0.083,
"Actual Rows": 100,
"Actual Loops": 1,
"Output": ["\"ANY_subquery\".*", "\"ANY_subquery\".pf2_id"],
"Shared Hit Blocks": 2,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
 {
"Node Type": "Limit",
"Parent Relationship": "Subquery",
"Parallel Aware": false,
"Async Capable": false,
"Startup Cost": 0.00,
"Total Cost": 2.54,
"Plan Rows": 100,
"Plan Width": 16,
"Actual Startup Time": 0.024,
"Actual Total Time": 0.053,
"Actual Rows": 100,
"Actual Loops": 1,
"Output": ["_td.pf2_id"],
"Shared Hit Blocks": 2,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
 {
"Node Type": "Seq Scan",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Async Capable": false,
"Relation Name": "_td",
"Schema": "public",
"Alias": "_td",
"Startup Cost": 0.00,
"Total Cost": 1100.07,
"Plan Rows": 43307,
"Plan Width": 16,
"Actual Startup Time": 0.023,
"Actual Total Time": 0.042,
"Actual Rows": 100,
"Actual Loops": 1,
"Output": ["_td.pf2_id"],
"Shared Hit Blocks": 2,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
 }
 ]
 }
 ]
 }
 ]
 },
 {
"Node Type": "Index Scan",
"Parent Relationship": "Inner",
"Parallel Aware": false,
"Async Capable": false,
"Scan Direction": "Forward",
"Index Name": "product_file_pkey",
"Relation Name": "product_file",
"Schema": "product",
"Alias": "product_file",
"Startup Cost": 0.42,
"Total Cost": 8.36,
"Plan Rows": 1,
"Plan Width": 22,
"Actual Startup Time": 0.003,
"Actual Total Time": 0.003,
"Actual Rows": 1,
"Actual Loops": 100,
"Output": ["product_file.ctid", "product_file.id"],
"Index Cond": "(product_file.id = \"ANY_subquery\".pf2_id)",
"Rows Removed by Index Recheck": 0,
"Shared Hit Blocks": 400,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 10,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
 }
 ]
 }
 ]
 },
"Planning": {
"Shared Hit Blocks": 0,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
 },
"Planning Time": 0.249,
"Triggers": [
 {
"Trigger Name": "RI_ConstraintTrigger_a_26535",
"Constraint Name": "fk_pfft_product",
"Relation": "product_file",
"Time": 4.600,
"Calls": 90
 },
 {
"Trigger Name": "RI_ConstraintTrigger_a_26837",
"Constraint Name": "fk_product_file_src",
"Relation": "product_file",
"Time": 5.795,
"Calls": 90
 },
 {
"Trigger Name": "RI_ConstraintTrigger_a_75463",
"Constraint Name": "fk_pfq_src_product_file",
"Relation": "product_file",
"Time": 11179.429,
"Calls": 90
 },
 {
"Trigger Name": "_trg_002_aiu_audit_row",
"Relation": "product_file",
"Time": 49.410,
"Calls": 90
 }
 ],
"Execution Time": 11240.265
 }
]

Re: slow delete

От

Tom Lane

Дата:

15 августа 2023 г., 23:37:39

Les <nagylzs@gmail.com> writes:
> It seems that two foreign key constraints use 10.395 seconds out of the
> total 11.24 seconds. But I don't see why it takes that much?

Probably because you don't have an index on the referencing column.
You can get away with that, if you don't care about the speed of
deletes from the PK table ...

            regards, tom lane

Re: slow delete

От

Les

Дата:

16 августа 2023 г., 07:43:05

Tom Lane <tgl@sss.pgh.pa.us> ezt írta (időpont: 2023. aug. 15., K, 22:37):

Les <nagylzs@gmail.com> writes:
> It seems that two foreign key constraints use 10.395 seconds out of the
> total 11.24 seconds. But I don't see why it takes that much?

Probably because you don't have an index on the referencing column.
You can get away with that, if you don't care about the speed of
deletes from the PK table ...

For fk_pfft_product constraint this is true, but I always thought that PostgreSQL can use an index "partially". There is already an index:

CREATE UNIQUE INDEX uidx_product_file_file_tag ON product.product_file_tag USING btree (product_file_id, file_tag_id);

It has the same order, only it has one column more. Wouldn't it be possible to use it for the plan?

After I created these two missing indices:

CREATE INDEX idx_pft_pf ON product.product_file_tag USING btree (product_file_id);
CREATE INDEX idx_pfq_src_pf ON product.product_file_queue USING btree (src_product_file_id);

I could delete all 40 000 records in 10 seconds.

Thank you!

Laszlo

Re: slow delete

От

Jeff Janes

Дата:

16 августа 2023 г., 17:03:49

On Tue, Aug 15, 2023 at 4:23 PM Les <nagylzs@gmail.com> wrote:

{
"Trigger Name": "RI_ConstraintTrigger_a_75463",
"Constraint Name": "fk_pfq_src_product_file",
"Relation": "product_file",
"Time": 11179.429,
"Calls": 90
},

...

The one with fk_pfft_product looks like this, it has about 5000 records in it:

That constraint took essentially no time. You need to look into the one that took all of the time,

which is fk_pfq_src_product_file.

Cheers,

Jeff

Вход в личный кабинет

Восстановление пароля

Подтверждение аккаунта

Изменение пароля

Обсуждение: slow delete

slow delete

Re: slow delete

Re: slow delete

Re: slow delete