Oracle Performance and Engineering

After yesterday's post where I said that Oracle10g PL/SQL compiler 'understands' if an expression will remain constant within a LOOP and does NOT execute it once per iteration of the loop.

I also used the following code piece on 9i and 10g -

declare
a number := 10;
b number := 23892;
c number := 42784782;
d number;
e number;
begin
dbms_profiler.start_profiler;
for i in 1 .. 1000000 loop
d := a * b * c;
e := (d * 1001);
end loop;
dbms_profiler.stop_profiler;
end;

On 9i it took 5.01 seconds (today, on 1st execution)
On 10g it took 1.69 seconds (today, on 1st execution)

I received an email asking me how did I derive that 10g does not evaluate the constant expression once per loop. It could as well be the 'natural optimization' of 10g compiler.

Thanks for asking. And sorry for not have given more supporting document. It was a great question to ask. Really.

As you could see this time I've included DBMS_PROFILER in the code to see how many times each line is actually executed for 1 million iteration of the loop. After both the executions I ran Oracle-supplied proftab.sql (an excellent formatting tool for PL/SQL profiling data - formats the report in HTML) against each run.

This is what I found -

on 9i -

Profiled Run 21 (plsql_profiler_runs)

Run	Date	Total Time1	Comment
21	03-MAY-05 18:01:01	4.64	03-MAY-05

Note 1: Total Time is in seconds

Profiled PL/SQL Libraries (plsql_profiler_units)

Unit	Owner	Name	Type	Timestamp	Total Time1	Text Header
1			ANONYMOUS BLOCK		3.57

Note 1: Total Time is in seconds

Top 10 profiled source lines in terms of Total Time (plsql_profiler_data)

Top	Total Time1	Times Executed	Min Time2	Max Time2	Unit	Owner	Name	Type	Line	Text
1	1.44	1000000	0.00	0.00	1			ANONYMOUS BLOCK	11
2	1.28	1000000	0.00	0.00	1			ANONYMOUS BLOCK	10
3	0.86	1000001	0.00	0.00	1			ANONYMOUS BLOCK	9

Note 1: Total Time is in seconds



on 10g -

Profiled Run 50 (plsql_profiler_runs)

Run	Date	Total Time1	Comment
50	03-MAY-05 17:59:40	1.51	03-MAY-05

Note 1: Total Time is in seconds

Profiled PL/SQL Libraries (plsql_profiler_units)

Unit	Owner	Name	Type	Timestamp	Total Time1	Text Header
1			ANONYMOUS BLOCK		0.74

Note 1: Total Time is in seconds

Top 10 profiled source lines in terms of Total Time (plsql_profiler_data)

Top	Total Time1	Times Executed	Min Time2	Max Time2	Unit	Owner	Name	Type	Line	Text
1	0.74	1000000	0.00	0.00	1			ANONYMOUS BLOCK	9

Note 1: Total Time is in seconds
Note 2: Min and Max Time for one execution of this line (in seconds)


We see, three lines - line # 9, 10 and 11 - were executed 1 million times with 9i. Whereas, *only* one line - line #9 - is executed 1 million times with 10g!

So what's on line# 10 and #11?


for i in 1 .. 1000000 loop --## line 9
d := a * b * c; --## line 10 - not in the LOOP with 10g but iterated on 9i
e := (d * 1001); --## line 11 - not in the LOOP with 10g but iterated on 9i

Since expressions in line#10 and line#11 do NOT change with iterations - Oracle actually does not evaluate it every time with the loop. Oracle 'understands' d and e above are "constants" and takes it out of the loop.

Isn't it cool?

BTW, if you're tuning PL/SQL program units, DBMS_PROFILER is the coolest profiling tool. Just 'start' and 'stop' profiling it across your program as shown above. Download the cool proftab.sql utility from Oracle metalink. Run the proftab.sql and get a HTML formatted report which will show you how much time the total program unit took, how much time each line took cumulatively, which were the most expensive lines, which lines were executed most etc. In other words, you know your bottlenecks and it's HTML!

Remember the post 'PL/SQL function in where clause'? We had a certain PL/SQL function that always returns the same value (exactly like a constant) equated with a column in WHERE clause. Though the function was merely serving as a constant, Oracle actually evaluated the function for every row returned by the dataset! Oracle was *not* smart enough to execute the function just once, figure out that the returned value for the function is not going to change within the context of this query (in this case, it was NEVER gonna change!) - and then use that constant throughout the query execution.

Well, Oracle *used to* behave the same way within PL/SQL too. A codepiece like -

<.....
LOOP
a *b *c = d;
-- say, d will remain a constant throughout the LOOP
....

END LOOP;
.....>

would, so far, have executed (a * b * c) as many times as the LOOP will be iterated through. So earlier you would see statement like this all over the 'PL.SQL best practice guide' -

" Don’t write an expression inside a loop if it remains constant over all iterations of the loop.”

The case is not true anymore with 10g.

10g PL/SQL compiler is smart enough to figure out that "d" is indeed a constant - and would NOT compute the value for D once per iteration. Oracle 10g would evaluate it just once per loop.

Say the following code -

declare
a number := 10;
b number := 23892;
c number := 42784782;
d number;
e number;
begin
execute immediate 'alter session set sql_trace = true';
for i in 1 .. 1000000 loop
d := a * b * c;
e := (d * 1001);
end loop;
end;


Took 2.64 secs to run on 9i. (a * b * c is evaluated 1 million times)

Took 0.03 secs to run on 10g. (a *b * c is evaluated only ONCE).

However, on my tests against 10g - SQL is still not smart enough to evaluate this "constant" just once per query if the constant is supplied in the WHERE clause in form of a PL/SQL function.