Using SQL*Plus Timers

SQL*Plus comes with a crude, built-in timing facility that allows you to measure the elapsed time of a script or any portion of a script. You can even have SQL*Plus report the elapsed execution time of every SQL query and PL/SQL block automatically after each statement has executed. Timers can be nested so you can time the overall execution of a script, as well as the execution time of each individual statement.

Timings can be useful in spotting trends. It may be helpful to know, for example, if a script is taking longer to run. Timings can help compare the relative efficiency of two SQL statements. If you have two statements that return equivalent results and one consistently runs faster than the other, that's the one you probably want to go with.

Take timing with a grain of salt, however. The timer measures elapsed time, sometimes called wall-clock time, not CPU time, and many factors can throw it off. The network throughput might vary between the execution of two queries. The load on the server might vary as well. For example, one query might run more slowly than another because many other users simultaneously happened to hit the database. Be skeptical of one-time results. Look for consistency over several timings.

12.1.1 The SET TIMING Command

You can have SQL*Plus automatically report the elapsed time it takes to execute every query by issuing the SET TIMING ON command:

SET TIMING ON

Now, whenever you execute a query, SQL*Plus will report the elapsed time. With older Windows versions of SQL*Plus, this time will be reported in milliseconds . The following example shows that it took two hundredths of a second for a query on dba_views to complete:


SELECT view_name


FROM dba_views


WHERE view_name = 'DBA_TABLES';

VIEW_NAME

------------------------------

DBA_TABLES

 

Elapsed: 00:00:00.02

When timing is on, SQL*Plus reports the time it takes to execute a PL/SQL block:


BEGIN


DBMS_OUTPUT.PUT_LINE('How long does this take?');


END;


/

How long does this take?

 

PL/SQL procedure successfully completed.

 

Elapsed: 00:00:00.04

To turn timing off, simply issue the SET TIMING OFF command as follows :

SET TIMING OFF

When you have timing turned on, SQL*Plus displays elapsed time only for statements executed by the database server. This includes SQL statements and PL/SQL blocks. Elapsed time for SQL*Plus commands, such as ACCEPT and DEFINE, is not reported.

In Oracle Database 10 g , timings are reported using an hour , minute, second, and hundredth format:

Elapsed: 00:00:00.04
 

Older releases of SQL*Plus running under Windows reported elapsed time in milliseconds:

real: 90500
 

In all cases, even today, timer resolution varies with the hardware platform. For example, a time interval reported in milliseconds doesn't mean that the underlying hardware can accurately track one-millisecond intervals.

 

12.1.2 The TIMING Command

The SQL*Plus TIMING command gives you complete control over when timing starts and stops and what is measured. With it, you can turn on a timer at any point in your script. You can display the elapsed time at any point after a timer is turned on, and you can nest timers. Nesting timers gives you a way to time a set of operations, maybe an entire script, while still allowing you to time each individual operation separately.

The TIMING command is useful only in scripts. You can use it interactively, but then the elapsed time will include your "think" time and the time it takes you to type commands.

 

Think of timers as being implemented on a stack. Each time you issue a TIMING START command, you push a new timer onto the stack. The TIMING SHOW and TIMING STOP commands each operate on whatever timer is currently at the top of the stack. To find out how many timers you have currently running, enter the TIMING command with no arguments.

12.1.2.1 Starting and stopping a timer

Use the TIMING START command to start a timer. If you like, you can give the timer a name. Timing starts the moment the command is executed. The following example starts a new timer, and gives it a name of for_testing :

TIMING START for_testing

 

You stop the timer and display its final value by issuing the TIMING STOP command as follows:

SQL>

TIMING STOP

timing for: for_testing

Elapsed: 00:00:07.72

 

In this case, the timer ran for a total elapsed time of 7.72 seconds.

12.1.2.2 Displaying the value of a timer

You can display the value of a timer without stopping it. This is useful if your script is executing several SQL queries and you want to see the cumulative elapsed time after each one:

SQL>

TIMING START for_show

SQL>

TIMING SHOW

timing for: for_show

Elapsed: 00:00:02.61

SQL>

TIMING SHOW

timing for: for_show

Elapsed: 00:00:04.97

SQL>

TIMING SHOW

timing for: for_show

Elapsed: 00:00:06.33

 

You can see from this example that once I got going, it took me in the neighborhood of two seconds, give or take, to type each TIMING SHOW command.

12.1.2.3 Nesting timers

Timers can be nested, allowing you to time a group of operations while simultaneously timing each individual operation within the larger group . The following example shows a timer being started, and while that's running, two more timers are started and stopped. Finally, the first timer is stopped .

SQL>

TIMING START first

SQL>

TIMING START second

SQL>

TIMING STOP

timing for: second

Elapsed: 00:00:03.66

SQL>

TIMING START third

SQL>

TIMING STOP

timing for: third

Elapsed: 00:00:02.21

SQL>

TIMING STOP

timing for: first

Elapsed: 00:00:17.14

 

The important thing to notice here is that the first timer kept running during this entire example. The total elapsed time was a bit over 17 seconds, while the two intermediate operations took 3.66 and 2.21 seconds respectively.

Example 12-1 shows how this nesting feature can be used. It creates a copy of each example table used for this book and reports the time needed for each copy, as well as the total elapsed time to run the entire script.

Example 12-1. Using nested timers to time a script and its operations

TIMING START entire_script



--Drop old versions of the copies, if any exist 

DROP TABLE employee_copy;

DROP TABLE project_copy;

DROP TABLE project_hours_copy;



--Copy the employee table

TIMING START copy_employees

CREATE TABLE employee_copy AS

 SELECT * FROM employee;

TIMING STOP



--Copy the project table

TIMING START copy_project

CREATE TABLE project_copy AS

 SELECT * FROM project;

TIMING STOP



--Copy the project_hours

TIMING START copy_project_hours

CREATE TABLE project_hours_copy AS

 SELECT * FROM project_hours;

TIMING STOP



TIMING STOP

 

Here is the output from running Example 12-1:


@ex12-1

Table dropped.



Table dropped.



Table dropped.



Table created.



timing for: copy_employees

Elapsed: 00:00:00.07



Table created.



timing for: copy_project

Elapsed: 00:00:00.37



Table created.



timing for: copy_project_hours

Elapsed: 00:00:00.08

timing for: entire_script

Elapsed: 00:00:00.73

 

You can see that the elapsed time was displayed for each table copy and for the script as a whole.

12.1.2.4 Finding out how many timers you have going

The TIMER command will cause SQL*Plus to report the number of active timers. The following example shows how the count goes up each time you start a timer and goes back down each time you stop one:


TIMING START


TIMING

1 timing element in use

TIMING START


TIMING

2 timing elements in use

TIMING STOP

Elapsed: 00:00:00.05

TIMING

1 timing element in use

TIMING STOP

Elapsed: 00:00:00.14

TIMING

no timing elements in use

 

12.1.2.5 Stopping all timers

You can stop and delete all timers with the CLEAR TIMING command. As each timer is stopped, its final value is displayed:


TIMING START first


TIMING START second


TIMING START third


CLEAR TIMING

timing for: third

Elapsed: 00:00:00.02

timing for: second

Elapsed: 00:00:00.06

timing for: first

Elapsed: 00:00:00.10

 

Capturing Elapsed Time

It's possible to capture elapsed time into a substitution variable, or a bind variable, which allows your script to do something with the value. You can find the following example in ex12-sb1.sql :

--Obtain the starting time

COLUMN start_time NEW_VALUE start

SELECT systimestamp(9) start_time FROM dual;

--Do some work that you want to measure

SELECT COUNT(*) FROM employee;

SELECT COUNT(*) FROM project;

SELECT COUNT(*) FROM project_hours;

--Grab the ending time

COLUMN end_time NEW_VALUE end

SELECT systimestamp(9) end_time FROM dual;

--Compute the elapsed time

COLUMN elapsed_time NEW_VALUE elapsed

SELECT TO_TIMESTAMP_TZ('&end')

 - TO_TIMESTAMP_TZ('&start') elapsed_time

FROM dual;

--Display the elapsed time

PROMPT The elapsed time for the SELECTs was: &elapsed
 

Once you have the elapsed time in a substitution variable, you can use it in your script, display it, or pass it back to a Unix shell script using one of the methods described near the end of Chapter 11. You can even email the elapsed time to yourself, from a shell script or by using Oracle's built-in packages, UTL_MAIL or UTL_SMTP.


     



Oracle SQL Plus The Definitive Guide, 2nd Edition
Oracle SQL*Plus: The Definitive Guide (Definitive Guides)
ISBN: 0596007469
EAN: 2147483647
Year: N/A
Pages: 151
Simiral book on Amazon

Flylib.com © 2008-2017.
If you may any questions please contact us: flylib@qtcs.net