From: | Les <nagylzs(at)gmail(dot)com> |
---|---|
To: | pgsql-performance(at)lists(dot)postgresql(dot)org |
Subject: | slow delete |
Date: | 2023-08-15 20:23:26 |
Message-ID: | CAKXe9UBE8wmTJnxrSqjVv+TTJqtPOv1TZn96TAvrxo5er6ZTvw@mail.gmail.com |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-performance |
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
}
]
From | Date | Subject | |
---|---|---|---|
Next Message | Tom Lane | 2023-08-15 20:37:39 | Re: slow delete |
Previous Message | Dorian Hoxha | 2023-08-11 11:09:57 | Re: Partitioning update-heavy queue with hash partitions vs partial indexes |