Horton

Thread

  1. slow delete

    Les <nagylzs@gmail.com> — 2023-08-15T20:23:26Z

    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

}

]

  2. Re: slow delete

    Tom Lane <tgl@sss.pgh.pa.us> — 2023-08-15T20:37:39Z

    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

  3. Re: slow delete

    Les <nagylzs@gmail.com> — 2023-08-16T04:43:05Z

    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

>
>

  4. Re: slow delete

    Jeff Janes <jeff.janes@gmail.com> — 2023-08-16T14:03:49Z

    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

>