透過pl/sql計算程式的執行時間

在sqlplus中執行sql語句或者pl/sql的時候如果需要統計執行的時間，只需要開啟set timing on選項即可。

SQL> set timing on
SQL>
SQL> select count(*)from cat;

  COUNT(*)
----------
       408

Elapsed: 00:00:00.15
如果在執行pl/sql的時候如果需要計算程式執行的時間。使用set timing on就顯得力不從心了。這個時候可以考慮使用dbms_utility.get_time來得到一個時間戳，然後在程式執行之後再得到一個時間戳，兩者想減就是程式的執行時間。
set serveroutput on
declare
 l_start_time PLS_INTEGER;
begin
 l_start_time := dbms_utility.get_time();
 dbms_output.put_line('this is a test');
 dbms_lock.sleep(2);  --這裡我們嘗試使pl/sql塊停滯2秒鐘
 dbms_output.put_line('Elapsed time :'||(dbms_utility.get_time-l_start_time)/100);
end;
/
程式執行的結果如下。

this is a test
Elapsed time :2.01

PL/SQL procedure successfully completed.

但是如果這樣計算，可能會出現負數的情況。在pl/sql程式設計這本書中，作者給出的解釋是，dbms_utility_get_time得到的數字式從某一個時間點以來所經過的總的毫秒數。而這個數字很大，很可能越界，越界的時候就會從0開始重新開始計數。如果這樣計算的話，很可能計算出來的結果就是一個負數了。
我們可以使用如下的pl/sql來做一個改進。
set serveroutput on
declare
 c_time_gap number:=power(2,32);
 l_start_time PLS_INTEGER;
begin
 l_start_time := dbms_utility.get_time();
 dbms_output.put_line('this is a test');
 dbms_lock.sleep(2);
 dbms_output.put_line('Elapsed time :'||mod(dbms_utility.get_time-l_start_time+c_time_gap,c_time_gap)/100);
end;
/
執行結果如下：

this is a test
Elapsed time :2

PL/SQL procedure successfully completed.

如果我們在程式中嵌入過多的程式碼去維護start_time,end_time必然會造成程式的依賴性，如果能夠把計算時間的功能獨立出來就好了。這樣程式的執行不必完全依賴於時間計算，可以靈活的新增和刪除。
這種實現在spring的AOP是根據動態代理來實現的，在pl/sql中我們可以使用package來實現。
我們的期望結果就是
begin
 pro_timing.start_timer;  --程式計算起始時間
 dbms_output.put_line('this is a test');  --程式業務邏輯
 dbms_lock.sleep(2);  --程式業務邏輯
 pro_timing.show_elapsed('test program');  --程式計算終止時間
end;
/

我們可以使用如下的package來實現。

create or replace package pro_timing
authid current_user
is
  procedure start_timer;
  procedure show_elapsed(program_name in varchar2);
end;
/

create or replace package body pro_timing
is
 c_time_gap number:=power(2,32);
 l_start_time PLS_INTEGER;
 
 procedure start_timer
 is
begin
 l_start_time := dbms_utility.get_time();
end;

 procedure show_elapsed(program_name in varchar2)
as
 l_end_time varchar2(100);
begin
 l_end_time:=mod(dbms_utility.get_time-l_start_time+c_time_gap,c_time_gap)/100;
dbms_output.put_line(program_name||' has elapsed time '||l_end_time||' s.');
end;
end;
/

我們來嘗試執行如下的pl/sql塊。
begin
 pro_timing.start_timer;
 dbms_output.put_line('this is a test');
 dbms_lock.sleep(2);
 pro_timing.show_elapsed('test program');
end;
/
執行結果如下：

this is a test
test program has elapsed time 2 s.

PL/SQL procedure successfully completed.

這樣就基本達到了我們的目標。我們可以在程式中靈活的配置這項功能，對於提升程式的效能來說也是功不可沒。