SQL> @snapper stats,ash 5 1 module=OGG-R1_825B-OPEN_DATA_SOURCE@2 Sampling SID module=OGG-R1_825B-OPEN_DATA_SOURCE@2 with interval 5 seconds, taking 1 snapshots... -- Session Snapper v4.24 - by Tanel Poder ( http://blog.tanelpoder.com/snapper ) - Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! :) ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ SID @INST, USERNAME , TYPE, STATISTIC , DELTA, HDELTA/SEC, %TIME, GRAPH , NUM_WAITS, WAITS/SEC, AVERAGES ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ 1864 @2, GGS , STAT, Requests to/from client , 337, 56.09, , , , , .99 per execution 1864 @2, GGS , STAT, opened cursors cumulative , 3, .5, , , , , .01 per execution 1864 @2, GGS , STAT, user calls , 340, 56.58, , , , , 1 per execution 1864 @2, GGS , STAT, recursive calls , 1, .17, , , , , 0 recursive CPU per recursive call 1864 @2, GGS , STAT, session logical reads , 7594, 1.26k, , , , , 7.62k total buffer visits 1864 @2, GGS , STAT, CPU used when call started , 16, 2.66, , , , , 160ms total CPU used when call started 1864 @2, GGS , STAT, CPU used by this session , 16, 2.66, , , , , 160ms total CPU used by this session 1864 @2, GGS , STAT, DB time , 594, 98.86, , , , , 1.75 per execution 1864 @2, GGS , STAT, cluster wait time , 7, 1.16, , , , , .02 per execution 1864 @2, GGS , STAT, concurrency wait time , 1, .17, , , , , 0 per execution 1864 @2, GGS , STAT, user I/O wait time , 559, 93.03, , , , , 1.65 per execution 1864 @2, GGS , STAT, non-idle wait time , 566, 94.2, , , , , 1.67 per execution 1864 @2, GGS , STAT, non-idle wait count , 1402, 233.33, , , , , 4.14 per execution 1864 @2, GGS , STAT, enqueue requests , 29, 4.83, , , , , .09 per execution 1864 @2, GGS , STAT, enqueue releases , 23, 3.83, , , , , .07 per execution 1864 @2, GGS , STAT, global enqueue gets sync , 12, 2, , , , , .04 per execution 1864 @2, GGS , STAT, global enqueue releases , 6, 1, , , , , .02 per execution 1864 @2, GGS , STAT, physical read total IO requests , 356, 59.25, , , , , 1.05 per execution 1864 @2, GGS , STAT, physical read total bytes , 2916352, 485.36k, , , , , 8.6k per execution 1864 @2, GGS , STAT, cell physical IO interconnect bytes , 2916352, 485.36k, , , , , 8.6k per execution 1864 @2, GGS , STAT, gcs messages sent , 329, 54.75, , , , , .97 per execution 1864 @2, GGS , STAT, ges messages sent , 3, .5, , , , , .01 per execution 1864 @2, GGS , STAT, db block gets , 7373, 1.23k, , , , , 21.75 per execution 1864 @2, GGS , STAT, db block gets from cache , 7373, 1.23k, , , , , 21.75 per execution 1864 @2, GGS , STAT, db block gets from cache (fastpath) , 1903, 316.71, , , , , 5.61 per execution 1864 @2, GGS , STAT, consistent gets , 221, 36.78, , , , , .65 per execution 1864 @2, GGS , STAT, consistent gets from cache , 221, 36.78, , , , , .65 per execution 1864 @2, GGS , STAT, consistent gets from cache (fastpath) , 66, 10.98, , , , , .19 per execution 1864 @2, GGS , STAT, consistent gets - examination , 150, 24.96, , , , , .44 per execution 1864 @2, GGS , STAT, logical read bytes from cache , 62210048, 10.35M, , , , , 183.51k per execution 1864 @2, GGS , STAT, physical reads , 356, 59.25, , , , , 1.05 per execution 1864 @2, GGS , STAT, physical reads cache , 356, 59.25, , , , , 1.05 per execution 1864 @2, GGS , STAT, physical read IO requests , 356, 59.25, , , , , 8.19k bytes per request 1864 @2, GGS , STAT, physical read bytes , 2916352, 485.36k, , , , , 8.6k per execution 1864 @2, GGS , STAT, db block changes , 4456, 741.6, , , , , 13.14 per execution 1864 @2, GGS , STAT, change write time , 5, .83, , , , , .01 per execution 1864 @2, GGS , STAT, free buffer requested , 466, 77.55, , , , , 1.37 per execution 1864 @2, GGS , STAT, dirty buffers inspected , 3, .5, , , , , .01 per execution 1864 @2, GGS , STAT, hot buffers moved to head of LRU , 1341, 223.18, , , , , 3.96 per execution 1864 @2, GGS , STAT, free buffer inspected , 884, 147.12, , , , , 2.61 per execution 1864 @2, GGS , STAT, commit cleanouts , 63, 10.48, , , , , .19 per execution 1864 @2, GGS , STAT, commit cleanouts successfully completed , 63, 10.48, , , , , .19 per execution 1864 @2, GGS , STAT, switch current to new buffer , 31, 5.16, , , , , .09 per execution 1864 @2, GGS , STAT, shared hash latch upgrades - no wait , 2, .33, , , , , .01 per execution 1864 @2, GGS , STAT, calls to kcmgcs , 99, 16.48, , , , , .29 per execution 1864 @2, GGS , STAT, calls to kcmgas , 122, 20.3, , , , , .36 per execution 1864 @2, GGS , STAT, calls to get snapshot scn: kcmgss , 151, 25.13, , , , , .45 per execution 1864 @2, GGS , STAT, redo entries , 2574, 428.38, , , , , 7.59 per execution 1864 @2, GGS , STAT, redo size , 1272112, 211.71k, , , , , ~ bytes per user commit 1864 @2, GGS , STAT, redo ordering marks , 73, 12.15, , , , , .22 per execution 1864 @2, GGS , STAT, redo subscn max counts , 2, .33, , , , , .01 per execution 1864 @2, GGS , STAT, file io wait time , 5588159, 930.02k, , , , , 15.7ms bad guess of IO wait time per IO request 1864 @2, GGS , STAT, gc current blocks received , 5, .83, , , , , .01 per execution 1864 @2, GGS , STAT, gc local grants , 226, 37.61, , , , , .67 per execution 1864 @2, GGS , STAT, gc remote grants , 325, 54.09, , , , , .96 per execution 1864 @2, GGS , STAT, undo change vector size , 432192, 71.93k, , , , , 1.27k per execution 1864 @2, GGS , STAT, no work - consistent read gets , 31, 5.16, , , , , .09 per execution 1864 @2, GGS , STAT, cleanouts only - consistent read gets , 1, .17, , , , , 0 per execution 1864 @2, GGS , STAT, RowCR attempts , 1, .17, , , , , 0 per execution 1864 @2, GGS , STAT, RowCR hits , 1, .17, , , , , 0 per execution 1864 @2, GGS , STAT, immediate (CURRENT) block cleanout applications , 73, 12.15, , , , , .22 per execution 1864 @2, GGS , STAT, immediate (CR) block cleanout applications , 1, .17, , , , , 0 per execution 1864 @2, GGS , STAT, deferred (CURRENT) block cleanout applications , 231, 38.44, , , , , .68 per execution 1864 @2, GGS , STAT, commit txn count during cleanout , 38, 6.32, , , , , .11 per execution 1864 @2, GGS , STAT, active txn count during cleanout , 36, 5.99, , , , , .11 per execution 1864 @2, GGS , STAT, cleanout - number of ktugct calls , 36, 5.99, , , , , .11 per execution 1864 @2, GGS , STAT, Block Cleanout Optim referenced , 67, 11.15, , , , , .2 per execution 1864 @2, GGS , STAT, min active SCN optimization applied on CR , 2, .33, , , , , .01 per execution 1864 @2, GGS , STAT, table fetch by rowid , 31, 5.16, , , , , .09 per execution 1864 @2, GGS , STAT, leaf node splits , 21, 3.49, , , , , .06 per execution 1864 @2, GGS , STAT, lob writes , 50, 8.32, , , , , .15 per execution 1864 @2, GGS , STAT, lob writes unaligned , 50, 8.32, , , , , .15 per execution 1864 @2, GGS , STAT, index fetch by key , 30, 4.99, , , , , .09 per execution 1864 @2, GGS , STAT, index scans kdiixs1 , 1, .17, , , , , 0 per execution 1864 @2, GGS , STAT, HSC Heap Segment Block Changes , 340, 56.58, , , , , 1 per execution 1864 @2, GGS , STAT, sql area evicted , 1, .17, , , , , 0 per execution 1864 @2, GGS , STAT, buffer is pinned count , 30, 4.99, , , , , .39 % buffer gets avoided thanks to buffer pin caching 1864 @2, GGS , STAT, buffer is not pinned count , 93, 15.48, , , , , .27 per execution 1864 @2, GGS , STAT, parse count (total) , 3, .5, , , , , 3 softparses per hardparse 1864 @2, GGS , STAT, parse count (hard) , 1, .17, , , , , 0 per execution 1864 @2, GGS , STAT, execute count , 339, 56.42, , , , , 113 executions per parse 1864 @2, GGS , STAT, bytes sent via SQL*Net to client , 58703, 9.77k, , , , , 173.17 bytes per roundtrip 1864 @2, GGS , STAT, bytes received via SQL*Net from client , 352913, 58.73k, , , , , 1.04k bytes per roundtrip 1864 @2, GGS , STAT, SQL*Net roundtrips to/from client , 339, 56.42, , , , , 1 per execution 1864 @2, GGS , TIME, hard parse elapsed time , 4562, 759.24us, .1%, [ ], , , 1864 @2, GGS , TIME, repeated bind elapsed time , 1539, 256.13us, .0%, [ ], , , 1864 @2, GGS , TIME, parse time elapsed , 4690, 780.54us, .1%, [ ], , , 1864 @2, GGS , TIME, DB CPU , 224965, 37.44ms, 3.7%, [@ ], , , 1864 @2, GGS , TIME, sql execute elapsed time , 5735589, 954.55ms, 95.5%, [##########], , , 1864 @2, GGS , TIME, DB time , 5717208, 951.49ms, 95.1%, [##########], , , 3.28 % unaccounted time 1864 @2, GGS , WAIT, db file sequential read , 5485206, 912.88ms, 91.3%, [WWWWWWWWWW], 353, 58.75, 15.54ms average wait 1864 @2, GGS , WAIT, gc current block busy , 838, 139.47us, .0%, [ ], 2, .33, 419us average wait 1864 @2, GGS , WAIT, gc cr grant 2-way , 475, 79.05us, .0%, [ ], 4, .67, 118.75us average wait 1864 @2, GGS , WAIT, gc current grant 2-way , 19205, 3.2ms, .3%, [ ], 144, 23.97, 133.37us average wait 1864 @2, GGS , WAIT, gc current grant busy , 52677, 8.77ms, .9%, [W ], 178, 29.62, 295.94us average wait 1864 @2, GGS , WAIT, library cache pin , 437, 72.73us, .0%, [ ], 2, .33, 218.5us average wait 1864 @2, GGS , WAIT, library cache lock , 218, 36.28us, .0%, [ ], 1, .17, 218us average wait 1864 @2, GGS , WAIT, SQL*Net message to client , 551, 91.7us, .0%, [ ], 347, 57.75, 1.59us average wait 1864 @2, GGS , WAIT, SQL*Net message from client , 94470, 15.72ms, 1.6%, [W ], 347, 57.75, 272.25us average wait -- End of Stats snap 1, end=2018-12-20 10:48:45, seconds=6 --------------------------------------------------------------------------------------------------------------- ActSes %Thread | INST | SQL_ID | SQL_CHILD | EVENT | WAIT_CLASS --------------------------------------------------------------------------------------------------------------- .49 (49%) | 2 | g4cf65js6kjf0 | 0 | db file sequential read | User I/O .14 (14%) | 2 | gabtdu60mta41 | 1 | db file sequential read | User I/O .11 (11%) | 2 | 43dvz166uqtkq | 0 | db file sequential read | User I/O .11 (11%) | 2 | 0s6zmhwfkuxwf | 0 | db file sequential read | User I/O .03 (3%) | 2 | g4cf65js6kjf0 | 0 | gc current request | Cluster .03 (3%) | 2 | dk114scy1su3r | 0 | db file sequential read | User I/O .03 (3%) | 2 | 43p1r78vagfby | 0 | db file sequential read | User I/O .03 (3%) | 2 | 2mb7g4w5wfk26 | 0 | ON CPU | ON CPU .03 (3%) | 2 | 5cfxg3dqppqj0 | 0 | db file sequential read | User I/O -- End of ASH snap 1, end=2018-12-20 10:48:45, seconds=5, samples_taken=35, AAS=1