jeudi 10 septembre 2015

Direct path reads et "enq KO – fast object checkpoint"


Bien que cet event commence par le mot « enq » il ne s’agit pas d’un enqueue au sens attente sur un lock. Je dis ça car récemment un développeur est venu me voir pour se plaindre de locks au niveau de sa base car il avait vu que certaines de ses requêtes étaient en attente sur cet event.

En réalité, si vous rencontrez cet event c’est que le moteur Oracle a choisi d’effectuer son full scan en utilisant du Direct Path Read et donc de bypasser le buffer cache en lisant les blocks directement depuis les datafiles. Cet event se déclenche si, parmi les blocs à lire, certains sont dirty (blocs modifiés dans le buffer cache mais pas encore envoyés par le processus DB Writer dans le disque). Pour avoir une lecture consistante un checkpoint doit être effectué pour mettre à jour les dirty blocs de la table à lire au niveau du disque. Pendant cette opération le process server en charge du direct path read attend sur l’event « enq KO – fast object checkpoint ».

Un exemple valant mieux qu’un long discours je me suis amusé à faire le petit test suivant sur ma base 12.1.0.2:
SQL>  create table T1 as select * from dba_objects;

Table created.

SQL> update T1 set created=sysdate where owner<>'SYS';

784976 rows updated.
Dans une session 1 j’ai créé une table T1 puis j’ai lancé un update de 78976 lignes pour avoir des dirty blocs dans le buffer cache.

La requête ci-dessous nous indique qu’on a 16 925 blocks qui sont dirty :
SQL> SELECT count(*)
  2  FROM v$bh b, dba_objects o
  3  WHERE b.objd = o.data_object_id and o.object_name='T1' and dirty='Y';
 

  COUNT(*)
----------
     16925
Dans une autre session je fais un count de la table en forçant le moteur SQL à choisir un Direct Path read en jouant sur le paramètre caché _serial_direct_read :
-- session 2
SQL> alter session set "_serial_direct_read"=always; 

Session altered. 

SQL> @10046.sql

SQL> set echo on feed on

SQL> ALTER SESSION SET  max_dump_file_size = UNLIMITED; 

Session altered. 

SQL> ALTER SESSION SET TRACEFILE_IDENTIFIER = 'ahmed_10046_sql_trace'; 

Session altered.

SQL> -- enables SQL trace at level 12 for the session executing it.

SQL> ALTER SESSION SET events '10046 trace name context forever, level 12'; 

Session altered.

SQL> select count(*) from T1;

  COUNT(*)
----------
     1465568  

SQL> @dis_10046.sql

SQL> set echo on feed on

SQL> -- disables SQL trace for the session executing it.

SQL> ALTER SESSION SET events '10046 trace name context off';

Session altered.

J’ai préalablement activé une trace 10046 level 12 pour capturer les wait event et voici un extrait de la trace :
WAIT #427376872: nam='enq: KO - fast object checkpoint' ela= 769931 name|mode=1263468550 2=65568 0=1 obj#=-1 tim=131292719765

WAIT #427376872: nam='Disk file operations I/O' ela= 10331 FileOperation=2 fileno=1 filetype=2 obj#=104369 tim=131292730309

WAIT #427376872: nam='direct path read' ela= 3831 file number=1 first dba=99529 block cnt=55 obj#=104369 tim=131292734495

WAIT #427376872: nam='direct path read' ela= 903 file number=1 first dba=102528 block cnt=72 obj#=104369 tim=131292737068

WAIT #427376872: nam='direct path read' ela= 2035 file number=1 first dba=102656 block cnt=128 obj#=104369 tim=131292741080

WAIT #427376872: nam='direct path read' ela= 716 file number=1 first dba=102784 block cnt=128 obj#=104369 tim=131292745168

Jetez un oeil à la première ligne: avant de voir les wait events correspondant à l’accès disque en direct path on voit que le process server a attendu 0.76 seconde sur l’event « enq: KO - fast object checkpoint » car il a fallu que le process DB writer flush les dirty blocks de la table sur disque avant qu'il puisse faire ses direct I/Os.

D’ailleurs lorsque j'interroge de nouveau la vue v$bh je constate qu’il n’existe plus de dirty blocks en mémoire pour la table T1 :
SQL> SELECT count(*)
  2  FROM v$bh b, dba_objects o
  3  WHERE b.objd = o.data_object_id and o.object_name='T1' and dirty='Y'; 

  COUNT(*)
----------
         0
Par contre on a toujours des dirty blocks appartenant à d’autres segments que ma table T1 cela prouve que le checkpoint engendré par le direct path read n’est pas globale au buffer cache mais local aux blocs de la table requête (ce qui est plutôt rassurant pour la performance des requêtes en direct path reads, je pense notamment à l'exadata):
SQL> SELECT count(*)
  2  FROM v$bh b, dba_objects o
  3  WHERE b.objd = o.data_object_id and o.object_name<>'T1' and dirty='Y'; 

  COUNT(*)
----------
         37


1 commentaire:

  1. merci c'est très intéressant. et claire et assez complet ce qui est rare.

    RépondreSupprimer