Nous sommes d’accord, les parcours complet des tables (FTS , Full Table Scan) sont à éviter le plus possible, particulièrement pour des applications au profil transactionnel. Ce point posé, il n’est pas toujours facile de faire autrement et je rencontre régulièrement des progiciels plus ou moins bien optimisés qui en génèrent de (trop) nombreux.
Avant la version 11G , la méthode de lecture utilisée dans ce cas était de remplir le cache des données de ces blocs, provoquant l’éjection massive d’autres blocs, potentiellement intéressant à conserver, diminuant ainsi grandement son efficacité. Pour remédier à cela, depuis la version 11.1, le mécanisme n’est plus le même et l’algorithme est le suivant : si la taille de la table est supérieure à 10% de la taille du cache alors la lecture ce fait en mode direct (directement du disque à la mémoire du processus serveur sans passer par le cache).
Ainsi le cache des données n’est plus perturbé par ces opérations et son efficacité est meilleure, vous devriez d’ailleurs remarquer un taux d’accès plus élevé sur votre version 11G que précédemment. L’inconvénient et le revers de la médaille c’est que du coup on peut se retrouver avec un volume global d’IO beaucoup plus important, surtout si plusieurs sessions réalisent le parcours complet des mêmes tables. Dans ce cas, les blocs des tables étant stockés dans la PGA de chaque processus serveur aucun n’est partagé et l’IO est refaite systématiquement.
J’ai pu constater chez un de nos clients un facteur fois deux sur le volume total des IO après le passage en version 11G, ceci a provoqué une saturation complète de ses disques et l’impossibilité de continuer à pouvoir utiliser correctement la plate forme Heureusement, Oracle nous fournit toujours une méthode pour pouvoir revenir au fonctionnement précédent, que ce soit sous forme de paramètre (caché ou non) ou d' »event » à positionner. Cette fois ce sera l’event 10949 qui nous rendra ce service (en attendant un paramètre pour les prochaines versions).
Voici quelques manipulations qui devraient vous permettre de vérifier ce que je viens d’énoncer et d’en voir les effets :
Hypothèses de départ et initialisation
- Ma base est une version Enterprise Edition 11.2.0.1 sur un linux EL5 fonctionnant sous Oracle Virtual Box.
- Avec un « memory_target » à 300Mo et étant seul à utiliser l’instance, la taille de mon cache de données est de l’ordre de 29Mo
- J’utilise un compte nommé « TEST » auquel j’attribue les droits DBA pour pouvoir rapidement créer une table de plus de 3Mo (10% du cache) à partir de OBJ$ et utiliser les commandes de « flush » du cache.
Initialisation de ma table T1:
[oracle@em11g ~]$ sqlplus test/test
...
Connecte a :
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
With the Partitioning option
SQL> create table T1 tablespace users as select * from sys.obj$ ;
Table creee.
SQL> select count(*) from T1 ;
COUNT(*)
----------
64760
SQL> exec DBMS_STATS.GATHER_TABLE_STATS('TEST','T1') ;
Procedure PL/SQL terminee avec succes.
SQL> select blocks*8192/1024/1024 from dba_tables where table_name='T1' ;
BLOCKS*8192/1024/1024
---------------------
6,390625
Comportement par défaut
Pour être certain de provoquer le plus d’IO possibles, je vide mon cache de données :
SQL> alter system flush buffer_cache ; Systeme modifie.
Je mets en trace ma session, puis je force un parcours complet de la table en comptant toutes les lignes.
Noter que j’utilise la nouvelle syntaxe de la version 11G pour enter et sortir du mode trace, il n’y a plus à se rappeler du numéro d’event ni passer par les sombres commandes « oradebug » :
SQL> alter system set events 'sql_trace level=12' ; Systeme modifie. SQL> select count(*) from t1 ; COUNT(*) ---------- 64760 SQL> alter system set events 'sql_trace off' ; Systeme modifie.
Pour retrouver un fichier trace sans avoir à se déplacer dans l’arborescence rien de tel que l’utilitaire adrci :
[oracle@em11g ~]$ adrci ADRCI: Release 11.2.0.1.0 - Production on Thu Jan 13 11:44:32 2011 Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved. ADR base = "/oracle/product"
Visualisation des « ORACLE_HOME » gérées depuis « ADR base » et positionnement sous celle de ma base de données :
adrci> show home ADR Homes: diag/rdbms/emrep/emrep diag/tnslsnr/em11g/listener adrci> set home diag/rdbms/emrep/emrep
Visualisation de la liste des fichiers de trace correspondant aux processus serveurs (processus foreground) en affichant d’abord le dernier généré :
adrci> show tracefile %ora% -rt 13-JAN-11 11:44:01 diag/rdbms/emrep/emrep/trace/emrep_ora_3372.trc 13-JAN-11 11:00:53 diag/rdbms/emrep/emrep/trace/emrep_ora_2944.trc 13-JAN-11 11:00:39 diag/rdbms/emrep/emrep/trace/emrep_ora_2853.trc 05-JAN-11 16:02:05 diag/rdbms/emrep/emrep/trace/emrep_ora_25132.trc 05-JAN-11 16:01:07 diag/rdbms/emrep/emrep/trace/emrep_ora_25035.trc
Affichage du fichier souhaité :
adrci> view emrep_ora_3372.trc Output the results to file: /tmp/utsout_3556_308598_4.ado
Dans le fichier trace qui s’affiche dans « vi » , je recherche l’exécution de mon curseur :
PARSING IN CURSOR #13 len=24 dep=0 uid=67 oct=3 lid=67 tim=1294915425507060 hv=2936121770 ad='2c5dc7f0' sqlid='b73dhvfrh3ada' select count(*) from t1 END OF STMT PARSE #13:c=3000,e=5584,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3724264953,tim=1294915425507059 EXEC #13:c=0,e=343,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3724264953,tim=1294915425508069 WAIT #13: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1294915425508197 WAIT #13: nam='db file sequential read' ela= 135 file#=4 block#=146 blocks=1 obj#=69164 tim=1294915425508581 WAIT #13: nam='direct path read' ela= 200 file number=4 first dba=147 block cnt=13 obj#=69164 tim=1294915425509408 WAIT #13: nam='direct path read' ela= 122 file number=4 first dba=161 block cnt=15 obj#=69164 tim=1294915425509602 WAIT #13: nam='direct path read' ela= 130 file number=4 first dba=177 block cnt=15 obj#=69164 tim=1294915425509897 ... WAIT #13: nam='direct path read' ela= 10 file number=4 first dba=1072 block cnt=2 obj#=69164 tim=1294915425535332 WAIT #13: nam='asynch descriptor resize' ela= 1 outstanding #aio=0 current aio limit=192 new aio limit=157 obj#=69164 tim=1294915425535489 FETCH #13:c=20997,e=27477,p=797,cr=799,cu=0,mis=0,r=1,dep=0,og=1,plh=3724264953,tim=1294915425535730 STAT #13 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=799 pr=797 pw=0 time=0 us)' STAT #13 id=2 cnt=64760 pid=1 pos=1 obj=69164 op='TABLE ACCESS FULL T1 (cr=799 pr=797 pw=0 time=1198553 us cost=820 size=0 card=64760)' WAIT #13: nam='SQL*Net message from client' ela= 201 driver id=1650815232 #bytes=1 p3=0 obj#=69164 tim=1294915425536333 FETCH #13:c=0,e=35,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=3724264953,tim=1294915425536467 WAIT #13: nam='SQL*Net message to client' ela= 28 driver id=1650815232 #bytes=1 p3=0 obj#=69164 tim=1294915425536603 *** 2011-01-13 11:44:01.455 WAIT #13: nam='SQL*Net message from client' ela= 15918456 driver id=1650815232 #bytes=1 p3=0 obj#=69164 tim=1294915441455104 CLOSE #13:c=0,e=279,dep=0,type=0,tim=1294915441456319
On retrouve bien une suite d’événements de type ‘direct path read’ correspondant à une lecture directe des blocs.
Modification du comportement
Modification au niveau de ma session :
[oracle@em11g ~]$ sqlplus test/test ... Connecte a : Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production With the Partitioning option SQL> alter system flush buffer_cache ; Systeme modifie. SQL> alter session set events '10949 trace name context forever, level 1'; Session modifiee. SQL> alter session set events 'sql_trace level=12' ; Session modifiee. SQL> select count(*) from T1 ; COUNT(*) ---------- 64760 SQL> alter session set events 'sql_trace off' ; Session modifiee.
Visualisation du fichier trace généré :
[oracle@em11g ~]$ adrci ADRCI: Release 11.2.0.1.0 - Production on Thu Jan 13 11:57:55 2011 Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved. ADR base = "/oracle/product" adrci> set home diag/rdbms/emrep/emrep adrci> show tracefile %ora% -rt 13-JAN-11 11:57:26 diag/rdbms/emrep/emrep/trace/emrep_ora_3533.trc 13-JAN-11 11:44:01 diag/rdbms/emrep/emrep/trace/emrep_ora_3372.trc 13-JAN-11 11:00:53 diag/rdbms/emrep/emrep/trace/emrep_ora_2944.trc 13-JAN-11 11:00:39 diag/rdbms/emrep/emrep/trace/emrep_ora_2853.trc 05-JAN-11 16:02:05 diag/rdbms/emrep/emrep/trace/emrep_ora_25132.trc 05-JAN-11 16:01:07 diag/rdbms/emrep/emrep/trace/emrep_ora_25035.trc adrci> set home diag/rdbms/emrep/emrep adrci> view emrep_ora_3533.trc Output the results to file: /tmp/utsout_3556_308598_4.ado PARSING IN CURSOR #2 len=24 dep=0 uid=67 oct=3 lid=67 tim=1294916233761725 hv=2831698764 ad='2de65080' sqlid='4dk84dqnchkuc' select count(*) from T1 END OF STMT PARSE #2:c=8999,e=14335,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3724264953,tim=1294916233760725 EXEC #2:c=1999,e=1959,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3724264953,tim=1294916233764581 WAIT #2: nam='SQL*Net message to client' ela= 26 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1294916233776299 WAIT #2: nam='Disk file operations I/O' ela= 176 FileOperation=2 fileno=4 filetype=2 obj#=69164 tim=1294916233777001 WAIT #2: nam='db file sequential read' ela= 447 file#=4 block#=146 blocks=1 obj#=69164 tim=1294916233777508 WAIT #2: nam='db file scattered read' ela= 29 file#=4 block#=147 blocks=5 obj#=69164 tim=1294916233778725 WAIT #2: nam='db file scattered read' ela= 141 file#=4 block#=152 blocks=8 obj#=69164 tim=1294916233780447 WAIT #2: nam='db file scattered read' ela= 84 file#=4 block#=161 blocks=7 obj#=69164 tim=1294916233781054 WAIT #2: nam='db file scattered read' ela= 258 file#=4 block#=168 blocks=8 obj#=69164 tim=1294916233782169 ... WAIT #2: nam='db file scattered read' ela= 222 file#=4 block#=1046 blocks=20 obj#=69164 tim=1294916233833967 WAIT #2: nam='db file scattered read' ela= 30 file#=4 block#=1066 blocks=8 obj#=69164 tim=1294916233834871 FETCH #2:c=46993,e=58887,p=797,cr=801,cu=0,mis=0,r=1,dep=0,og=1,plh=3724264953,tim=1294916233835298 STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=801 pr=797 pw=0 time=0 us)' STAT #2 id=2 cnt=64760 pid=1 pos=1 obj=69164 op='TABLE ACCESS FULL T1 (cr=801 pr=797 pw=0 time=970873 us cost=820 size=0 card=64760)' WAIT #2: nam='SQL*Net message from client' ela= 1397 driver id=1650815232 #bytes=1 p3=0 obj#=69164 tim=1294916233837055 FETCH #2:c=0,e=63,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=3724264953,tim=1294916233837371 WAIT #2: nam='SQL*Net message to client' ela= 43 driver id=1650815232 #bytes=1 p3=0 obj#=69164 tim=1294916233837589 *** 2011-01-13 11:57:26.379 WAIT #2: nam='SQL*Net message from client' ela= 12541651 driver id=1650815232 #bytes=1 p3=0 obj#=69164 tim=1294916246379320 CLOSE #2:c=0,e=741,dep=0,type=0,tim=1294916246381275
On retrouve cette fois le comportement habituel avec les events de type ‘db file scattered read’ correspondant à une lecture vers le cache des données en mode multi blocs.
Passage d’un mode de lecture à l’autre
Pour passer d’un mode à l’autre il suffit d’activer ou non l’event 10949 pour la session.
Exécution avec l’event positionné (correspondant au fonctionnement antérieur à la version 11G):
SQL> alter session set events '10949 trace name context forever, level 1'; Session modifiee. SQL> alter session set events 'sql_trace level=12' ; Session modifiee. select /* cache */ count(*) from T1;
On retrouve bien les « events » de type « db file scattered read » dans le fichier trace:
select /* cache */ count(*) from T1 END OF STMT PARSE #3:c=19996,e=38243,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3724264953,tim=1294916846783497 EXEC #3:c=1000,e=231,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3724264953,tim=1294916846784141 WAIT #3: nam='SQL*Net message to client' ela= 41 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1294916846784454 WAIT #3: nam='Disk file operations I/O' ela= 209 FileOperation=2 fileno=4 filetype=2 obj#=69164 tim=1294916846785512 WAIT #3: nam='db file sequential read' ela= 102 file#=4 block#=146 blocks=1 obj#=69164 tim=1294916846785813 WAIT #3: nam='db file scattered read' ela= 521 file#=4 block#=147 blocks=5 obj#=69164 tim=1294916846787654
En désactivant l’event :
SQL> alter system flush buffer_cache; SQL> alter session set events '10949 trace name context off' ; Session modifiee. SQL> alter session set events 'sql_trace level=12' ; select /* direct io */ count(*) from T1 ;
Le fichier trace montre de nouveau les « events » de type « direct path read » :
select /* direct io */ count(*) from T1 END OF STMT PARSE #2:c=4000,e=3936,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3724264953,tim=1294917025443939 EXEC #2:c=999,e=505,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3724264953,tim=1294917025445473 WAIT #2: nam='SQL*Net message to client' ela= 27 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1294917025445772 WAIT #2: nam='db file sequential read' ela= 204 file#=4 block#=146 blocks=1 obj#=69164 tim=1294917025446338 WAIT #2: nam='direct path read' ela= 2606 file number=4 first dba=147 block cnt=13 obj#=69164 tim=1294917025469665 WAIT #2: nam='direct path read' ela= 1878 file number=4 first dba=161 block cnt=15 obj#=69164 tim=1294917025471892 WAIT #2: nam='direct path read' ela= 362 file number=4 first dba=177 block cnt=15 obj#=69164 tim=1294917025473262
Quelques statistiques
Quelques informations sur les actions réalisées dans chacun des modes :
- En mode de lecture directe : 53 lectures en 0,6 secondes, 16 blocs lus en moyenne par lecture
- En mode lecture via le cache : 56 lectures en 1,4 secondes, 20 blocs lus en moyenne par lecture
La lecture en mode directe est plus rapide, même si sur mon environnement elle prend moins de blocs à chaque fois. Le gain se fait sur la gestion du cache : elle n’a pas à gérer les latchs et les chaînes de blocs.
Paramétrage global pour la base
Pour permettre à votre base de données de fonctionner comme avant c’est la commande ci-dessous qu’il faut passer (si vous utiliser un spfile) avant de bouncer votre instance.
alter system set event= '10949 trace name context forever, level 1' scope=spfile ;
Rappel : le choix d’utilisation d’un mode ou d’un autre est fait par le noyau pendant l’exécution du curseur (et non pas par l’optimiseur pendant la phase de « parsing »), il dépend de la taille de la table à parcourir par rapport à la taille du cache des données.
Conclusion
Petite cause grand effet, ce nouveau mécanisme peut avoir une influence importante lors de vos migrations, son utilisation par défaut est surprenante au vue des autres améliorations apportées au moteur comme « In memory parallel query » (qui permet la mise en cache des blocs lus par les process de parallélisation), le « flash cache » (qui n’est d’aucun intérêt pour les IO de type direct) ou le « cache pour les LOB » (associé au LOBs du nouveau type SecureFiles).
De plus malgré son importance on trouve à ce jour très peu d’informations sur le sujet , la documentation d’Oracle n’en parle pas, les cours de mise à niveau non plus et en dehors de références ci dessous, je n’ai pas trouvé d’autres lien sur ce sujet. Si vous en connaissez n’hésitez pas laisser vos commentaires, si vous découvrez d’autres effets de bord n’hésitez pas non plus !
Références:
- Note Metalink 793845.1 « High ‘direct path read’ waits in 11g »
- Note Metalink 1081553.1 « KEEP BUFFER POOL Does Not Work for Large Objects on 11g »
- Note Metalink813737.1 « How To Use The New 11g Events Syntax For Easier SQL Tracing Of Datapump Operations? »
12 réflexions sur “Effet caché de la database 11G – Direct Path Read”
Excellent day! This post could not be written any greater! Reading this post reminds me of my previous room mate! He always kept chatting about this. I will forward this write-up to him. Fairly certain he will have a good read. Thanks for sharing!
Ping : Effet caché de la database 11G – Augmentation du volume des traces | EASYTEAM
Ping : Effet caché de la database 11G – Augmentation du volume des traces « EASYTEAM LE BLOG
Une recherche Google sur l’event ‘Disk file operations I/O’ m’a amené sur votre article très intéressant concernant le direct path read.
Avez-vous remarqué que, dans tous vos fichiers de trace, et ce quelque soit le mode choisi par Oracle pour exécuter un FULL segment scan, la première opération faite est la suivante :
WAIT #3: nam=’db file sequential read’ ela= 102 file#=4 block#=146 blocks
Faite sur le file 4 et le block 146. Ceci correspond au ‘’segment header block de votre table T1.
En faisant un dump de ce block on observerait quelque chose du genre:
Extent Control Header
—————————————————————–
Extent Header:: spare1: 0 spare2: 0 #extents: 72 #blocks: 7296
last map 0x00000000 #maps: 0 offset: 2716
Highwater:: 0x01007e00 ext#: 71 blk#: 128 ext size: 128
#blocks in seg. hdr’s freelists: 0
#blocks below: 7198
mapblk 0x00000000 offset: 71
C’est sur la base de cette lecture qu’Oracle décide de choisir entre un db file scattered read ou un direct path read dépendant du nombre de blocks se trouvant en dessous du High Water Mark et de la taille du buffer cache entre autres.
Mais, c’est très bien de savoir qu’il existe un event (10949) éliminant la possibilité de faire un direct path read. Il supplante même le paramètre _serial_direct_read !!!
Par contre, je prendrai quelques précautions avant d’utiliser cet event (10949) particulièrement dans des machines exadata où le propre même d’un ‘Smart Scan’ a pour condition préalable une lecture via direct path.
Mohamed Houri
La nouvelle syntaxe de la version 11G pour activer et terminer le mode trace,
n’est pas décrite dans la documentation officielle Oracle 11gR2.
Seule la note Metalink N° 813737.1 décrit très brièvement cette syntaxe.
Dommage…
Voilà pourquoi je trouvais un full de « Direct path read » dans les waits events.
En effet, c’est très bizarre que la documentation Oracle ne parle pas de se fonctionnement tout a fait différent pour une opération aussi importante que les FTS. Ça ne serait pas la première fois que la doc Oracle est déficiente !
Interesting indeed.
I managed to do the same on a spare zone of a M5000 with a NAS attached to it.
I can see the changes in behavior when the event are on/off, but actually,I did not get the interest of moving back to the past. In my system (11.2.0.2, 3Gb Memory and a huge table > 20% of cache), I did not see any issue when running in DPR. On the contrary, everything went better.
I believe Oracle did that to improve performances and it really does. Keeping the possibility to come back to old technology is always a good thing. But, clearly here, I would keep working with DPR.
Still, there can be something I missed in your post and made me misunderstood the meaning of it.
@Thierry : /* Cache */ is not a hint. It’s a comment ! 😉
Cheers,
Gilles
Je pense aussi que l’idée sous jacente est l’amélioration des performances, et si cette amélioration est constatée ou s’il n’y a pas eut d’impact, autant rester dans la configuration par défaut. Par contre si le système est globalement déjà en limite au niveau des IO, c’est le contraire qui ce passera et il vaut mieux pouvoir revenir en l’état précédent rapidement. Merci pour l’échange
Bonjour,
J’avais déjà rencontré ce problème.
Je peux rajouter que si on rajoute à cela une migration vers ASM => on court-circuite le cache du système de fichiers ….
De plus, je crois qu’il y a des soucis avec le hint CACHE sur les tables.
C’est surement une évolution de plus la base de données vers des solutions EXADATA..
Encore merci.
Thierry.
Ca m’embête de dire ça parce que ton article est tout à fait pertinent : l’utilisation du terme « Direct I/O » est, il me semble, inapropriée. Il s’agit de DIRECT PATH READ (d’ailleurs tu le dis bien, les blocs ne sont pas mis en SGA) et en aucun cas d’I/O direct comme dans open(…, O_DIRECT) ou dans filesystemio_options=directio ou setall!
Dans le cas d’un DIRECT PATH READ, il est tout à fait possible que le buffer cache du système d’exploitation cache tes blocs. Evidemment, ça complique un peu plus l’histoire.
Judicieuse remarque, je me suis fourvoyé dans l’utilisation du terme c’est bien « DIRECT PATH READ » qu’il faut utiliser. Cela provient de la manière dont j’ai mémorisé l’information pour les IO à l’intérieur de la base et celle ci n’est pas la plus juste. Si tu as la possibilité de modifier le titre n’hésite pas, cela évitera des confusions dans les recherches. Quant à l’effet du cache des FS sur le comportement global, c’est une autre histoire …
C’est fait !
Les commentaires sont fermés.