Forgot to mention. If I cancel the long running insert statement from
schema1_u user query before completion, I see the below. Not sure if this
will help but just thought to mention it.

CONTEXT:  SQL statement "SELECT 1 FROM ONLY "schema1"."table_b" x WHERE
"id" OPERATOR(pg_catalog.=) $1 FOR KEY SHARE OF x"
Regards,

Satalabha


On Sun, 4 Jun 2023 at 14:04, Satalabaha Postgres <
satalabaha.postg...@gmail.com> wrote:

> 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
>

Reply via email to