The Fastest Way to Store / Retrieve a Cross Session Variable

I’m working on a logging / debugging utility in my spare time that allows a developer to set the logging level. Currently I’m using Conditional Compilation to completely remove all logging code as this was the fastest way I could think of to do it. After talking it over with Tom Kyte, he brought up a very important point that since this technique relies on recompiling the logging package, this will invalidate any code that calls it which could be undesirable (potentially disastrous) in a production environment. His solution? Use Function Result Cache if the logger is installed in an 11g Database which should be plenty fast and not require recompilation to change the logging level.

If I’ve learned anything from Tom it’s the concept of “prove it”, so I set out to find the quickest way to store a cross session variable that will be heavily used in an application. In addition, was function result cache really fast enough given the huge benefit of the solution?

Update: John Scott posted a great suggestion in the comments of using a Global Application Context as there is no Database version / edition dependency issue and it does not require recompilation.  I added it to the test and it appears to be the new winner!  Thanks John!

I’ll post the results first since the test code is a bit lengthy. Each result is the time it took to check the variable 100,000 times.:

----------------------------------------------------------------
Simple Loop:                                     0.00247 seconds
No-op Procedure Call:                            0.06028 seconds
Procedure Call with simple IF-THEN:              0.05350 seconds
Procedure Call with Package Globals IF-THEN:     0.05019 seconds
Procedure with standard select:                  8.50581 seconds
Procedure with Query Result Cache:               9.50794 seconds
Function Result Cache:                           0.75690 seconds
Package Globals:                                 0.06700 seconds
Global Application Context:                      0.33737 seconds

As you can see, Function Result Cache is about 14 times slower than the current solution which results in a NO OP.  However, if we step back and look at this objectively, it’s still REALLY fast and as Tom said, “faster than fast enough”.  If we divide 0.7 by 100,000 we get the time per call to this function which is 0.000007.  Lets say we’re using this in an APEX environment and we call the logging package 100 times per page view which in my opinion is very generous.  Lets also assume our average page view time is 0.3 seconds.   (0.0007 / 0.3 ) * 100 = 0.23% overhead added to our application. In my opinion, 5% overhead would be a fair price to pay for an application that is instrumented with debug code.  This way when (not if) something goes wrong, the time to diagnose the problem should be substantially less. 0.23% isn’t even worth talking about.  The benefit of instrumentation FAR outweighs the overhead.

Here’s my test script (11g Database only):

set serveroutput on

-- grant create any context to user;

create or replace context test_global_ctx using set_global_ctx accessed globally;

create or replace function time_diff(
    p_start    in  timestamp,
    p_end      in  timestamp)
return varchar2
is
    l_return number;
begin
    l_return :=  extract(second from (p_end-p_start))+
           (extract(minute from (p_end-p_start))*60)+
           (extract(hour from (p_end-p_start))*60*60);
           
    return to_char(l_return,'9990D00000');
end time_diff;
/


drop table some_table;

create table some_table(
	object_name	varchar2(30),
	object_owner varchar2(30)
)
/

create unique index some_tab_index on some_table(object_name,object_owner)
/

insert into some_table
    select level object_name, level object_owner
      from dual
   connect by level <= 20;

begin     
    dbms_stats.gather_table_stats(
        ownname => user,
        tabname  => 'SOME_TABLE',
        estimate_percent => 100);
end;
/

create or replace package globals_test
as

	g_one	constant varchar2(255)   := 'One';
	g_two	constant varchar2(255)   := 'Two';
	g_three	constant varchar2(255)   := 'Three';
	
	
end globals_test;
/
show errors

create or replace procedure test1
is
begin
	null;
end;
/

create or replace procedure test1_2
is
begin
	if 1 = 1 then
		null;
	end if;
end;
/


create or replace procedure test1_3
is
begin
	if globals_test.g_one = 'One' then
		null;
	end if;
end;
/

create or replace procedure test2(p_name in varchar2)
is
	l_owner varchar2(30);
begin
	select object_owner into l_owner from some_table where object_name = p_name;
end;
/

create or replace procedure test3(p_name in varchar2)
is
	l_owner varchar2(30);
begin
	for c1 in (select /*+ result_cache */ object_owner from some_table where object_name = p_name)
    loop
        l_owner := c1.object_owner;
    end loop; --c1
end;
/

create or replace function test4(p_name in varchar2)
	return varchar2
	result_cache
	relies_on(some_table)
is
	l_owner varchar2(30);
begin
	for c1 in (select object_owner from some_table where object_name = p_name)
    loop
        l_owner := c1.object_owner;
    end loop; --c1
	
	return l_owner;
end;
/


create or replace procedure test5
is
	l_dummy varchar2(30);
begin
	l_dummy := globals_test.g_one;
end;
/


create or replace procedure set_global_ctx(
    p_var   in varchar2)
is
begin
    dbms_session.set_context(  
        namespace  => 'test_global_ctx', 
        attribute  => 'foo', 
        value      => p_var);
end;
/


accept DUMMY prompt "Ready to run tests which will take a while.  Press ENTER to continue..."
prompt  
prompt  

declare
    l_start     timestamp;
	l_object_name	varchar2(30);
	l_return varchar2(30);
	l_loop_size	pls_integer := 100000;
    
    function format_title(p_title in varchar2)
    return varchar2
    is
    begin
        return rpad(p_title,45);
    end format_title;
begin
	l_start := current_timestamp;
	for i in 1..l_loop_size 
	loop
		null;
	end loop; --i
	dbms_output.put_line('----------------------------------------------------------------');
	dbms_output.put_line(format_title('Simple Loop: ')||
                           time_diff(l_start,current_timestamp)|| ' seconds');
						   
						   
	l_start := current_timestamp;
	for i in 1..l_loop_size 
	loop
		test1;
	end loop; --i
	dbms_output.put_line(format_title('No-op Procedure Call: ')||
                           time_diff(l_start,current_timestamp)|| ' seconds');
						   
	l_start := current_timestamp;
	for i in 1..l_loop_size 
	loop
		test1_2;
	end loop; --i
	dbms_output.put_line(format_title('Procedure Call with simple IF-THEN: ')||
                           time_diff(l_start,current_timestamp)|| ' seconds');
						   
	l_start := current_timestamp;
	for i in 1..l_loop_size 
	loop
		test1_3;
	end loop; --i
	dbms_output.put_line(format_title('Procedure Call with Package Globals IF-THEN: ')||
                           time_diff(l_start,current_timestamp)|| ' seconds');
						   
	
	select object_name into l_object_name from some_table where rownum = 1; 
	l_start := current_timestamp;
	for i in 1..l_loop_size 
	loop
		test2(l_object_name);
	end loop; --i
	dbms_output.put_line(format_title('Procedure with standard select: ')||
                           time_diff(l_start,current_timestamp)|| ' seconds');
						   
	l_start := current_timestamp;
	for i in 1..l_loop_size 
	loop
		test3(l_object_name);
	end loop; --i
	dbms_output.put_line(format_title('Procedure with Query Result Cache: ')||
                           time_diff(l_start,current_timestamp)|| ' seconds');
						   
	l_start := current_timestamp;
	for i in 1..l_loop_size 
	loop
		l_return := test4(l_object_name);
	end loop; --i
	dbms_output.put_line(format_title('Function Result Cache: ')||
                           time_diff(l_start,current_timestamp)|| ' seconds');
						   
	l_start := current_timestamp;
	for i in 1..l_loop_size 
	loop
		test5;
	end loop; --i
	dbms_output.put_line(format_title('Package Globals: ')||
                           time_diff(l_start,current_timestamp)|| ' seconds');	
    
    set_global_ctx('bar');
    l_start := current_timestamp;
    for i in 1..l_loop_size 
	loop
		l_return :=  sys_context('test_global_ctx using','foo');
	end loop; --i
	dbms_output.put_line(format_title('Global Application Context: ')||
                           time_diff(l_start,current_timestamp)|| ' seconds');	
end;
/

About these ads