Please Comment on STATSPACK Report

[jkny1319]

Buffer Cache: 1,632M 1,632M Std Block Size: 8K
Shared Pool Size: 2,544M 2,544M Log Buffer: 6,200K
Per Second Per Transaction
Redo size: 2,207,472.91 778.35
Logical reads: 29,644.94 10.45
Block changes: 15,117.28 5.33
Physical reads: 49.08 0.02
Physical writes: 152.28 0.05
User calls: 3.16 0.00
Parses: 58.08 0.02
Hard parses: 8.25 0.00
Sorts: 705.81 0.25
Logons: 0.04 0.00
Executes: 5,701.67 2.01
Transactions: 2,836.10
% Blocks changed per Read: 50.99 Recursive Call %: 99.97
Rollback per transaction %: 0.00 Rows per Sort: 2.02

Instance Efficiency Percentages (Target 100%)
Buffer Nowait %: 100.00 Redo NoWait %: 100.00
Buffer Hit %: 99.87 In-memory Sort %: 100.00
Library Hit %: 99.46 Soft Parse %: 85.79
Execute to Parse %: 98.98 Latch Hit %: 99.98
Parse CPU to Parse Elapsd %: 94.83 % Non-Parse CPU: 98.43

Shared Pool Statistics
Begin End
Memory Usage %: 59.92 60.34
% SQL with executions>1: 99.49 99.63
% Memory for SQL w/exec>1: 96.01 96.94

Top 5 Timed Events
Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class
CPU time 3,594 99.2
log file parallel write 6,368,927 2,541 0 70.1 System I/O
db file parallel write 66,788 65 1 1.8 System I/O
enq: RO - fast object reuse 2,700 48 18 1.3 Application
log file sequential read 10,198 35 3 1.0 System I/O

Time Model Statistics
Total time in database user-calls (DB Time): 3622.7s
Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic
Ordered by % or DB time desc, Statistic name
Statistic Name Time (s) % of DB Time
sql execute elapsed time 3,623.07 100.01
DB CPU 3,593.81 99.20
PL/SQL execution elapsed time 253.38 6.99
parse time elapsed 104.50 2.88
hard parse elapsed time 79.49 2.19
PL/SQL compilation elapsed time 17.49 0.48
hard parse (sharing criteria) elapsed time 0.32 0.01
connection management call elapsed time 0.13 0.00
repeated bind elapsed time 0.01 0.00
sequence load elapsed time 0.00 0.00
hard parse (bind mismatch) elapsed time 0.00 0.00
DB time 3,622.74
background elapsed time 3,272.29
background cpu time 3,035.15

Wait Class Waits %Time -outs Total Wait Time (s) Avg wait (ms) Waits /txn
System I/O 6,489,897 0.00 2,646 0 0.63
Application 3,148 0.00 48 15 0.00
User I/O 159,186 0.00 37 0 0.02
Other 527,892 0.00 16 0 0.05
Concurrency 73 4.11 10 135 0.00
Configuration 578 0.35 9 16 0.00
Commit 5,667 0.00 4 1 0.00
Network 10,540 0.00 0 0 0.00

log file parallel write 6,368,927 0.00 2,541 0 0.62
db file parallel write 66,788 0.00 65 1 0.01
enq: RO - fast object reuse 2,700 0.00 48 18 0.00
log file sequential read 10,198 0.00 35 3 0.00
db file sequential read 131,476 0.00 19 0 0.01
Data file init write 7,652 0.00 14 2 0.00
rdbms ipc reply 8,381 0.00 8 1 0.00
LGWR wait for redo copy 516,796 0.00 7 0 0.05
log file switch completion 250 0.80 7 26 0.00
buffer busy waits 21 14.29 6 268 0.00
os thread startup 40 0.00 4 106 0.00
log file sync 5,667 0.00 4 1 0.00
control file parallel write 4,267 0.00 4 1 0.00
enq: HW - contention 1 0.00 2 1639 0.00
db file scattered read 989 0.00 1 1 0.00
Log archive I/O 26,165 0.00 1 0 0.00
log file switch (checkpoint incomplete) 5 0.00 1 235 0.00
direct path write temp 2,838 0.00 1 0 0.00
reliable message 2,700 0.00 1 0 0.00
direct path read temp 8,574 0.00 1 0 0.00
control file sequential read 13,140 0.00 0 0 0.00
db file single write 173 0.00 0 3 0.00
direct path write 6,648 0.00 0 0 0.00
log file single write 412 0.00 0 1 0.00
SQL*Net break/reset to client 448 0.00 0 1 0.00
enq: CF - contention 13 0.00 0 10 0.00
latch free 1 0.00 0 84 0.00
direct path read 830 0.00 0 0 0.00
SQL*Net more data from client 320 0.00 0 0 0.00
latch: redo writing 322 0.00 0 0 0.00
SQL*Net message to client 9,942 0.00 0 0 0.00
local write wait 6 0.00 0 1 0.00
SQL*Net more data to client 278 0.00 0 0 0.00
latch: library cache 12 0.00 0 0 0.00
latch: session allocation 1 0.00 0 0 0.00
SQL*Net message from client 9,947 0.00 23,639 2377 0.00
wait for unread message on broadcast channel 3,577 100.00 3,525 986 0.00

Background Wait Events
ordered by wait time desc, waits desc (idle events last)
Event Waits %Time -outs Total Wait Time (s) Avg wait (ms) Waits /txn
log file parallel write 6,368,926 0.00 2,541 0 0.62
db file parallel write 66,788 0.00 65 1 0.01
log file sequential read 10,198 0.00 35 3 0.00
events in waitclass Other 516,810 0.00 7 0 0.05
os thread startup 40 0.00 4 106 0.00
control file parallel write 3,748 0.00 3 1 0.00
Log archive I/O 26,165 0.00 1 0 0.00
buffer busy waits 4 0.00 1 248 0.00
direct path write 824 0.00 0 0 0.00
control file sequential read 8,613 0.00 0 0 0.00
log file single write 412 0.00 0 1 0.00
db file scattered read 53 0.00 0 1 0.00
direct path read 824 0.00 0 0 0.00
latch: redo writing 322 0.00 0 0 0.00
Data file init write 6 0.00 0 6 0.00
db file sequential read 20 0.00 0 0 0.00
rdbms ipc message 254,990 5.01 42,231 166 0.02
smon timer 2,704 0.00 3,525 1304 0.00
pmon timer 1,223 98.69 3,519 2877 0.00
Streams AQ: qmn slave idle wait 220 0.00 3,512 15962 0.00
Streams AQ: qmn coordinator idle wait 310 41.94 3,512 11328 0.00
Streams AQ: waiting for time management or cleanup tasks 18 50.00 2,896 160904 0.00

Operating System Statistics
Statistic Total
AVG_BUSY_TIME 41,441
AVG_IDLE_TIME 319,538
AVG_IOWAIT_TIME 0
AVG_SYS_TIME 21,492
AVG_USER_TIME 19,836
BUSY_TIME 831,251
IDLE_TIME 6,393,355
IOWAIT_TIME 0
SYS_TIME 432,210
USER_TIME 399,041
LOAD 3
OS_CPU_WAIT_TIME 7,100
RSRC_MGR_CPU_WAIT_TIME 0
VM_IN_BYTES 24,576
VM_OUT_BYTES 0
PHYSICAL_MEMORY_BYTES 59,877,433,344
NUM_CPUS 20

Service Statistics
ordered by DB Time
Service Name DB Time (s) DB CPU (s) Physical Reads Logical Reads
SYS$USERS 3,611.90 3,585.80 175,414 106,991,695
10.80 8.00 278 74,054
SYS$BACKGROUND 0.00 0.00 1,455 20,445

Service Wait Class Stats
Wait Class info for services in the Service Statistics section.
Total Waits and Time Waited displayed for the following wait classes: User I/O, Concurrency, Administrative, Network
Time Waited (Wt Time) in centisecond (100th of a second)
Service Name User I/O Total Wts User I/O Wt Time Concurcy Total Wts Concurcy Wt Time Admin Total Wts Admin Wt Time Network Total Wts Network Wt Time
SYS$USERS 157099 3573 29 464 0 0 2953 5
299 26 0 0 0 0 7452 0
SYS$BACKGROUND 1782 54 44 521 0 0 0 0

SQL ordered by Elapsed Time
Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code.
% Total DB Time is the Elapsed Time of the SQL statement divided into the Total Database Time multiplied by 100
Elapsed Time (s) CPU Time (s) Executions Elap per Exec (s) % Total DB Time SQL Id SQL Module SQL Text
3,526 3,505 0 97.32 d4zqn6mrqudp9 SQL*Plus DECLARE CURSOR dmaf2kad_cur...
192 189 1,940,395 0.00 5.31 7x6q5gbadqfkm SQL*Plus UPDATE DMAF2KOP_06 SET DMAF2KO...
121 120 2,529,127 0.00 3.34 df34r66td9g6r SQL*Plus SELECT IQCIDATE, IQDCDATE, RQC...
95 95 2,529,419 0.00 2.62 dq8gvm8d52758 SQL*Plus SELECT SURNAME, GQHUFLAG FROM ...
55 54 581,293 0.00 1.50 9ts789szm54y7 SQL*Plus UPDATE DMAF2KOP_06 SET DMAF2KO...
34 34 0 0.94 bxwypmga1nq7s SQL*Plus SELECT GRFC2K_06.COLST, GRFC2K...
26 24 0 0.73 90pry53952x6u TOAD 8.6.1.0 BEGIN cef06.cef06_run('48'); E...
17 17 6 2.75 0.46 b058ymxj1rvkg Admin Connection SELECT sql_id, sql_text from v...
12 12 2,702 0.00 0.32 cn1gtsav2d5jh DBMS_SCHEDULER BEGIN BEGIN IF (xdb.DBMS...
7 7 1 7.47 0.21 5huzbrs2xr2tx TOAD 8.6.1.0 SELECT CO.SORT_ORDER, D.MAFID...

SQL ordered by CPU Time
Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code.
% Total DB Time is the Elapsed Time of the SQL statement divided into the Total Database Time multiplied by 100
CPU Time (s) Elapsed Time (s) Executions CPU per Exec (s) % Total DB Time SQL Id SQL Module SQL Text
3,505 3,526 0 97.32 d4zqn6mrqudp9 SQL*Plus DECLARE CURSOR dmaf2kad_cur...
189 192 1,940,395 0.00 5.31 7x6q5gbadqfkm SQL*Plus UPDATE DMAF2KOP_06 SET DMAF2KO...
120 121 2,529,127 0.00 3.34 df34r66td9g6r SQL*Plus SELECT IQCIDATE, IQDCDATE, RQC...
95 95 2,529,419 0.00 2.62 dq8gvm8d52758 SQL*Plus SELECT SURNAME, GQHUFLAG FROM ...
54 55 581,293 0.00 1.50 9ts789szm54y7 SQL*Plus UPDATE DMAF2KOP_06 SET DMAF2KO...
34 34 0 0.94 bxwypmga1nq7s SQL*Plus SELECT GRFC2K_06.COLST, GRFC2K...
24 26 0 0.73 90pry53952x6u TOAD 8.6.1.0 BEGIN cef06.cef06_run('48'); E...
17 17 6 2.75 0.46 b058ymxj1rvkg Admin Connection SELECT sql_id, sql_text from v...
12 12 2,702 0.00 0.32 cn1gtsav2d5jh DBMS_SCHEDULER BEGIN BEGIN IF (xdb.DBMS...
7 7 1 7.47 0.21 5huzbrs2xr2tx TOAD 8.6.1.0 SELECT CO.SORT_ORDER, D.MAFID...

SQL ordered by Executions
Total Executions: 20,595,958
Captured SQL account for 37.6% of Total
Executions Rows Processed Rows per Exec CPU per Exec (s) Elap per Exec (s) SQL Id SQL Module SQL Text
2,529,419 2,529,419 1.00 0.00 0.00 dq8gvm8d52758 SQL*Plus SELECT SURNAME, GQHUFLAG FROM ...
2,529,127 2,529,127 1.00 0.00 0.00 df34r66td9g6r SQL*Plus SELECT IQCIDATE, IQDCDATE, RQC...
1,940,395 1,940,395 1.00 0.00 0.00 7x6q5gbadqfkm SQL*Plus UPDATE DMAF2KOP_06 SET DMAF2KO...
581,293 581,293 1.00 0.00 0.00 9ts789szm54y7 SQL*Plus UPDATE DMAF2KOP_06 SET DMAF2KO...
17,533 20,877 1.19 0.00 0.00 bsa0wjtftg3uw select file# from file$ where ...
11,505 11,505 1.00 0.00 0.00 9qgtwh66xg6nz update seg$ set type#=:4, bloc...
8,112 0 0.00 0.00 0.00 gdhz78y24tvnz delete from ncomp_dll$ where o...
8,100 0 0.00 0.00 0.00 9y7s2afnkqs9d delete from idl_ub2$ where obj...
8,100 0 0.00 0.00 0.00 d5jd9b2xct7xz delete from idl_char$ where ob...
8,100 0 0.00 0.00 0.00 dvpfc386d6dmm delete from idl_sb4$ where obj...

[tamilselvan]

Are the users complaining about response time?

Tamil

[jkny1319]

Yes. There is a job PL/SQL procedure select and updates 1 million records that I ran which took about hours. Iam trying to optimize this.

[bhatia333]

Whats the database version? Hardware? OS? What is your log file size? Can you attach the statspack report rather that copy pasting it for readibility purpose.?

[davey23uk]

Yes. There is a job PL/SQL procedure select and updates 1 million records that I ran which took about hours. Iam trying to optimize this.

statspack wont help you then, you need to trace that query and see wherer the time is being taken

[slimdave]

I bet it runs row-by-row selects and updates, instead of using bulk operations.

[tamilselvan]

Yes. There is a job PL/SQL procedure select and updates 1 million records that I ran which took about hours. Iam trying to optimize this.

You need to learn how to use dbms profiler.

Tamil

[pss]

I bet it runs row-by-row selects and updates, instead of using bulk operations.

It sure does :-) Take a look at SQL list. The first one is declare cursor... then there is a couple of updates of a table with a similar name.
I saw guys doing it to a 1.6 million rows table with 130+ columns... one column at a time!!! Doing 130+ commits per row updated. This thing used to take 4 days to finish! I replaced it with an update and an insert (no merge in 8i). The execution went down to 30-40 minutes.

[Bore]

To add to the latest 2 comments
Executions: 2,529,419
Rows processed:2,529,419
Rows per execution: 1.00
statement: SQL*Plus SELECT SURNAME, GQHUFLAG FROM ...

Executions: 2,529,127
Rows Processed: 2,529,127
Rows per execution: 1.00
Statement: SQL*Plus SELECT IQCIDATE, IQDCDATE, RQC...
Executions: 1,940,395
Rows processed: 1,940,395
Rows per execution: 1.00
Statement: SQL*Plus UPDATE DMAF2KOP_06 SET DMAF2KO...

Executions:581,293
Rows processed: 581,293
Rows per execution: 1.00
Statement: SQL*Plus UPDATE DMAF2KOP_06 SET DMAF2KO...

So, guys, you hit the reason right on the head. I guess at least updates should be easy to be done bulk. Just updating row by row is not slow but deadly slow