Weird behavior of INSERT QUERY

From: Satalabaha Postgres <satalabaha(dot)postgres(at)gmail(dot)com>
To: pgsql-performance(at)lists(dot)postgresql(dot)org
Subject: Weird behavior of INSERT QUERY
Date: 2023-06-04 08:34:52
Message-ID: CAJ_W8nbj4KWOB-N5Y41VoaEkUs9PCEezNK8t+fEE5UJFsACJAQ@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hi Listers,

DB : postgres 14.

We are experiencing weird performance issue of one simple insert statement
taking several minutes to insert data. The application calls insert
statement via stored procedure show mentioned below.

The select query in the insert returns about 499 rows. However, this insert
statement when executed from application user i.e. schema1_u takes close to
8 minutes. When the same insert statement gets executed as postgres user
it takes less than 280 ms. Both the executions use the same execution plan
with only difference that when schema1_u executes the SQL, we observe
"Trigger for constraint fk_con_tablea: time=426499.314 calls=499" taking
more time. Both the parent and child tables are not big in size. There is
no table bloat etc for both of these tables. Below are the details.
Is there any way we can identify why as postgres user the insert statement
works fine and why not with application user schema1_u?

Stored Procedure:
====================

CREATE OR REPLACE FUNCTION schema1.ins_staging_fn(parfileid double
precision, parcreatedby text)
RETURNS void
LANGUAGE plpgsql
AS $function$
BEGIN
insert into table_a
(
ROWVERSION,
CREATED,
ISDELETED,
ISIGNORED,
IMPORTEDACCOUNTCODE,
IMPORTEDUNITCODE,
BEGINNINGBALANCE,
ENDINGBALANCE,
CREATEDBY,
FILEID
)
select to_timestamp(To_char(clock_timestamp(),'DD-MON-YY
HH.MI.SS.FF4 AM'),'DD-MON-YY HH.MI.SS.FF4 AM'),
to_timestamp(To_char(clock_timestamp() at time zone
'utc', 'DD-MON-YY HH.MI.SS.MS AM'),'DD-MON-YY HH.MI.SS.FF4 AM'),
false,
false,
IMPORTEDACCOUNTCODE,
IMPORTEDUNITCODE,
BEGINNINGBALANCE,
ENDINGBALANCE,
parCreatedBy,
FILEID
from STAGING_table_a
where FILEID = parFileId;

END;
$function$
;

Count of tables:
=================

select count(*) from schema1.table_a;
count
-------
67019

select count(*) from schema1.table_b;
count
-------
20

create trigger table_a_trigger before
insert
on
schema1.table_a for each row execute function
schema1."table_a_trigger$table_a"();

CREATE OR REPLACE FUNCTION schema1."table_a_trigger$table_a"()
RETURNS trigger
LANGUAGE plpgsql
AS $function$
BEGIN
IF COALESCE(new.id, - 1) = - 1 THEN
SELECT
nextval('table_a_sq')
INTO STRICT new.id;
END IF;
RETURN NEW;
END;
$function$;

ALTER TABLE schema1.table_a ADD CONSTRAINT fk_con_tablea FOREIGN KEY
(fileid) REFERENCES schema1.table_b(id);

POSTGRES
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------
Insert on table_a (cost=0.00..431.80 rows=0 width=0) (actual
time=35.806..35.807 rows=0 loops=1)
Buffers: shared hit=9266 written=19
-> Subquery Scan on "*SELECT*" (cost=0.00..431.80 rows=499 width=771)
(actual time=0.427..5.654 rows=499 loops=1)
Buffers: shared hit=162
-> Seq Scan on staging_table_a (cost=0.00..414.33 rows=499
width=83) (actual time=0.416..4.286 rows=499 loops=1)
Filter: (fileid = 37)
Rows Removed by Filter: 18989
Buffers: shared hit=162
Settings: effective_cache_size = '266500832kB', maintenance_io_concurrency
= '1', max_parallel_workers = '24', search_path = 'schema1, public'
Planning Time: 0.092 ms
Trigger for constraint fk_con_tablea: time=6.304 calls=499
Trigger table_a_trigger: time=5.658 calls=499
Execution Time: 42.206 ms
(13 rows)

schema1_U QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------
Insert on table_a (cost=0.00..431.80 rows=0 width=0) (actual
time=34.806..34.806 rows=0 loops=1)
Buffers: shared hit=9247 written=9
-> Subquery Scan on "*SELECT*" (cost=0.00..431.80 rows=499 width=771)
(actual time=0.427..5.372 rows=499 loops=1)
Buffers: shared hit=162
-> Seq Scan on staging_table_a (cost=0.00..414.33 rows=499
width=83) (actual time=0.416..4.159 rows=499 loops=1)
Filter: (fileid = 37)
Rows Removed by Filter: 18989
Buffers: shared hit=162
Settings: effective_cache_size = '266500832kB', maintenance_io_concurrency
= '1', max_parallel_workers = '24', search_path = 'schema1, public'
Planning Time: 0.092 ms
Trigger for constraint fk_con_tablea: time=426499.314 calls=499
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< Issue
Trigger table_a_trigger: time=5.712 calls=499
Execution Time: 426534.633 ms
(13 rows)

Regards,

Satalabha

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Satalabaha Postgres 2023-06-04 08:40:05 Re: Weird behavior of INSERT QUERY
Previous Message Satalabaha Postgres 2023-06-03 17:46:30 Re: Understand time taken by individual SQL statements in a procedure