On Mon, 5 Jun 2023 at 04:35, Ranier Vilela <ranier.vf@xxxxxxxxx> wrote:
Em dom., 4 de jun. de 2023 às 11:49, Satalabaha Postgres <satalabaha.postgres@xxxxxxxxx> escreveu:On Sun, 4 Jun 2023 at 19:46, Ranier Vilela <ranier.vf@xxxxxxxxx> wrote:Em dom., 4 de jun. de 2023 às 05:35, Satalabaha Postgres <satalabaha.postgres@xxxxxxxxx> escreveu: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$
;Can you show what type is FILEID?Can there be type mismatch?regards,Ranier VilelaThanks Ranier. Please find the below.\d+ schema1.table_a
Table "schema1.table_a"
Column | Type | Collation | Nullable | Default | Storage | Stats target | Description
---------------------+--------------------------------+-----------+----------+---------+----------+--------------+-------------
id | numeric(20,0) | | not null | | main | |
rowversion | timestamp(4) without time zone | | not null | | plain | |
created | timestamp(4) without time zone | | not null | | plain | |
isdeleted | boolean | | not null | | plain | |
lastupdated | timestamp(4) without time zone | | | | plain | |
isignored | boolean | | not null | | plain | |
importedaccountcode | character varying(255) | | | | extended | |
importedunitcode | character varying(255) | | | | extended | |
beginningbalance | numeric(19,5) | | | | main | |
endingbalance | numeric(19,5) | | | | main | |
createdbyid | numeric(20,0) | | | | main | |
updatedbyid | numeric(20,0) | | | | main | |
fileid | numeric(20,0) | | not null | | main | |
previousid | numeric(20,0) | | | | main | |
createdby | character varying(255) | | | | extended | |
lastupdatedby | character varying(255) | | | | extended | |\d+ schema1.table_b
Table "schema1.table_b"
Column | Type | Collation | Nullable | Default | Storage | Stats target | Description
--------------------------+--------------------------------+-----------+----------+---------+----------+--------------+-------------
id | numeric(20,0) | | not null | | main | |
rowversion | timestamp(4) without time zone | | not null | | plain | |
created | timestamp(4) without time zone | | not null | | plain | |
isdeleted | boolean | | not null | | plain | |
lastupdated | timestamp(4) without time zone | | | | plain | |
version | numeric(10,0) | | not null | | main | |
isactive | boolean | | not null | | plain | |
name | character varying(255) | | not null | | extended | |
displayname | character varying(255) | | not null | | extended | |
ispublished | boolean | | not null | | plain | |
isretired | boolean | | not null | | plain | |
publishdatetime | timestamp(4) without time zone | | | | plain | |
createdbyid | numeric(20,0) | | | | main | |
updatedbyid | numeric(20,0) | | | | main | |
periodid | numeric(20,0) | | not null | | main | |
uploadchartyearversionid | numeric(20,0) | | not null | | main | |
importchartyearversionid | numeric(20,0) | | | | main | |
initialtbadjversionid | numeric(20,0) | | | | main | |
latesttbadjversionid | numeric(20,0) | | | | main | |
trialbalancesourceid | numeric(20,0) | | not null | | main | |
filedefinitionid | numeric(20,0) | | not null | | main | |
createdby | character varying(255) | | | | extended | |
lastupdatedby | character varying(255) | | | | extended | |I think you are in trouble when comparing float8 (double precision) with numeric.
This small example shows problems.Postgres version 14.2:SELECT '8217316934885843456'::float8 = '8217316934885843456'::float8::bigint::float8, '8217316934885843456'::float8 = '8217316934885843456'::float8::numeric::float8;
?column? | ?column?
----------+----------
t | f
(1 row)I suggest a study to switch to bigint.
regards,Ranier Vilela
Hi Ranier / All,
Any idea if that is the case why as postgres user the query just works fine? Also I enabled all parameters for auto_explain and couldn't find any SQL that is taking more time. At last it just showed the insert statement and its execution plan which I have mentioned in the beginning of the email stating "trigger for constraints " taking more time.
One thing that was observed is that, when as postgres user I ran the query, it was not taking rowshare locks on the parent table (table_b) whereas as when I ran the same SQL as schema1_u user, I saw the Row Share locks acquired on the parent table and its FK's and indexes etc. Not sure if I am missing something here.
As postgres user:
clock_timestamp | relname | locktype | database | relation | page | tuple | virtualtransaction | pid | mode | granted
-------------------------------+----------------------+----------+----------+----------+------+-------+--------------------+-------+------------------+---------2023-06-05 08:57:38.596859+00 | table_a_sq | relation | 16400 | 12826203 | | | 11/14697 | 17833 | RowExclusiveLock | t
2023-06-05 08:57:38.596877+00 | idx1_table_a | relation | 16400 | 28894204 | | | 11/14697 | 17833 | RowExclusiveLock | t
2023-06-05 08:57:38.596884+00 | idx2_table_a | relation | 16400 | 28894201 | | | 11/14697 | 17833 | RowExclusiveLock | t
2023-06-05 08:57:38.59689+00 | idx3_table_a | relation | 16400 | 28894199 | | | 11/14697 | 17833 | RowExclusiveLock | t
2023-06-05 08:57:38.596896+00 | idx4_table_a | relation | 16400 | 28894197 | | | 11/14697 | 17833 | RowExclusiveLock | t
2023-06-05 08:57:38.596902+00 | idx5_table_a | relation | 16400 | 28894195 | | | 11/14697 | 17833 | RowExclusiveLock | t
2023-06-05 08:57:38.596909+00 | fk1_table_a | relation | 16400 | 28894193 | | | 11/14697 | 17833 | RowExclusiveLock | t
2023-06-05 08:57:38.596915+00 | fk2_table_a | relation | 16400 | 28894191 | | | 11/14697 | 17833 | RowExclusiveLock | t
2023-06-05 08:57:38.596923+00 | table_a_pkey | relation | 16400 | 12826690 | | | 11/14697 | 17833 | RowExclusiveLock | t
2023-06-05 08:57:38.596932+00 | staging_table_a | relation | 16400 | 12826482 | | | 11/14697 | 17833 | AccessShareLock | t
2023-06-05 08:57:38.596939+00 | table_a | relation | 16400 | 12826497 | | | 11/14697 | 17833 | RowExclusiveLock | t
(11 rows)
As schema1_u user:
===========================
clock_timestamp | relname | locktype | database | relation | page | tuple | virtualtransaction | pid | mode | granted
-------------------------------+------------------------+----------+----------+----------+------+-------+--------------------+-------+------------------+---------
2023-06-05 09:16:24.097184+00 | fk1_table_b | relation | 16400 | 28894114 | | | 13/18586 | 21032 | RowShareLock | t
2023-06-05 09:16:24.097203+00 | fk2_table_b | relation | 16400 | 28894112 | | | 13/18586 | 21032 | RowShareLock | t
2023-06-05 09:16:24.09721+00 | fk3_table_b | relation | 16400 | 28894110 | | | 13/18586 | 21032 | RowShareLock | t
2023-06-05 09:16:24.097221+00 | table_b_pkey | relation | 16400 | 12826648 | | | 13/18586 | 21032 | RowShareLock | t
2023-06-05 09:16:24.097229+00 | table_b | relation | 16400 | 12826410 | | | 13/18586 | 21032 | RowShareLock | t
2023-06-05 09:16:24.097238+00 | table_a_sq | relation | 16400 | 12826203 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.097246+00 | idx1_table_a | relation | 16400 | 28894204 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.097252+00 | idx2_table_a | relation | 16400 | 28894201 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.097258+00 | idx3_table_a | relation | 16400 | 28894199 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.097264+00 | idx4_table_a | relation | 16400 | 28894197 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.097271+00 | idx5_table_a | relation | 16400 | 28894195 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.097277+00 | fk1_table_a | relation | 16400 | 28894193 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.097283+00 | fk2_table_a | relation | 16400 | 28894191 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.09729+00 | table_a_pkey | relation | 16400 | 12826690 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.097298+00 | staging_table_a | relation | 16400 | 12826482 | | | 13/18586 | 21032 | AccessShareLock | t
2023-06-05 09:16:24.097305+00 | table_a | relation | 16400 | 12826497 | | | 13/18586 | 21032 | RowExclusiveLock | t
2023-06-05 09:16:24.097318+00 | fk4_table_b | relation | 16400 | 28894116 | | | 13/18586 | 21032 | RowShareLock | t
2023-06-05 09:16:24.097324+00 | fk5_table_b | relation | 16400 | 28894120 | | | 13/18586 | 21032 | RowShareLock | t
2023-06-05 09:16:24.09733+00 | fk6_table_b | relation | 16400 | 28894122 | | | 13/18586 | 21032 | RowShareLock | t
2023-06-05 09:16:24.097336+00 | fk7_table_b | relation | 16400 | 28894118 | | | 13/18586 | 21032 | RowShareLock | t
2023-06-05 09:16:24.097344+00 | fk8_table_b | relation | 16400 | 29343754 | | | 13/18586 | 21032 | RowShareLock | t
(21 rows)
Regards, Satalabaha
