I’ve described how to measure context switches some time ago in this post.
Given that with_clause allows to declare PL/SQL functions in 12c it’s interesting to analyze overhead for context switches in this case.
SQL> set timing on SQL> create or replace function f(n in number) return number as 2 begin 3 return - n; 4 end; 5 / Function created. Elapsed: 00:00:00.10 SQL> with function f0(n number) return number is 2 begin 3 return - n; 4 end; 5 select max(f0(rownum)) m from dual connect by level <= 2e6 6 / M ---------- -1 Elapsed: 00:00:02.14 SQL> select max(f(rownum)) m from dual connect by level <= 2e6 2 / M ---------- -1 Elapsed: 00:00:05.35
So execution of function declared in a query completed more than two times faster.
Going further UDF pragma may significantly improve performance for PL/SQL functions called from SQL.
SQL> create or replace function f1(n in number) return number as 2 pragma udf; 3 begin 4 return - n; 5 end; 6 / Function created. Elapsed: 00:00:00.18 SQL> select max(f1(rownum)) m from dual connect by level <= 2e6 2 / M ---------- -1 Elapsed: 00:00:02.03
In this case function executed even a bit faster than the one declared in a query.
Let’s have a look what is going on under the hood by decreasing number of calls from 2e6 to 3.
alter session set events '10938 trace name context forever, level 511'; select max(f(rownum)) m from dual connect by level <= 3;
511 = 1 + 2 + 4 + 8 + 16 + 32 + 64 + 128 + 256, please refer to “DBMS_TRACE Event Constants” in documentation for more details.
And similarly
with function f0(n number) return number is begin return - n; end; select max(f0(rownum)) m from dual connect by level <= 3 /
select max(f1(rownum)) m from dual connect by level <= 3;
According to below output in all cases 3 context switches took place. In case of declaration in a query also “Unknown Trace Event” occurred.
RUNID EVENT_SEQ EVENT_UNIT EVENT_UNIT_KIND EVENT_LINE STACK_DEPTH EVENT_COMMENT ---------- ---------- --------------- --------------- ---------- ----------- -------------------------------------------------- 12 1 PL/SQL Trace Tool started 12 2 Trace flags changed 12 3 <anonymous> ANONYMOUS BLOCK 0 0 PL/SQL Virtual Machine started 12 4 F FUNCTION 3 1 New line executed 12 5 F FUNCTION 4 1 New line executed 12 6 PL/SQL Virtual Machine stopped 12 7 <anonymous> ANONYMOUS BLOCK 0 0 PL/SQL Virtual Machine started 12 8 F FUNCTION 3 1 New line executed 12 9 F FUNCTION 4 1 New line executed 12 10 PL/SQL Virtual Machine stopped 12 11 <anonymous> ANONYMOUS BLOCK 0 0 PL/SQL Virtual Machine started 12 12 F FUNCTION 3 1 New line executed 12 13 F FUNCTION 4 1 New line executed 12 14 PL/SQL Virtual Machine stopped 14 rows selected. RUNID EVENT_SEQ EVENT_UNIT EVENT_UNIT_KIND EVENT_LINE STACK_DEPTH EVENT_COMMENT ---------- ---------- --------------- --------------- ---------- ----------- -------------------------------------------------- 13 1 PL/SQL Trace Tool started 13 2 Trace flags changed 13 3 <anonymous> ANONYMOUS BLOCK 0 0 PL/SQL Virtual Machine started 13 4 <anonymous> ANONYMOUS BLOCK 5 1 New line executed 13 5 Unknown Trace Event 13 6 <anonymous> ANONYMOUS BLOCK 5 1 New line executed 13 7 PL/SQL Virtual Machine stopped 13 8 <anonymous> ANONYMOUS BLOCK 0 0 PL/SQL Virtual Machine started 13 9 <anonymous> ANONYMOUS BLOCK 5 1 New line executed 13 10 Unknown Trace Event 13 11 <anonymous> ANONYMOUS BLOCK 5 1 New line executed 13 12 PL/SQL Virtual Machine stopped 13 13 <anonymous> ANONYMOUS BLOCK 0 0 PL/SQL Virtual Machine started 13 14 <anonymous> ANONYMOUS BLOCK 5 1 New line executed 13 15 Unknown Trace Event 13 16 <anonymous> ANONYMOUS BLOCK 5 1 New line executed 13 17 PL/SQL Virtual Machine stopped 17 rows selected. RUNID EVENT_SEQ EVENT_UNIT EVENT_UNIT_KIND EVENT_LINE STACK_DEPTH EVENT_COMMENT ---------- ---------- --------------- --------------- ---------- ----------- -------------------------------------------------- 15 1 PL/SQL Trace Tool started 15 2 Trace flags changed 15 3 <anonymous> ANONYMOUS BLOCK 0 0 PL/SQL Virtual Machine started 15 4 F1 FUNCTION 4 1 New line executed 15 5 F1 FUNCTION 5 1 New line executed 15 6 PL/SQL Virtual Machine stopped 15 7 <anonymous> ANONYMOUS BLOCK 0 0 PL/SQL Virtual Machine started 15 8 F1 FUNCTION 4 1 New line executed 15 9 F1 FUNCTION 5 1 New line executed 15 10 PL/SQL Virtual Machine stopped 15 11 <anonymous> ANONYMOUS BLOCK 0 0 PL/SQL Virtual Machine started 15 12 F1 FUNCTION 4 1 New line executed 15 13 F1 FUNCTION 5 1 New line executed 15 14 PL/SQL Virtual Machine stopped 14 rows selected.
So PL/SQL tracing is not very useful to see the differences. Let’s check behavior using hierarchical profiler.
exec dbms_hprof.start_profiling('UDUMP', '1.trc'); select max(f(rownum)) from dual connect by level <= 2e6; exec dbms_hprof.stop_profiling; select dbms_hprof.analyze('UDUMP', '1.trc') runid from dual;
And similarly for functions f0 and f1 and “select max(rownum) m from dual connect by level <= 2e6".
Results are following
SQL> select pci.runid, 2 level depth, 3 rpad(' ', (level - 1) * 3, ' ') || fi.function as name, 4 fi.subtree_elapsed_time, 5 fi.function_elapsed_time, 6 fi.calls 7 from (select runid, parentsymid, childsymid 8 from dbmshp_parent_child_info 9 union all 10 select runid, null, 2 from dbmshp_runs) pci 11 join dbmshp_function_info fi 12 on pci.runid = fi.runid 13 and pci.childsymid = fi.symbolid 14 where fi.function <> 'STOP_PROFILING' 15 connect by prior childsymid = parentsymid 16 and prior pci.runid = pci.runid 17 start with pci.parentsymid is null 18 and pci.runid in (6, 7, 8, 9); RUNID DEPTH NAME SUBTREE_ELAPSED_TIME FUNCTION_ELAPSED_TIME CALLS ---------- ---------- -------------------- -------------------- --------------------- ---------- 6 1 __plsql_vm 1645310 1046294 2000001 6 2 __anonymous_block 162 162 1 6 2 F 598854 598854 2000000 7 1 __plsql_vm 122 38 2 7 2 __anonymous_block 84 84 2 8 1 __plsql_vm 145 51 2 8 2 __anonymous_block 89 89 1 8 2 F1 5 5 1 9 1 __plsql_vm 91 5 1 9 2 __anonymous_block 86 86 1 10 rows selected.
There were 2e6 calls for ordinary PL/SQL function, while function declared in with_clause caused one additional call of "__anonymous_block" as well as function declared with "pragma udf" was logged like executed only once.
This helps better understand difference in timings but on the other hand such results look a bit "inconsistent" with the results of PL/SQL tracing.
So even though PL/SQL tracing logged the same amount of context switches in all cases (PL/SQL Virtual Machine started => PL/SQL Virtual Machine stopped), more detailed results of hierarchical profiler has shown that only one PL/SQL call happens in case of "pragma udf"/"declaration in with_clause".
Declaring functions which are intensively used from SQL with "pragma udf" seems the better way to me since it allows much more flexible maintainability than functions declared in the queries.