Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Mailing Lists -> Oracle-L -> RE: Session Stat interpretation - total runtime

RE: Session Stat interpretation - total runtime

From: John Kanagaraj <john.kanagaraj_at_hds.com>
Date: Tue, 16 Sep 2003 15:24:36 -0800
Message-ID: <F001.005D0146.20030916152436@fatcity.com>


Ildefonso,

SQL*Net event is a null event, and should not be considered. Hence, taking only meaningful I/O wait times,

CPU Time (service time) = 182141 ms ; Conv to secs = 1821 secs Wait Time = 657.21 + 48.00 + 2.60 ~= 708 secs Response time = service time + Wait time = 1821 + 708 = 2529 secs

Total Elapsed time = 2622 secs, which ties in neatly (nearly) to 2529 secs... The DB cannot measure time for context switches and wait times less than a msec (I think).

Hope this explains!
John Kanagaraj
DB Soft Inc
Phone: 408-970-7002 (W)

Disappointment is inevitable, but Discouragement is optional!

>-----Original Message-----
>From: Erroba, Ildefonso N [mailto:Erroba.Ildefonso_at_emeryworld.com]
>Sent: Tuesday, September 16, 2003 11:05 AM
>To: Multiple recipients of list ORACLE-L
>Subject: Session Stat interpretation - total runtime
>
>
>I believe that a number of threads have already discussed how
>to equate the total runtime of a given session to its
>individual stats as shown in v$sesstat, but I could not find
>on my collection of threads relating to this subject.
>
>The stats below shows that the individual session stat is more
>than the total runtime. I calculated session stat using the
>wait events (1268 secs) + CPU used by this session
>(182141/100) = 3089 secs, whereas the total runtime is only
>2622 secs (sysdate - logon_time). Could somebody help in
>accounting for the discrepancy? Appreciate any input on this.
>
>
> DB
>SESSION EVENTS REPORT
>
>======================
>Session Stat
>ID ST# Name
>VALUE
>======= ====
>============================================================
>===========
> 31 12 CPU used by this session
>182141
> 31 11 CPU used when call started
>182141
> 31 90 CR blocks created
>318
> 31 238 SQL*Net roundtrips to/from client
>2168273
> 31 177 active txn count during cleanout
>12876
> 31 197 branch node splits
>20
> 31 223 buffer is not pinned count
>3240239
> 31 222 buffer is pinned count
>2172655
> 31 237 bytes received via SQL*Net from client
>106496601
> 31 236 bytes sent via SQL*Net to client
>353672034
> 31 110 calls to get snapshot scn: kcmgss
>1955374
> 31 107 calls to kcmgas
>7836
> 31 105 calls to kcmgcs
>6384
> 31 71 change write time
>2694
> 31 178 cleanout - number of ktugct calls
>31196
> 31 165 cleanouts only - consistent read gets
>1638
> 31 193 cluster key scan block gets
>636
> 31 192 cluster key scans
>318
> 31 81 commit cleanout failures: block lost
>2704
> 31 84 commit cleanout failures: buffer being written
>8
> 31 85 commit cleanout failures: callback failure
>2
> 31 86 commit cleanouts
>103823
> 31 87 commit cleanouts successfully completed
>101109
> 31 176 commit txn count during cleanout
>25135
> 31 44 consistent changes
>318
> 31 41 consistent gets
>8913902
> 31 102 consistent gets - examination
>6640509
> 31 207 cursor authentications
>13
> 31 163 data blocks consistent reads - undo records applied
>318
> 31 43 db block changes
>3610861
> 31 40 db block gets
>4591125
> 31 175 deferred (CURRENT) block cleanout applications
>88288
> 31 76 dirty buffers inspected
>9386
> 31 26 enqueue conversions
>122
> 31 27 enqueue releases
>12117
> 31 25 enqueue requests
>12117
> 31 235 execute count
>1939464
> 31 79 free buffer inspected
>9386
> 31 75 free buffer requested
>711023
> 31 78 hot buffers moved to head of LRU
>29338
> 31 174 immediate (CR) block cleanout applications
>1638
> 31 173 immediate (CURRENT) block cleanout applications
>18011
> 31 203 index fetch by key
>1971817
> 31 204 index scans kdiixs1
>235827
> 31 196 leaf node 90-10 splits
>3234
> 31 195 leaf node splits
>6992
> 31 0 logons cumulative
>1
> 31 1 logons current
>1
> 31 17 messages sent
>6363
> 31 164 no work - consistent read gets
>2027606
> 31 2 opened cursors cumulative
>733
> 31 3 opened cursors current
>10
> 31 233 parse count (hard)
>13
> 31 232 parse count (total)
>1103
> 31 230 parse time cpu
>18
> 31 231 parse time elapsed
>20
> 31 42 physical reads
>662867
> 31 95 prefetched blocks
>320225
> 31 96 prefetched blocks aged out before use
>1227
> 31 14 process last non-idle time
>1063669608
> 31 7 recursive calls
>8236
> 31 8 recursive cpu usage
>112
> 31 116 redo buffer allocation retries
>14
> 31 114 redo entries
>1808956
> 31 122 redo log space requests
>14
> 31 123 redo log space wait time
>36
> 31 115 redo size
>623135736
> 31 73 redo synch time
>276
> 31 72 redo synch writes
>138
> 31 171 rollback changes - undo records applied
>29
> 31 166 rollbacks only - consistent read gets
>318
> 31 194 rows fetched via callback
>792660
> 31 13 session connect time
>1063669608
> 31 9 session logical reads
>13505027
> 31 20 session pga memory
>41565776
> 31 21 session pga memory max
>41565776
> 31 15 session uga memory
>38816520
> 31 16 session uga memory max
>38816520
> 31 103 shared hash latch upgrades - no wait
>848093
> 31 242 sorts (memory)
>123
> 31 244 sorts (rows)
>36156497
> 31 190 table fetch by rowid
>2103679
> 31 189 table scan blocks gotten
>368716
> 31 188 table scan rows gotten
>32838820
> 31 184 table scans (long tables)
>118
> 31 183 table scans (short tables)
>8
> 31 172 transaction rollbacks
>15
> 31 6 user calls
>2168275
> 31 4 user commits
>123
> 31 227 workarea executions - optimal
>244
> 31 226 workarea memory allocated
>37534
> 31 93 write clones created in foreground
>65
>
>Session
>ID BLOCK_GETS CONSISTENT_GETS
>PHYSICAL_READS
>BLOCK_CHANGES CONSISTENT_CHANGES
>======= ==================== ====================
>==================== ==================== ====================
> 31 4591125 8914482
> 663124
>3610861 318
>
>Session Total Total

Time(sec)        Avg(sec)

>ID Wait Event Waits Timouts Waited
Wait
>======= ============================== ============== ===========
=============== ===========
> 31 db file sequential read 329,270 0 657.21
.000
> 31 SQL*Net message from client 2,168,273 0 556.22
.000
> 31 db file scattered read 13,649 0 48.00
.000
> 31 log file sync 117 2 2.60
.020

>Current Logon
> Total
>Date Date
> Runtime
>============================== ==============================
> =========
>Sep-16-2003:00.30.31 Sep-15-2003:23.46.48
> 2622
>--
>Please see the official ORACLE-L FAQ: http://www.orafaq.net
>--
>Author: Erroba, Ildefonso N
> INET: Erroba.Ildefonso_at_emeryworld.com
>
>Fat City Network Services -- 858-538-5051 http://www.fatcity.com
>San Diego, California -- Mailing list and web hosting services
>---------------------------------------------------------------------
>To REMOVE yourself from this mailing list, send an E-Mail message
>to: ListGuru_at_fatcity.com (note EXACT spelling of 'ListGuru')
>and in the message BODY, include a line containing: UNSUB
>ORACLE-L (or the name of mailing list you want to be removed
>from). You may also send the HELP command for other
>information (like subscribing).
>

-- 
Please see the official ORACLE-L FAQ: http://www.orafaq.net
-- 
Author: John Kanagaraj
  INET: john.kanagaraj_at_hds.com

Fat City Network Services    -- 858-538-5051 http://www.fatcity.com
San Diego, California        -- Mailing list and web hosting services
---------------------------------------------------------------------
To REMOVE yourself from this mailing list, send an E-Mail message
to: ListGuru_at_fatcity.com (note EXACT spelling of 'ListGuru') and in
the message BODY, include a line containing: UNSUB ORACLE-L
(or the name of mailing list you want to be removed from).  You may
also send the HELP command for other information (like subscribing).
Received on Tue Sep 16 2003 - 18:24:36 CDT

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US