On Mon, 5 Jun 2023 at 04:35, Ranier Vilela <ranier...@gmail.com> wrote:
> Em dom., 4 de jun. de 2023 às 11:49, Satalabaha Postgres < > satalabaha.postg...@gmail.com> escreveu: > >> >> >> >> On Sun, 4 Jun 2023 at 19:46, Ranier Vilela <ranier...@gmail.com> wrote: >> >>> Em dom., 4 de jun. de 2023 às 05:35, Satalabaha Postgres < >>> satalabaha.postg...@gmail.com> 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 Vilela >>> >> >> Thanks 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