Re: [HACKERS] why subplan is 10x faster then function?

Поиск
Список
Период
Сортировка
От Pavel Stehule
Тема Re: [HACKERS] why subplan is 10x faster then function?
Дата
Msg-id CAFj8pRAs1o6AkQPD1jJh0_7C4jJrhQsX68wRSdiNSSxKuAQt_w@mail.gmail.com
обсуждение исходный текст
Ответ на [HACKERS] why subplan is 10x faster then function?  (Pavel Stehule <pavel.stehule@gmail.com>)
Ответы Re: [HACKERS] why subplan is 10x faster then function?  (Sokolov Yura <funny.falcon@postgrespro.ru>)
Список pgsql-hackers


2017-09-30 23:23 GMT+02:00 Pavel Stehule <pavel.stehule@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

В списке pgsql-hackers по дате отправления:

Предыдущее
От: Shubham Barai
Дата:
Сообщение: Re: [HACKERS] GSoC 2017: weekly progress reports (week 6)
Следующее
От: Sokolov Yura
Дата:
Сообщение: Re: [HACKERS] why subplan is 10x faster then function?