Re: Linear slow-down while inserting into a table with an ON INSERT trigger ?

[Ninad Shah <nshah.postgres@xxxxxxxxx>]

How much does the function-ed UPDATE statement take?

Regards,

Ninad Shah

On Sat, 17 Jul 2021 at 02:57, Tobias Gierke <tobias.gierke@xxxxxxxxxxxxxxxx> wrote:

Hi,

Probably my google-foo is weak today but I couldn't find any (convincing) explanation for this.

I'm running PostgreSQL 12.6 on 64-bit Linux (CentOS 7, PostgreSQL compiled from sources) and I'm trying to insert 30k rows into a simple table that has an "ON INSERT .. FOR EACH STATEMENT" trigger.

                                      Table "public.parent_table"

   Column    |          Type          | Collation | Nullable |                  Default                   
-------------+------------------------+-----------+----------+--------------------------------------------
 id          | bigint                 |           | not null | nextval('parent_table_id_seq'::regclass)
 name        | character varying(64)  |           | not null | 
 enabled     | boolean                |           | not null | 
 description | character varying(255) |           |          | 
 deleted     | boolean                |           | not null | false
 is_default  | boolean                |           | not null | false

Indexes:
    "parent_pkey" PRIMARY KEY, btree (id)
    "uniq_name" UNIQUE, btree (name) WHERE deleted = false

Referenced by:
    TABLE "child" CONSTRAINT "child_fkey" FOREIGN KEY (parent_id) REFERENCES parent_table(id) ON DELETE CASCADE

Triggers:
    parent_changed BEFORE INSERT OR DELETE OR UPDATE OR TRUNCATE ON parent_table FOR EACH STATEMENT EXECUTE FUNCTION parent_table_changed();

This is the trigger function

CREATE OR REPLACE FUNCTION parent_table_changed() RETURNS trigger LANGUAGE plpgsql
AS $function$
BEGIN
    UPDATE data_sync SET last_parent_table_change=CURRENT_TIMESTAMP;
    RETURN NEW;
END;
$function$

I'm trying to insert 30k rows (inside a single transaction) into the parent table using the following SQL (note that I came across this issue while debugging an application-level performance problem and the SQL I'm using here is similar to what the application is generating):

BEGIN;
-- ALTER TABLE public.parent_table DISABLE TRIGGER parent_changed; 
PREPARE my_insert (varchar(64), boolean, varchar(255), boolean, boolean) AS INSERT INTO public.parent_table (name,enabled,description,deleted,is_default) VALUES($1, $2, $3, $4, $5);
EXECUTE my_insert ($$035001$$, true, $$null$$, false, false);
EXECUTE my_insert ($$035002$$, true, $$null$$, false, false);
....29998 more lines

This is the execution time I get when running the script while the trigger is enabled:

~/tmp$ time psql -q -Upostgres -h dbhost -f inserts.sql test_db

real    0m8,381s
user    0m0,203s
sys     0m0,287s

Running the same SQL script with trigger disabled shows a ~4x speed-up:

~/tmp$ time psql -q -Upostgres -h dbhost -f inserts.sql test_db

real    0m2,284s
user    0m0,171s
sys     0m0,261s

Defining the trigger as "BEFORE INSERT" or "AFTER INSERT" made no difference.

I then got curious , put a "/timing" at the start of the SQL script, massaged the psql output a bit and plotted a chart of the statement execution times.
To my surprise, I see a linear increase of the per-INSERT execution times, roughly 4x as well:

While the execution time per INSERT remains constant when disabling the trigger before inserting the data:

What's causing this slow-down ?

Thanks,
Tobias