Here is a quick overview about commands in SQL*plus that help to track and measure time.
set time on/off
This displays a prompt in front of each statement with the current time. Be aware that it is not the time, when the statement was executed, but the time when the line in sql*plus was created. This difference is usually not relevant when running scripts, just something to be aware of when manually typing and executing statements in sql*plus.
SQL> set time on; 10:56:02 SQL> 10:56:10 SQL> execute dbms_session.sleep(3); PL/SQL procedure successfully completed. 10:56:23 SQL>
The prompt shows that 13 seconds passed by. However the sleep time specified was only 3 seconds. The reason is it took me approximately 10 seconds to type the statement.
set timing on/off
The result is the runtime of a sql statement or an anonymous plsql block in SQL*plus.
SQL> set timing on; SQL> execute dbms_session.sleep(3); PL/SQL procedure successfully completed. Elapsed: 00:00:03.02 SQL>
After any SQL statement or anonymous plsql blocks, sql*plus shows the elapsed time for that command.
The elapsed time is not shown after SQL*PLUS commands (like SET or SPOOL).
The time is measured on the client. So it includes the time to send the command to the server, execute the command there and move the resulting information from the database server back to the sql*plus client. When very exact measurements are needed network issues will make this elapsed time fluctuate a little more than what is useful.
timing start+stop
Timing start+stop is very similar to set timing on/off. It starts a timer with timing start and shows the elpased time after the timing stop command. This allows to measure the time to run multiple commands. Wheras set timing on/off only measures a single command.
SQL> set time on; 11:14:37 SQL> timing start 11:14:45 SQL> execute dbms_session.sleep(3); PL/SQL procedure successfully completed. 11:14:55 SQL> select * from dual; D - X 11:15:00 SQL> execute dbms_session.sleep(1); PL/SQL procedure successfully completed. 11:15:12 SQL> timing stop; Elapsed: 00:00:31.48 11:15:17 SQL>
We can compare the measurement from timing with the times shown by set time on.
From 11:14:45 to 11:15:17 there are 32 seconds. Which matches perfectly the elapsed time or 31.48 seconds shown by timing start+stop.
_DATE
This is a predefined sql*plus variable that holds the current time. It uses the sessions nls settings as display format.
SQL> prompt &_DATE
27-APR-22
SQL> alter session set nls_date_format = 'dd-mm-yyyy HH24:MI:SS';
Session altered.
SQL> prompt &_DATE
27-04-2022 11:22:20
SQL> set pagesize 10
SQL> ttitle "Important list of numbers &_DATE."
SQL> select level as num from dual connect by level <= 10;
Important list of numbers 27-04-2022 11:59:56
NUM
----------
1
2
3
4
5
6
Important list of numbers 27-04-2022 11:59:56
NUM
----------
7
8
9
10
10 rows selected.
SQL> ttitle OFF
Useful when one wants to add the day and/or time to the name of a log file for example.
sysdate/systimestamp
These are SQL pseudofunctions that give the current datetime. Sysdate delivers a date (incl. time up to the second), systimestamp delivers also fractional seconds. The time is derived from the servers time settings. So client settings do not influence the value. However client nls settings effect the conversion to strings.
SQL> select sysdate from dual; SYSDATE --------- 27-APR-22 SQL> alter session set nls_date_format='DD-MM-YYYY HH24:MI:SS'; Session altered. SQL> select sysdate from dual; SYSDATE ------------------- 27-04-2022 14:33:03 SQL> select to_char(sysdate,'FMDay, DDth Month YYYY') from dual; TO_CHAR(SYSDATE,'FMDAY,DDTHMONTHYYYY') ----------------------------------------- Wednesday, 27TH April 2022 SQL> select systimestamp from dual; SYSTIMESTAMP ----------------------------------------- 27-APR-22 02.33.10.675396 PM +02:00 SQL> alter session set nls_timestamp_tz_format='DD-MM-YYYY HH24:MI:SSXFF'; Session altered. SQL> select systimestamp from dual; SYSTIMESTAMP ------------------------------------------ 27-04-2022 14:33:18.033306 SQL> select to_char(systimestamp,'FMDay, DDth Month YYYY HH24:MI:SSXFF TZR') from dual; TO_CHAR(SYSTIMESTAMP,'FMDAY,DDTHMONTHYYYYHH24:MI:SSXFFTZR') ------------------------------------------ Wednesday, 27TH April 2022 14:33:22.260310 +02:00
dbms_utility.get_time
A possibility to measure very exact times (1/100 of a second) in plsql.
SQL>declare
2 time number;
3 begin
4 time:=dbms_utility.get_time;
5 dbms_session.sleep(3);
6 dbms_output.put_line('Elapsed in sec: '||to_char((dbms_utility.get_time - time)/100));
7 end;
8 /
Elapsed in sec: 3.04
PL/SQL procedure successfully completed.
SQL>
Be aware that the numbers returned by get_time are often negative integers, like -1618843773.
We can also use this to measure the time between several sql*plus calls by storing the first time in a sql*plus variable. So it doesn’t need to be a single large plsql block.
SQL> var stime number;
SQL> exec :stime := dbms_utility.get_time;
PL/SQL procedure successfully completed.
SQL> exec dbms_session.sleep(3);
PL/SQL procedure successfully completed.
SQL> select * from dual;
D
-
X
SQL> exec dbms_output.put_line('Elapsed in sec: '||to_char((dbms_utility.get_time - :stime)/100));
Elapsed in sec: 18.62
PL/SQL procedure successfully completed.
SQL>
Serveroutput needs to be switched on to see the result of dbms_output.
Recommendations
- For crude but easy performance time measurements
set time onandset timing onare solid. - For exact and comparable measurements on the database use
dbms_utility.get_time. - To show date and time in scripts sometimes
_DATEis a little easier to use thansysdate. - To add the full runtime of a script to the end of a spooled logfile
timing start+stopcan be used.
svenweller 