Statspack

1. Statspack Analyse des statistiques générées Page 1

2. Génération d’un report (rappel) Après avoir pris les photos (« snapshots »), il suffit de lancer la procédure (sous l’utilisateur concerné): /oracle/ora920/rdbms/admin/spreport.sql Paramètres : numéros de photos debut et fin, et nom de fichier Page 2

3. Statistiques inutiles • Certaines statistiques dont les chiffres sont impressionnants n’ont aucun rapport avec une quelconque perte de performance. • Ceci inclut notamment les timers (smon timer, pmon timer), les stats « SQL*Net », les stats rdbms … Page 3

4. Partie 1 : Informations relatives aux snapshots STATSPACK report for DB Name DB Id Instance Inst Num Release Cluster Host ------------ ----------- ------------ -------- ----------- ------- ------------ SILODECL 387227106 SILODECL 1 9.2.0.4.0 NO servdon1 Snap Id Snap Time Sessions Curs/Sess Comment ------- ------------------ -------- --------- ------------------- Begin Snap: 5 16-Mar-04 15:34:01 11 2.2 End Snap: 9 16-Mar-04 15:59:46 25 1.0 Elapsed: 25.75 (mins) Page 4

5. Partie 2 : Informations relatives à l’instance (mémoires & accès) Cache Sizes (end) ~~~~~~~~~~~~~~~~~ Buffer Cache: 64M Std Block Size: 8K Shared Pool Size: 80M Log Buffer: 512K Load Profile ~~~~~~~~~~~~ Per Second Per Transaction --------------- --------------- Redo size: 1,433.53 276,850.00 Logical reads: 4,628.45 893,868.75 Block changes: 2.57 497.25 Physical reads: 19.23 3,713.38 Physical writes: 1.91 368.13 User calls: 12.06 2,328.50 Parses: 1.11 214.25 Hard parses: 0.41 79.75 Sorts: 1.66 320.25 Logons: 0.03 5.13 Executes: 1.11 214.75 Transactions: 0.01 % Blocks changed per Read: 0.06 Recursive Call %: 12.50 Rollback per transaction %: 0.00 Rows per Sort: 391.75 Page 5

6. Partie 3 : Efficacité de l’instance Instance Efficiency Percentages (Target 100%) ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Buffer Nowait %: 99.99 (> 90%) Redo NoWait %: 100.00 (>98%) Buffer Hit %: 99.62 (> 90%) In-memory Sort %: 99.41 (>99%) Library Hit %: 95.57 (> 95%) Soft Parse %: 62.78 (>80%) Execute to Parse %: 0.23 (> 98%) Latch Hit %: 99.26 (>99%) Parse CPU to Parse Elapsd %: 52.44 (> 95%) % Non-Parse CPU: 41.55 Shared Pool Statistics Begin End ------ ------ Memory Usage %: 81.57 94.27 ( devrait etre stable) % SQL with executions>1: 71.59 14.25 ( devrait etre proche de 100% si…) % Memory for SQL w/exec>1: 47.00 8.33 ( ‘’ ‘’ ‘’ ‘’) Page 6

7. Partie 4 : Top 5 des evenements générant de l’activité sur la base Top 5 Timed Events ~~~~~~~~~~~~~~~~~~ % Total Event Waits Time (s) Ela Time -------------------------------------------- ------------ ----------- -------- CPU time 171 41.03 db file sequential read 26,969 165 39.64 library cache pin 31 47 11.23 resmgr:waiting in end wait 333 22 5.40 latch free 2,041 3 .80 Page 7

8. Partie 5 : Événements d’attente Wait Events for DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> s - second -> cs - centisecond - 100th of a second -> ms - millisecond - 1000th of a second -> us - microsecond - 1000000th of a second -> ordered by wait time desc, waits desc (idle events last) Avg Total Wait wait Waits Event Waits Timeouts Time (s) (ms) /txn ---------------------------- ------------ ---------- ---------- ------ -------- db file sequential read 26,969 0 165 6 3,371.1 library cache pin 31 15 47 1507 3.9 resmgr:waiting in end wait 333 0 22 67 41.6 latch free 2,041 0 3 2 255.1 buffer busy waits 565 0 3 6 70.6 resmgr:waiting in check 46 0 2 39 5.8 control file parallel write 501 0 1 2 62.6 resmgr:waiting in check2 20 0 1 40 2.5 SQL*Net more data to client 5,942 0 0 0 742.8 log file parallel write 43 0 0 5 5.4 log file sync 17 0 0 6 2.1 db file scattered read 13 0 0 2 1.6 control file sequential read 630 0 0 0 78.8 resmgr:wait in actses run 1 0 0 5 0.1 direct path read 164 0 0 0 20.5 direct path write 30 0 0 0 3.8 SQL*Net message from client 18,643 0 46,422 2490 2,330.4 SQL*Net more data from clien 231 0 8 36 28.9 SQL*Net message to client 18,657 0 0 0 2,332.1 -------------------------------------------------------------2,041 3 .80 On recherche ici les plus grosses attentes (waits & avg wait), ce sont celles qui handicapent le plus la base, car Oracle attend que ces événements soient passés afin de pouvoir enchaîner sur le traitement suivant. Page 8

9. Partie 6 : Événements d’attente (background) Background Wait Events for DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> ordered by wait time desc, waits desc (idle events last) Avg Total Wait wait Waits Event Waits Timeouts Time (s) (ms) /txn ---------------------------- ------------ ---------- ---------- ------ -------- control file parallel write 501 0 1 2 62.6 log file parallel write 43 0 0 5 5.4 db file scattered read 9 0 0 3 1.1 db file sequential read 5 0 0 3 0.6 control file sequential read 350 0 0 0 43.8 rdbms ipc reply 8 0 0 0 1.0 rdbms ipc message 1,590 1,535 7,526 4733 198.8 smon timer 6 4 1,535 ###### 0.8 pmon timer 519 519 1,509 2907 64.9 ------------------------------------------------------------- Page 9

10. Partie 7 : Requetes les plus consommatrices (part 1) SQL ordered by Gets for DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> End Buffer Gets Threshold: 10000 -> Note that resources reported for PL/SQL includes the resources used by all SQL statements called within the PL/SQL code. As individual SQL statements are also reported, it is possible and valid for the summed total % to exceed 100 CPU Elapsd Buffer Gets Executions Gets per Exec %Total Time (s) Time (s) Hash Value --------------- ------------ -------------- ------ -------- --------- ----- 6,721,520 633 10,618.5 94.0 52.21 210.53 1358576331 Module: JDBC Thin Client select /*+ INDEX (DONNEE_TVA IX_DONNEE_TVA_03) INDEX (IMPRIME_TV A IX_IMPRIME_TVA_03) */ T.ID_DEPOT_TVA, T.siren, T.nic, T.numact , T.numseq, T.numero_ordre, T.sages2_recette, T.sages2_cdi, T.ty pe_declaration, to_char(T.dls,'DD/MM/YYYY') as dls, to_char(T.da te_depot,'DD/MM/YYYY') as date_depot, to_char(T.date_debut_perio 93,779 4 23,444.8 1.3 6.44 7.05 300097093 Module: SQL*Plus begin :numero_snapshot := statspack.snap(i_snap_level=>7); end; Attention, 500 premiers caracteres, voir hashvalue Page 10

11. Partie 7 : Requetes les plus consommatrices (part 2) SQL ordered by Reads for DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> End Disk Reads Threshold: 1000 CPU Elapsd Physical Reads Executions Reads per Exec %Total Time (s) Time (s) Hash Value --------------- ------------ -------------- ------ -------- --------- ---------- 22,042 633 34.8 74.2 52.21 210.53 1358576331 Module: JDBC Thin Client select /*+ INDEX (DONNEE_TVA IX_DONNEE_TVA_03) INDEX (IMPRIME_TV A IX_IMPRIME_TVA_03) */ T.ID_DEPOT_TVA, T.siren, T.nic, T.numact , T.numseq, T.numero_ordre, T.sages2_recette, T.sages2_cdi, T.ty pe_declaration, to_char(T.dls,'DD/MM/YYYY') as dls, to_char(T.da te_depot,'DD/MM/YYYY') as date_depot, to_char(T.date_debut_perio 1,902 4 475.5 6.4 6.44 7.05 300097093 Module: SQL*Plus begin :numero_snapshot := statspack.snap(i_snap_level=>7); end; Page 11

12. Partie 7 : Requetes les plus consommatrices (part 3) SQL ordered by Executionsfor DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> End Executions Threshold: 100 CPU per Elap per Executions Rows Processed Rows per Exec Exec (s) Exec (s) Hash Value ------------ --------------- ---------------- ----------- ---------- ---------- 633 4,531 7.2 0.08 0.33 1358576331 Module: JDBC Thin Client select /*+ INDEX (DONNEE_TVA IX_DONNEE_TVA_03) INDEX (IMPRIME_TV A IX_IMPRIME_TVA_03) */ T.ID_DEPOT_TVA, T.siren, T.nic, T.numact , T.numseq, T.numero_ordre, T.sages2_recette, T.sages2_cdi, T.ty pe_declaration, to_char(T.dls,'DD/MM/YYYY') as dls, to_char(T.da te_depot,'DD/MM/YYYY') as date_depot, to_char(T.date_debut_perio Page 12

13. Partie 7 : Requetes les plus consommatrices (part 4) SQL ordered by Parse Calls for DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> End Parse Calls Threshold: 1000 % Total Parse Calls Executions Parses Hash Value ------------ ------------ -------- ---------- 633 633 36.93 1358576331 Module: JDBC Thin Client select /*+ INDEX (DONNEE_TVA IX_DONNEE_TVA_03) INDEX (IMPRIME_TV A IX_IMPRIME_TVA_03) */ T.ID_DEPOT_TVA, T.siren, T.nic, T.numact , T.numseq, T.numero_ordre, T.sages2_recette, T.sages2_cdi, T.ty pe_declaration, to_char(T.dls,'DD/MM/YYYY') as dls, to_char(T.da te_depot,'DD/MM/YYYY') as date_depot, to_char(T.date_debut_perio Page 13

14. Partie 8 : Activité de l’instance Instance Activity Stats for DB: SILODECL Instance: SILODECL Snaps: 5 -9 Statistic Total per Second per Trans --------------------------------- ------------------ -------------- ------------ active txn count during cleanout 85 0.1 10.6 background timeouts 1,534 1.0 191.8 buffer is not pinned count 2,912,871 1,885.4 364,108.9 buffer is pinned count 2,101,500 1,360.2 262,687.5 bytes received via SQL*Net from c 7,057,529 4,568.0 882,191.1 bytes sent via SQL*Net to client 22,618,423 14,639.8 2,827,302.9 calls to get snapshot scn: kcmgss 1,978 1.3 247.3 […] commit cleanouts successfully com 406 0.3 50.8 commit txn count during cleanout 258 0.2 32.3 consistent changes 159 0.1 19.9 consistent gets 7,147,193 4,626.0 893,399.1 CPU used by this session 17,072 11.1 2,134.0 CPU used when call started 17,072 11.1 2,134.0 […] transaction rollbacks 8 0.0 1.0 Ici on peut détailler chaque action de la base, mais ceci ne sert qu’a confirmer le pré-diagnostic déjà établi, Explications completes sur Oracle9i Database Reference Release 2 (9.2) Page 14

15. Partie 8 : Activité de l’instance Activité significative : Activité des buffers buffer is not pinned count 2,912,871 1,885.4 364,108.9 => buffers libres buffer is pinned count 2,101,500 1,360.2 262,687.5 => buffers occupés (=> déplacement des blocs en mémoire) no buffer to keep pinned count 2,805,800 1,816.1 350,725.0 => buffers alloués mais non disponibles no work - consistent read gets 2,469,792 1,598.6 308,724.0 => buffers ok (ni cleanout, ni rollback) Activité des I/O index fetch by key 296,170 191.7 37,021.3 => acces table index par clef (le + efficace) index scans kdiixs1 2,946,260 1,907.0 368,282.5 => acces par “index fast full scan” table fetch by rowid 1,182,762 765.5 147,845.3 => acces table via index : optimisé table fetch continued row 2,138 1.4 267.3 => multiples I/O pour acceder un bloc, du a un bloc trop grand ou chaîné table scan blocks gotten 320 0.2 40.0 => besoin reel des select en blocs table scan rows gotten 2,946 1.9 368.3=> besoin reel des select en lignes table scans (long tables) 0 0.0 0.0 => scans sur grandes tables table scans (short tables) 47 0.0 5.9 => scans sur petites tables Tris sorts (disk) 15 0.0 1.9 => tris disque sorts (memory) 2,547 1.7 318.4 => tris memoire sorts (rows) 1,003,672 649.6 125,459.0 => nb de lignes triées Autres transaction rollbacks 8 0.0 1.0 Page 15

16. Partie 9 : Activité des I/O (plusieurs tris) File IO Stats for DB: SILODECL Instance: SILODECL Snaps: 5 -9 ->ordered by Tablespace, File Tablespace Filename ------------------------ ---------------------------------------------------- Av Av Av Av Buffer Av Buf Reads Reads/s Rd(ms) Blks/Rd Writes Writes/s Waits Wt(ms) -------------- ------- ------ ------- ------------ -------- ---------- ------ SILODECL_D06 /ADE-DECLA1-DATA/silodecl_d06.dbf 114 0 6.3 1.0 0 0 2 5.0 SILODECL_D07 /ADE-DECLA1-DATA/silodecl_d07.dbf 103 0 5.7 1.0 0 0 4 2.5 SILODECL_D08 /ADE-DECLA1-DATA/silodecl_d08.dbf 417 0 6.8 1.0 0 0 14 2.9 SILODECL_D09 /ADE-DECLA1-DATA/silodecl_d09.dbf 696 0 6.7 1.0 0 0 19 4.2 SILODECL_D10 /ADE-DECLA1-DATA/silodecl_d10.dbf 707 0 7.0 1.0 0 0 5 8.0 […] SILODECL_D16 /ADE-DECLA1-DATA/silodecl_d16.dbf 3,898 3 6.8 1.0 0 0 99 5.2 SILODECL_D17 /ADE-DECLA1-DATA/silodecl_d17.dbf 2,999 2 6.5 1.0 0 0 84 4.8 SILODECL_I05 /ADE-DECLA1-INDEX/silodecl_i05.dbf 64 0 6.6 1.0 0 0 0 SILODECL_I06 /ADE-DECLA1-INDEX/silodecl_i06.dbf 313 0 6.3 1.0 0 0 1 10.0 On recherche ici les différences de traitement (I/O) entre les différents tablespaces plutôt que des valeurs optimales, ainsi que le « buffer wait » moyen qui donne une idée de l’encombrement des I/O a partir du disque Page 16

17. Partie 10 : Buffer pool Buffer Pool Statistics for DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> Standard block size Pools D: default, K: keep, R: recycle -> Default Pools for other block sizes: 2k, 4k, 8k, 16k, 32k Free Write Buffer Number of Cache Buffer Physical Physical Buffer Complete Busy P Buffers Hit % Gets Reads Writes Waits Waits Waits --- ---------- ----- ----------- ----------- ---------- ------- -------- ------ D 7,940 99.6 7,150,839 27,043 273 0 0 724 ------------------------------------------------------------- Cette statistique donne le ratio entre la recherche de blocs de données trouvés en cache sur le nombre total de blocs requis par l’ensemble des requêtes SQL. Un taux < à 95% indique que le buffer est trop petit, exceptionnellement que de multiples activités se passent simultanément sur la base (tres tres rare). Page 17

18. Partie 11 : Conseiller Buffer pool Buffer Pool Advisory -> Only rows with estimated physical reads >0 are displayed -> ordered by Block Size, Buffers For Estimate Size for Size Buffers for Est Physical Estimated P Estimate (M) Factr Estimate Read Factor Physical Reads --- ------------ ----- ---------------- ------------- ------------------ D 16 .3 1,985 1.01 6,993,287 D 32 .5 3,970 1.01 6,959,843 D 48 .8 5,955 1.00 6,942,127 D 64 1.0 7,940 1.00 6,923,121 D 80 1.3 9,925 1.00 6,914,350 D 96 1.5 11,910 1.00 6,897,016 D 112 1.8 13,895 0.99 6,877,294 D 128 2.0 15,880 0.99 6,858,941 D 144 2.3 17,865 0.99 6,848,817 D 160 2.5 19,850 0.99 6,830,846 D 176 2.8 21,835 0.99 6,827,869 D 192 3.0 23,820 0.99 6,822,871 D 208 3.3 25,805 0.98 6,817,586 D 224 3.5 27,790 0.98 6,810,837 D 240 3.8 29,775 0.98 6,800,825 D 256 4.0 31,760 0.98 6,792,006 D 272 4.3 33,745 0.98 6,780,609 D 288 4.5 35,730 0.98 6,759,884 D 304 4.8 37,715 0.97 6,745,256 D 320 5.0 39,700 0.97 6,715,919 ------------------------------------------------------------- Advisory = conseiller Cette partie simule une diminution /augmentation du buffer pool afin de vérifier le gain ou l’impact de la taille mémoire buffer sur le nombre de lectures nécessaires Rappel : il existe les vue v$shared_pool_advice et v$buffer_pool_advice qui fournissent les mêmes données en temps réel. Page 18

19. Partie 12 : Attentes du Buffer Pool Buffer wait Statistics for DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> ordered by wait time desc, waits desc Tot Wait Avg Class Waits Time (s) Time (ms) ------------------ ----------- ---------- --------- data block 723 3 5 undo header 1 0 0 ------------------------------------------------------------- Attente majoritairement dûe aux blocs de données Page 19

20. Partie 13 : Rollbacks & undo Rollback Segment Stats : Inutilisé en 9i Remplacé par : Undo Segment Summary for DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> Undo segment block stats: -> uS - unexpired Stolen, uR - unexpired Released, uU - unexpired reUsed -> eS - expired Stolen, eR - expired Released, eU - expired reUsed Undo Undo Num Max Qry Max Tx Snapshot Out of uS/uR/uU/ TS# Blocks Trans Len (s) Concurcy Too Old Space eS/eR/eU ---- -------------- ---------- -------- ---------- -------- ------ ------------- 1 153 11,558 5 2 0 0 0/0/0/0/0/0 ------------------------------------------------------------- Undo Segment Stats for DB: SILODECL Instance: SILODECL Snaps: 5 -9 -> ordered by Time desc Undo Num Max Qry Max Tx Snap Out of uS/uR/uU/ End Time Blocks Trans Len (s) Concy Too Old Space eS/eR/eU ------------ ------------ -------- ------- -------- ------- ------ ------------- 16-Mar 15:56 29 3,872 2 2 0 0 0/0/0/0/0/0 16-Mar 15:46 40 3,853 4 1 0 0 0/0/0/0/0/0 16-Mar 15:36 84 3,833 5 1 0 0 0/0/0/0/0/0 ------------------------------------------------------------- Page 20