Introduction

Comme vous avez pu dans le voir dans l’article Générer des traces sur votre instance Oracle , les traces en elle-même sont globalement illisibles

Pour vous éviter un mal de tête, Oracle a développer un outil très pratique nommé Tkprof qui se chargera de vous décoder vos traces et de vous fournir quelques éléments pratiques comme le plan d’exécution des requêtes.

Utilisation de TkProf

TkProf est inclut dans Oracle Client et Oracle Database. C’est un outil en ligne de commande que vous pouvez via une invite de commande sous Windows ou un terminal sous Linux.

Sans plus attendre, voici la syntaxe :

Windows :

tkprof  C:/oracle/…./trace.trc output=C:/oracle/…./trace_output.txt

Linux :

$ORACLE_HOME/bin/tkprof  /app/oracle/…/trace.trc output=/app/oracle/…/trace_output.txt

Attention : La version de TkProf doit être impérativement la même que celle de la base de donnée où vous avez généré vos traces. Si elles sont différentes, vous aurez à coup sûr des valeurs aberrantes dans votre output file.

Les options indispensables

Pour que vos rapports TkProf soient plus lisibles, quelques options sont indispensables.

• SYS=no : Ne pas afficher les ordres SQL exécutés par l’utilisateur SYS
• EXPLAIN=user/password : Permet de spécifier le schéma dans lequel tkprof va générer les explain plan. Inutile si vous générez vos traces directement avec le compte oracle en local sur votre base de donnée
• AGGREGATE=no : Permet de ne pas regrouper les ordres SQL similaires
• SORT= : Permet de triées les instructions selon l’option désirée

Et comment je les utilise ces options ?

Simple comme bonjour ! Par exemple, pour des traces sans ordres SQL exécutées par SYS et pas de regroupements d’ordres SQL similaires sous Linux :

$ORACLE_HOME/bin/tkprof  /app/oracle/…/trace.trc sys=no aggregate=no output=/app/oracle/…/trace_output.txt

Comment lire mon rapport ?

Pour mieux illustrer, prenons la trace qui avait été générée dans mon article Générer des traces sur votre instance Oracle.

********************************************************************************

SELECT e.last_name, j.job_title from oracle.employees e
    JOIN oracle.jobs j ON (e.job_id=j.job_id)

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.13          0          4          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0         15          0         107
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.01       0.14          0         19          0         107

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS

Rows     Row Source Operation
-------  ---------------------------------------------------
    107  HASH JOIN  (cr=15 pr=0 pw=0 time=5798 us)
     19   TABLE ACCESS FULL JOBS (cr=7 pr=0 pw=0 time=187 us)
    107   TABLE ACCESS FULL EMPLOYEES (cr=8 pr=0 pw=0 time=796 us)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       2        0.00          0.00
  SQL*Net message from client                     2        0.14          0.15
********************************************************************************

Nous pouvons distinguer trois parties :

• Un tableau avec plein de nombres. (On reviendra dessus après)
• L’explain plan de la requête
• Les Wait events générés par la requête

Comment je le lis le tableau ?

Ce fameux tableau est découpé en trois lignes :

• Parse : Cette étape détermine le plan d’exécution de votre requête
• Execute : Pour les ordres INSERT, UPDATE, DELETE : modifie les données. Pour l’ordre SELECT : Identifie les lignes à extraire
• Fetch : Extraction des lignes et opérations de tri. Concerne uniquement l’ordre SELECT.

Concernant les lignes, voici leurs significations :

• Count : Nombre de fois que le Parse/Execute/Fetch a été exécuté
• CPU (Seconde) : Temps total de traitement CPU
• Elapsed (Seconde) : Temps total pris par le Parse/Execute/Fetch.
• Disk : Nombre total de blocs lus physiquement dans les fichiers de données
• Query : Nombre de buffers exploités en mode cohérent
• Current : Nombre de buffers exploités en mode courant
• Rows : Nombre de lignes affectés par la requête.

Quelques consignes pour bien commencer

1. Vérifier qu’il n’y a pas de grosses différences entre CPU et Elapsed
2. N’oubliez jamais de diviser vos valeurs par la valeur de Count
3. Prenez l’habitude d’additionner Current et Query pour connaître le nombre total de buffers extraits
4. Comparer le nombre de blocs parcourus aux nombre de lignes fetchées pour vérifier s’il ne manque pas un index. (Inutile si vous avez l’explain plan)
5. Ne perdez pas de temps à trop décoder, ça se parcoure vraiment très rapidement

Conclusion

TkProf est un outil très facile à utiliser mais néanmoins indispensable à tous les DBAs. Il vous permettra de comprendre et résoudre de nombreux problèmes en très peu de temps.

Une réponse à to “Décoder vos traces avec l’utilitaire TKPROF”