Re: Measuring SQL execution time ?

From: Brian P. Mac Lean <brian.maclean_at_teldta.com>
Date: 1996/06/14
Message-ID: <31C1AC52.2DB5_at_teldta.com>#1/1


Maurice De Vidts NE3S wrote:
>
> Hi,
>
> I am interested in timing some SQL calls for a hardware comparison,
> and I am aware of the timing function in SQL. The problem is
> this is actual clocked time, from start to finish. It includes
> time the CPU may have used to do other things and serve other users.
>
> Is there any other way to measure CPU cycle associated with this call >?
>
> I am also wondering if there is an easy way to simulate a large user load
> and make timing measurements "under load".
>
> Any pointers, and sugestions will be appreciated !
>
> Maurice De Vidts
> ceham_at_w3eax.umd.edu

I have had some luck before using the “timex” command on unix. Actual cpu is reported, including all of the child processes. The man page is good reading if you haven't before. If you don’t care about the individual call statistics that Oracle’s tkprof utility provides this will do. the following is an example of “timex” using the “-ops” options:

[oracle]: cat bart.sql
set timing on
select count(*) from bart;
exit;
[oracle]: timex -ops sqlplus / _at_bart.sql SQL*Plus: Release 3.2.3.0.0 - Production on Fri Jun 14 11:05:17 1996 Copyright (c) Oracle Corporation 1979, 1994. All rights reserved. Connected to:
Oracle7 Server Release 7.2.3.0.0 - Production Release With the distributed, replication and parallel query options PL/SQL Release 2.2.3.0.0 - Production  

  COUNT(*)


         5  

Elapsed: 00:00:00.01
Disconnected from Oracle7 Server Release 7.2.3.0.0 - Production Release With the distributed, replication and parallel query options PL/SQL Release 2.2.3.0.0 - Production  

real 0.26
user 0.09
sys  0.16
 

START AFT: Fri Jun 14 11:05:17 1996
END BEFOR: Fri Jun 14 11:05:17 1996

COMMAND                      START    END          REAL      CPU    CHARS   BLOCKS
NAME       USER     TTYNAME  TIME     TIME       (SECS)   (SECS)   TRNSFD     READ
sqlplus    oracle   pts     11:05:17 11:05:17     0.25     0.03     33832        0
sadc       oracle   pts     11:05:17 11:05:17     0.55     0.52   3017728        0
bsh        oracle   pts     11:05:17 11:05:17     0.56     0.01         0        0
 

CHARS TRNSFD = 3051560
BLOCKS READ = 0   AIX bart 2 3 000072777500 06/14/96  

11:05:17 %usr %sys %wio %idle 11:05:17 25 75 0 0  

11:05:17 bread/s lread/s %rcache bwrit/s lwrit/s %wcache pread/s pwrit/s 11:05:17 0 0 0 0 0 0 0 0  

11:05:17 slots cycle/s fault/s odio/s 11:05:17 117382 0.00 381.93 0.00  

11:05:17 rawch/s canch/s outch/s rcvin/s xmtin/s mdmin/s 11:05:17 0 0 669 0 0 0  

11:05:17 scall/s sread/s swrit/s fork/s exec/s rchar/s wchar/s 11:05:17 25667 10667 127 4.82 4.82 3708008 7165  

11:05:17 pswch/s
11:05:17 190  

11:05:17 iget/s lookuppn/s dirblk/s
11:05:17 672 196 148  

11:05:17 runq-sz %runocc swpq-sz %swpocc 11:05:17  

11:05:17  proc-sz      inod-sz      file-sz      proc-ov   file-ov
11:05:17  100/131071   264/8472     588/712            0         0
 

11:05:17 msg/s sema/s
11:05:17 0.00 0.00
[oracle]:

brian.maclean_at_teldta.com Received on Fri Jun 14 1996 - 00:00:00 CEST

Original text of this message