Oracle SQLPlus [Electronic resources] : The Definitive Guide, 2nd Edition نسخه متنی

12.1 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