Introduction
Cet article ne décrit pas comment lire la trace 10053, d'autres sites ont déjà traité le sujet. En revanche la génération de cette trace révèle quelques pièges et c'est de cela dont je veux parler puisque ces sites font en général l'impasse dessus.


 
Points d'attention
Aucun.



Base de tests
N'importe quelle base Oracle.



Exemples
============================================================================================
Générer la trace : rôle DBA suffisant ou user SYS obligatoire?
============================================================================================

Pour rappel, tracer l’évènement 10053 permet de lister dans un fichier le travail effectué par le CBO pour retenir le plan d'exécution le moins coûteux.
J'utilise le user HR qui a le rôle DBA.
     [oracle@vbgeneric ~]$ sqlplus HR/HR@orcl
     
La commande pour créer la trace est la suivante; c'est la syntaxe la plus basique mais on peut spécifier le nom du fichier et plein d'autres options mais c'est hors du scope de cet article.
     SQL> ALTER SESSION SET EVENTS '10053 trace name context forever, level 1';

On exécute maintenant l'ordre sql à analyser.    
     SQL> select count(*) from employees;
       COUNT(*)
     ----------
            107

Et on n'oublie pas de désactiver la trace pour éviter de générer un fichier trop volumineux!
     SQL> ALTER SESSION SET EVENTS '10053 trace name context off';

Le répertoire de la trace générée est listé dans la vue V$DIAG_INFO, via le début de l'entrée "Default Trace File".
     SQL> SELECT name, value from V$DIAG_INFO order by name;
     NAME                   VALUE
     ------------------------------ --------------------------------------------------
     ADR Base               /u01/app/oracle
     ADR Home               /u01/app/oracle/diag/rdbms/orcl12c/orcl12c
     Active Incident Count           0
     Active Problem Count           0
     Default Trace File           /u01/app/oracle/diag/rdbms/orcl12c/orcl12c/trace/orcl12c_ora_4528.trc
     Diag Alert               /u01/app/oracle/diag/rdbms/orcl12c/orcl12c/alert
     Diag Cdump               /u01/app/oracle/diag/rdbms/orcl12c/orcl12c/cdump
     Diag Enabled               TRUE
     Diag Incident               /u01/app/oracle/diag/rdbms/orcl12c/orcl12c/incident
     Diag Trace               /u01/app/oracle/diag/rdbms/orcl12c/orcl12c/trace
     Health Monitor               /u01/app/oracle/diag/rdbms/orcl12c/orcl12c/hm
     
     11 rows selected.
     
A partir d'un autre terminal, on se déplace dans le répertoire des traces.
     [oracle@vbgeneric ~]$ cd /u01/app/oracle/diag/rdbms/orcl12c/orcl12c/trace

Attention, il faut maintenant identifier le fichier généré. Pour notre test, c'est orcl12c_ora_4528.trc, c'est celui qui correspond à la bonne heure et qui n'a pas de nom de background process dans son nom.
     [oracle@vbgeneric trace]$ ls -lrt
     ...
     -rw-r----- 1 oracle oinstall   52979 Jan 17 09:31 orcl12c_ora_4528.trm
     -rw-r----- 1 oracle oinstall  103077 Jan 17 09:31 orcl12c_ora_4528.trc
     -rw-r----- 1 oracle oinstall    3444 Jan 17 09:36 orcl12c_mmon_2826.trm
     -rw-r----- 1 oracle oinstall   19913 Jan 17 09:36 orcl12c_mmon_2826.trc
     -rw-r----- 1 oracle oinstall    3505 Jan 17 09:36 orcl12c_gen0_2778.trm
     -rw-r----- 1 oracle oinstall   20472 Jan 17 09:36 orcl12c_gen0_2778.trc

Pour le visualiser, utilisez la commande Unix VIEW, qui interdit les modifications.
     [oracle@vbgeneric trace]$ view orcl12c_ora_4528.trc
    
Si le fichier de trace brut ressemble aux lignes ci-dessous, alors connectez vous comme le user SYS ou un user avec le rôle DBA mais pas comme un user banal
     CursorDiagnosticsNodes:
       ChildNode:  ChildNumber=2 ID=40 reason=Bind mismatch(17) size=4x4 bind_position=8 original_oacflg=18 original_oacflg=18 new_oacflg=32
       ChildNode:  ChildNumber=1 ID=40 reason=Bind mismatch(17) size=4x4 bind_position=8 original_oacflg=32 original_oacflg=32 new_oacflg=18
       ChildNode:  ChildNumber=1 ID=40 reason=Bind mismatch(22) size=4x4 bind_position=31 original_oacflg=18 original_oacmxl=128 upgradeable_new_oacmxl=32
     

============================================================================================
Ne pas utiliser l'utilitaire TKPROF
============================================================================================
      
ATTENTION au piège suivant : le fichier de trace généré est un fichier dit brut, difficilement lisible, comme le montre l'extract suivant.
     [oracle@vbgeneric trace]$ view orcl12c_ora_4528.trc     
     Trace file /u01/app/oracle/diag/rdbms/orcl12c/orcl12c/trace/orcl12c_ora_4528.trc
     Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production
     Build label:    RDBMS_12.2.0.1.0_LINUX.X64_170125
     ORACLE_HOME:    /u01/app/oracle/product/12.2/db_1
     System name:    Linux
     Node name:      vbgeneric
     Release:        4.1.12-61.1.27.el7uek.x86_64
     Version:        #2 SMP Fri Feb 3 12:31:56 PST 2017
     Machine:        x86_64
     Instance name: orcl12c
     Redo thread mounted by this instance: 1
     Oracle process number: 83
     Unix process pid: 4528, image: oracle@vbgeneric
     
     
     *** 2019-01-17T09:31:18.263974-05:00 (ORCL(3))
     *** SESSION ID:(79.19319) 2019-01-17T09:31:18.263999-05:00
     *** CLIENT ID:() 2019-01-17T09:31:18.264003-05:00
     *** SERVICE NAME:(orcl) 2019-01-17T09:31:18.264007-05:00
     *** MODULE NAME:(SQL*Plus) 2019-01-17T09:31:18.264011-05:00
     *** ACTION NAME:() 2019-01-17T09:31:18.264014-05:00
     *** CLIENT DRIVER:(SQL*PLUS) 2019-01-17T09:31:18.264018-05:00
     *** CONTAINER ID:(3) 2019-01-17T09:31:18.264021-05:00
     
     Registered qb: SEL$1 0xabf57700 (PARSER)
     ---------------------
     QUERY BLOCK SIGNATURE
     ---------------------
       signature (): qb_name=SEL$1 nbfros=1 flg=0
         fro(0): flg=4 objn=79041 hint_alias="EMPLOYEES"@"SEL$1"
     
     SPM: statement not found in SMB
     SPM: capture of plan baseline is OFF
     
     **************************
     Automatic degree of parallelism (AUTODOP)
     **************************
     
     Automatic degree of parallelism is disabled: Parameter.
     kkopqSetForceParallelProperties: Hint:no
     Query: compute:yes forced:no forceDop:0
     Global Manual Dop: 1 - Rounded?: no
     
     PM: Considering predicate move-around in query block SEL$1 (#0)
     **************************
     Predicate Move-Around (PM)
     **************************
     OPTIMIZER INFORMATION
     
     ******************************************
     ----- Current SQL Statement for this session (sql_id=7c1rnh08dp922) -----
     select count(*) from employees
     *******************************************
     
     ...
     ...
     
     =====================================
     SPD: BEGIN context at statement level
     =====================================
     Stmt: ******* UNPARSED QUERY IS *******
     SELECT COUNT(*) "COUNT(*)" FROM "HR"."EMPLOYEES" "EMPLOYEES"
     Objects referenced in the statement
       EMPLOYEES[EMPLOYEES] 79041, type = 1
     Objects in the hash table
       Hash table Object 79041, type = 1, ownerid = 4429906441427842598:
          No Dynamic Sampling Directives for the object
      Return code in qosdInitDirCtx: ENBLD
      ===================================
      SPD: END context at statement level
      ===================================
      Final query after transformations:******* UNPARSED QUERY IS *******
      SELECT COUNT(*) "COUNT(*)" FROM "HR"."EMPLOYEES" "EMPLOYEES"
      kkoqbc: optimizing query block SEL$1 (#0)
      
              :
          call(in-use=1256, alloc=16344), compile(in-use=79432, alloc=83032), execution(in-use=2936, alloc=4032)
      
      kkoqbc-subheap (create addr=0x7f73abf5fb78)
      ****************
      QUERY BLOCK TEXT
      ****************
      select count(*) from employees
      ---------------------
      QUERY BLOCK SIGNATURE
      ---------------------
      signature (optimizer): qb_name=SEL$1 nbfros=1 flg=0
        fro(0): flg=0 objn=79041 hint_alias="EMPLOYEES"@"SEL$1"
      
      ...
      ...
      
      ***************************************
      BASE STATISTICAL INFORMATION
      ***********************
      Table Stats::
        Table: EMPLOYEES  Alias: EMPLOYEES
        #Rows: 107  SSZ: 0  LGR: 0  #Blks:  5  AvgRowLen:  69.00  NEB: 0  ChainCnt:  0.00  ScanRate:  0.00  SPC: 0  RFL: 0  RNF: 0  CBK: 0  CHR: 0  KQDFLG: 1
        #IMCUs: 0  IMCRowCnt: 0  IMCJournalRowCnt: 0  #IMCBlocks: 0  IMCQuotient: 0.000000
      Index Stats::
        Index: EMP_DEPARTMENT_IX  Col#: 11
        LVLS: 0  #LB: 1  #DK: 11  LB/K: 1.00  DB/K: 1.00  CLUF: 9.00  NRW: 106.00 SSZ: 0.00 LGR: 0.00 CBK: 0.00 GQL: 0.00 CHR: 0.00 KQDFLG: 8192 BSZ: 1
        KKEISFLG: 1
        Index: EMP_EMAIL_UK  Col#: 4
        LVLS: 0  #LB: 1  #DK: 107  LB/K: 1.00  DB/K: 1.00  CLUF: 19.00  NRW: 107.00 SSZ: 0.00 LGR: 0.00 CBK: 0.00 GQL: 0.00 CHR: 0.00 KQDFLG: 8192 BSZ: 1
        KKEISFLG: 1
        Index: EMP_EMP_ID_PK  Col#: 1
        LVLS: 0  #LB: 1  #DK: 107  LB/K: 1.00  DB/K: 1.00  CLUF: 2.00  NRW: 107.00 SSZ: 0.00 LGR: 0.00 CBK: 0.00 GQL: 0.00 CHR: 0.00 KQDFLG: 8192 BSZ: 1
        KKEISFLG: 1
        Index: EMP_JOB_IX  Col#: 7
        LVLS: 0  #LB: 1  #DK: 19  LB/K: 1.00  DB/K: 1.00  CLUF: 8.00  NRW: 107.00 SSZ: 0.00 LGR: 0.00 CBK: 0.00 GQL: 0.00 CHR: 0.00 KQDFLG: 8192 BSZ: 1
        KKEISFLG: 1
        Index: EMP_MANAGER_IX  Col#: 10
        LVLS: 0  #LB: 1  #DK: 18  LB/K: 1.00  DB/K: 1.00  CLUF: 8.00  NRW: 106.00 SSZ: 0.00 LGR: 0.00 CBK: 0.00 GQL: 0.00 CHR: 0.00 KQDFLG: 8192 BSZ: 1
        KKEISFLG: 1
        Index: EMP_NAME_IX  Col#: 3 2
        LVLS: 0  #LB: 1  #DK: 107  LB/K: 1.00  DB/K: 1.00  CLUF: 15.00  NRW: 107.00 SSZ: 0.00 LGR: 0.00 CBK: 0.00 GQL: 0.00 CHR: 0.00 KQDFLG: 8192 BSZ: 1
        KKEISFLG: 1
      try to generate single-table filter predicates from ORs for query block SEL$1 (#0)
      
      ...
      ...
      
Sur plusieurs sites web, il est conseillé d'utiliser l'outil TKPROF ou un autre profiler pour agréger les données des fichiers de trace bruts et rendre ceux-ci bien plus lisibles. Le problème est que si cette recommandation est exacte pour la trace 10046, elle est fausse pour la trace 10053 car le fichier généré ne contient quasiment plus aucune info...
      [oracle@vbgeneric trace]$ tkprof orcl12c_ora_4528.trc orcl12c_ora_4528.txt
      
Et voilà le contenu intégral du ficheir en sortie de TKPROF : rien de rien d'exploitable, seulement 30 lignes de résumé mais INUTILES!
      [oracle@vbgeneric trace]$ view orcl12c_ora_4528.txt
      TKPROF: Release 12.2.0.1.0 - Development on Thu Jan 17 09:38:18 2019
      
      Copyright (c) 1982, 2017, Oracle and/or its affiliates.  All rights reserved.
      
      Trace file: orcl12c_ora_4528.trc
      Sort options: default
      
      ********************************************************************************
      count    = number of times OCI procedure was executed
      cpu      = cpu time in seconds executing
      elapsed  = elapsed time in seconds executing
      disk     = number of physical reads of buffers from disk
      query    = number of buffers gotten for consistent read
      current  = number of buffers gotten in current mode (usually for update)
      rows     = number of rows processed by the fetch or execute call
      ********************************************************************************
      Trace file: orcl12c_ora_4528.trc
      Trace file compatibility: 12.2.0.0
      Sort options: default
      
             1  session in tracefile.
             0  user  SQL statements in trace file.
             0  internal SQL statements in trace file.
             0  SQL statements in trace file.
             0  unique SQL statements in trace file.
          2929  lines in trace file.
             0  elapsed seconds in trace file.
      ~
      ~
      ~



Voilà, une fois la trace générée, amusez-vous maintenant à la décrypter :-)