2017-10-01 12:45 GMT+02:00 Sokolov Yura <funny.fal...@postgrespro.ru>:

> 1 октября 2017 г. 12:42:14 GMT+03:00, Pavel Stehule <
> pavel.steh...@gmail.com> пишет:
> >2017-09-30 23:23 GMT+02:00 Pavel Stehule <pavel.steh...@gmail.com>:
> >
> >> Hi
> >>
> >> I have some strange slow queries based on usage "view" functions
> >>
> >> one function looks like this:
> >>
> >> CREATE OR REPLACE FUNCTION
> >ides_funcs.najdatsplt_cislo_exekuce(mid_najdatsplt
> >> bigint)
> >>  RETURNS character varying
> >>  LANGUAGE sql
> >>  STABLE
> >> AS $function$
> >> select CISLOEXEKUCE
> >>       from najzalobpr MT, najvzallok A1,
> >>                     NAJZALOBST A2, NAJZALOBCE A3 where
> >>                     MT.ID_NAJVZALLOK= A1.ID_NAJVZALLOK AND
> >>                     A1.ID_NAJZALOBST=A2.ID_NAJZALOBST AND
> >>                     A2.ID_NAJZALOBCE= A3.ID_NAJZALOBCE AND
> >>                     MT.ID_NAJDATSPLT = mID_NAJDATSPLT  LIMIT 1;
> >> $function$ cost 20
> >> ;
> >>
> >> I know so using this kind of functions is not good idea - it is
> >customer
> >> old code generated from Oracle. I had idea about possible planner
> >issues.
> >> But this is a executor issue.
> >>
> >> when this function is evaluated as function, then execution needs
> >about 46
> >> sec
> >>
> >>     ->  Nested Loop Left Join  (cost=0.71..780360.31 rows=589657
> >> width=2700) (actual time=47796.588..47796.588 rows=0 loops=1)
> >>           ->  Nested Loop  (cost=0.29..492947.20 rows=589657
> >width=2559)
> >> (actual time=47796.587..47796.587 rows=0 loops=1)
> >>                 ->  Seq Scan on najdatsplt mt  (cost=0.00..124359.24
> >> rows=1106096 width=1013) (actual time=47796.587..47796.587 rows=0
> >loops=1)
> >>                       Filter:
> >(najdatsplt_cislo_exekuce(id_najdatsplt) IS
> >> NOT NULL)
> >>                       Rows Removed by Filter: 1111654
> >>
> >> When I use correlated subquery, then
> >>
> >>  ->  Nested Loop  (cost=0.29..19876820.11 rows=589657 width=2559)
> >(actual
> >> time=3404.154..3404.154 rows=0 loops=1)
> >>   ->  Seq Scan on najdatsplt mt  (cost=0.00..19508232.15 rows=1106096
> >> width=1013) (actual time=3404.153..3404.153 rows=0 loops=1)
> >>       Filter: ((SubPlan 11) IS NOT NULL)
> >>       Rows Removed by Filter: 1111654
> >>       SubPlan 11
> >>         ->  Limit  (cost=1.10..17.49 rows=1 width=144) (actual
> >> time=0.002..0.002 rows=0 loops=1111654)
> >>               ->  Nested Loop  (cost=1.10..17.49 rows=1 width=144)
> >(actual
> >> time=0.002..0.002 rows=0 loops=1111654)
> >>                     ->  Nested Loop  (cost=0.83..17.02 rows=1
> >width=8)
> >> (actual time=0.002..0.002 rows=0 loops=1111654)
> >>                           ->  Nested Loop  (cost=0.56..16.61 rows=1
> >> width=8) (actual time=0.002..0.002 rows=0 loops=1111654)
> >>
> >> The execution plan is +/- same - the bottleneck is in function
> >execution
> >>
> >> Tested with same result on 9.6, 10.
> >>
> >> Is known overhead of function execution?
> >>
> >>
> >profile of slow execution looks like
> >
> >+   24,71%    24,40%         48235  postmaster  [.] SearchCatCache
> >+   14,25%     0,00%             0  postmaster  [unknown]           [.]
> >0000000000000000
> >+    9,76%     9,65%         19071  postmaster  [.]
> >TupleDescInitEntry
> >+    3,91%     3,86%          7625  postmaster  [.]
> >ExecAssignScanProjectionInfoWithVarno
> >+    3,56%     3,52%          6955  postmaster  [.] AllocSetAlloc
> >+    2,66%     2,63%          5193  postmaster  [.]
> >FunctionCall2Coll
> >+    2,65%     2,62%          5183  postmaster  [.]
> >ResourceArrayRemove
> >+    2,42%     2,39%          4719  postmaster  [.]
> >ExecTypeFromTLInternal
> >+    2,21%     2,19%          4321  postmaster  [.]
> >DirectFunctionCall1Coll
> >+    2,02%     2,00%          3961  postmaster  [.]
> >heap_getsysattr
> >+    1,85%     1,82%          3604  postmaster  [.]
> >exprTypmod
> >+    1,81%     1,79%          3540  postmaster  [.]
> >ResourceArrayAdd
> >+    1,68%     1,66%          3282  postmaster  [.]
> >hash_uint32
> >+    1,65%     1,63%          3214  postmaster  [.]
> >hash_search_with_hash_value
> >+    1,64%     1,62%          3208  postmaster  [.]
> >CatalogCacheComputeHashValue
> >+    1,28%     1,26%          2498  postmaster  [.]
> >MemoryContextAllocZeroAligned
> >+    1,25%     1,24%          2446  postmaster  [.] palloc0
> >
> >Any ides why SearchCatCache is called too often?
> >
> >
> >
> >> Regards
> >>
> >> Pavel
> >>
>
> Looks like you've already collected profile with call-graph. So you can
> tell us where it were called from.
>

There was zero info. I'll try to install this database on my notebook, and
I'll see

Pavel


>
> With regards,
> --
> Sokolov Yura aka funny_falcon
>

Reply via email to