Solaris mon amour

Après avoir rencontré quelques anomalies dans la gestion de ISM sous Solaris x86 (voir l'analyse du bug), nous allons étudier la manière de le contourner. Pour rappel le bug est le suivant : non partage de la table de pages en ISM. Les workarounds mis en oeuvre ici concernent uniquement les bases de données Oracle. Cependant certains d'entre eux peuvent vous aider à adresser ce type de problème dans contextes différents. Je remercie Alain et Thierry (consultants Oracle) pour l'aide apportée sur la mise en place de ces workarounds (notamment sur la partie Oracle base de données).

Ce bug a toujours existé dans Solaris 10x86, et pourtant personne ne l'a remarqué. Et pourquoi donc !? Il faut deux éléments pour qu'il devienne visisble sur le système :

• Une taille de ISM importante (supérieur à 80 Go environ)
• Une multitude d'attachements / détachements à cette ISM

Sans ces deux conditions, le dysfonctionnement n'est pas impactant pour le système (la consommation du serveur n'est pas affectée par des Spin locks provenant du bug). Il y a deux manières de controurner ce problème :

• La taille de l'ISM
• Diminuer le nombre d'attachements / détachements

Diminuer la taille de l'ISM va un peu à l'encontre de l'histoire !! Possédant des serveurs de plus en plus capacitifs (512 Go de RAM voir plus maintenant), et ne pas en profiter pleinement, c'est un peu ridicule. Une approche plus constructive serait de découper le segment ISM par plusieurs segments de plus petites tailles. Solaris a bien des qualités mais ne posséde malheuresement pas celle de découper un segment ISM (à l'inverse de Linux : voir shmmax et shmall).

Reste que le monde informatique est bien fait !! L'architecture des serveurs x86 (je parle des serveurs produits actuellement) fonctionne en utilisant le schéma mémoire NUMA. Pour simplifier, le temps d'accès à la mémoire dépend de sa localisation par rapport aux processeurs. Solaris utilise pleinement ces fonctionnalités à travers les locality groups (lgrp). La mémoire est implicitement découpée par le système Solaris. La base de données Oracle est capable de découper son segment de mémoire partagée sur les différents locality groups disponibles sur le serveurs. Quand je vous disais que le monde informatique était bien fait !! Il s'agit d'activer une option lors du démarrage de la base de données.

L'autre approche est de limiter le nombre d'attachements / détachements. Même si diminuer le nombre d'utilisateurs reste une solution, je ne vous la conseille pas !! Par contre utiliser les fonctionnalités d'Oracle base de données nous permet de répondre à ce besoin. Il s'agit d'utiliser soit la fonctionnalité de Shared Server soit la fonctionnalité de Database Resident Connection Pooling. La dernière fonctionnalité étant disponible en version 11g. 

Le protocol de tests est assez simple : lancement de 50 connexions simultanées (via sqlplus). Chaque sqlplus provoque une connexion / déconnexion à la base toutes les 2 secondes. L'activité du système est surveillée par la commande vmstat, les locks (et leurs temps) sont tracés avec un petit script Dtrace. Tous les tests ont été réalisés avec une SGA de 200 Go et 25 Go de shared pool.

Résultats obtenus :      

Cas 1 : Reproduction du problème

Cas 2 : Utilisation de NUMA

Remarques :

• 4 lgrps disponibles sur le serveur
• 3 segments ISM de 50 Go + 1 segment ISM de 75 Go (50 Go de SGA et 25 Go PGA)
• 1 segment ISM de quelques Mo pour la gestion des 4 autres segments

Cas 3 : Utilisation de Data Resident Connection Pooling dans Oracle

Remarques :

• Lors du test, un hang non expliqué est apparu
• Les limitations fonctionnelles de connexions au même schéma sont à valider par l'applicatif

Cas 4 : Utilisation de Shared Server      

Remarques :

• Quelques ajustements à faire : nombre de serveurs, large pool, taille de la UGA
• Fonctionnalités présentes depuis plusieurs versions d'Oracle base de données

Les 3 workarounds présentés ici permettent d'augementer la taille de la SGA de votre base Oracle sur Solaris x86 sans saturer votre système. Les fonctionnalités présentes dans Oracle (Data Resident Connection Pooling et Shared Servers) permettent même de masquer complétement le bug ISM : les attachements / détachements sont supprimés. Cependant leur mise en oeuvre nécessite un paramétrage à faire valider par les utilisateurs. L'option NUMA est plus simple à mettre en oeuvre mais dépend surtout de votre architecture matérielle : nombre de lgrps disponibles sur votre système (j'écris en ce moment un petit artcile à ce sujet).

Ci-joint quelques références sur ce sujet : 

• Chapitre 16 "Support for NUMA and CMT Hardware" dans Solaris internals
• Application and Networking Architecture in Oracle DB 
• Configuring Oracle Database for Shared Server
• Tuning Shared Server
• About Databe Resident Connection Pooling
• Configuring Database Resident Connection Pooling

Petit sujet qui m'a tenu en haleine. Pour faciliter sa compréhension je le découpe en deux parties : une première partie sur un problème d'initialisation d'un segment de type ISM et une seconde partie sur un dysfonctionnement de l'ISM. Les deux sous Solaris x86 uniquement.

Mais de quoi parlons nous ? Quelques explications sont nécessaires. Pour partager des données et synchroniser des évènements entre processus, le système Solaris utilise un framework nommé IPC (InterProcess Communication). Ce framework contient plusieurs objets IPC dont le standard POSIX IPC : POSIX semaphores, POSIX shared memory et POSIX message queues. 

J'évoque ici l'objet IPC : POSIX shared memory. Cet objet est notamment utilisé dans les bases de données (en tout cas Oracle et Sybase). Pour les "spécialistes" de ces produits, il s'agit ni plus ni moins de la fameuse SGA. Pour nous, les "spécialistes" du système nous appelons cela un segment SHM (Segment sHared Memory). Lors du démarrage d'une instance Sybase ou Oracle, un segment SHM est initialisé avec une taille spécifique. Si cette taille n'est pas disponible, l'instance ne s'active pas. 

Par défaut, la création d'un segment SHM : 

• n'est pas locké en mémoire (donc swappable).
• utilise des tailles de pages par défaut (soit 4K sous Solaris x86 et 8K sous Solaris sparc).
• n'utilise pas de table de translation d'addresse commune entre tous les processus utilisants ce segment.

Les ingénieurs Solaris ont donc optimisé la gestion de ce segment SHM : ISM (Intimate Shared Memory).

L'ISM corrige les problèmatique d'un segment SHM classique : 

• taille de pages optimisée.
• création d'une table de partage d'adresse pour optimiser les translation.
• segment automatiquement locké en mémoire.

L'utilisation de ce type de segment est devenu le standard pour les bases de données : la SGA fonctionne donc avec un segment ISM sous Solaris.

D'où mon problème : ma base de données Oracle 11g r2 sous Solaris 10x86 (update 9) n'utilise pas un segment ISM mais un simple segment SHM !!! Analysons un peu tout cela. 

En espectant l'espace d'adresse du process Oracle (ici pmon), j'ai étais surpris de constater que la SGA utilisait un segment SHM classique : 

# pmap -x 10735
10735:  ora_pmon_XXXX22
         Address   Kbytes       RSS    Anon   Locked Mode   Mapped File
0000000000400000   222240     91144       -       - r-x--   oracle
000000000DD17000     1180       676     208       - rw---   oracle
000000000DE3E000      136        32      32       - rw---   oracle
000000000DE60000     1828      1644    1632       - rw---   [ heap ]
0000000060000000        4         4       -       - r--s-   [ shmid=0x4000003c ]
0000000060001000  2097156   2028692       -       - rwxs-   [ shmid=0x4000003c ]
FFFFFD7FFCAA0000       64         8       8       - rwx--   [ anon ]
FFFFFD7FFCABE000       72         8       8       - rw---   [ anon ]
FFFFFD7FFCAD0000       64        12      12       - rw---   [ anon ]
[...] 

L'initialisation d'un segment type ISM provient du demandeur et non du système. J'ai donc décidé de vérifier les logs de démarrage de l'instance Oracle (fichier alert.log). Je suis tombé sur ce message fort intéressant : 

Mon Nov 21 16:38:40 2011
Starting ORACLE instance (normal)
WARNING: Not enough physical memory for SHM_SHARE_MMU segment of size 0x0000000080002000 [flag=0x4000] 

Lors de l'activation de l'instance, Oracle a tenté d'activer un segment type ISM sans y être parvenu. Le message indiquant l'erreur suivante : Not enough physical memory for SHM_SHARE_MMU segment. Tiens donc pas assez de mémoire ? Alors que la SGA demandée correspondait à seulement 2 Go ? La vérité était ailleurs... 

Pour mieux reproduire le problème, j'ai décidé d'écrire un petit programme C me permettant de créer un segment type ISM. Contrairement à ce que je pensais, ce n'est pas lors de la création du segment que le type ISM est spécifié mais lors d'un attachement. 

La création et l'attachement correspondent aux appels suivants :

shmget(2, size, 0660 | IPC_CREAT | IPC_EXCL)

shmat(shmid, (void *)0, SHM_SHARE_MMU) 

Le flag SHM_SHARE_MMU de la fonction shmat permet l'utilisation de l'ISM. L'exécution de mon petit programme C m'a permis d'activer sans problème un segment ISM de 10 Go. 

# ./ishm
shmid: 1526726689

# ipcs -m
IPC status from <running system> as of Tue Jan 10 11:26:10 CET 2012
T         ID      KEY        MODE        OWNER    GROUP
Shared Memory:
m 1526726689   0x2        --rw-rw----     root     root

[...]

# pmap -x 24680
24680:  ./ishm
         Address   Kbytes       RSS  Anon    Locked Mode   Mapped File
0000000000400000        4         4     -         - r-x--  ishm
0000000000410000        8         8     8         - rw---  ishm
FFFFFD7F80000000  1048576   1048576     -   1048576 rwxsR  [ ism shmid=0x5b000021 ]
FFFFFD7FFF210000       64        64    64         - rwx--  [ anon ]
FFFFFD7FFF230000       24        12    12         - rwx--  [ anon ]
FFFFFD7FFF240000     1276       712     -         - r-x--  libc.so.1
FFFFFD7FFF380000        4         4     4         - rwx--  [ anon ]
FFFFFD7FFF38F000       36        36    36         - rw---  libc.so.1
FFFFFD7FFF398000       16         4     4         - rw---  libc.so.1
FFFFFD7FFF3AE000      244       244     -         - r-x--  ld.so.1
FFFFFD7FFF3F0000        4         4     4         - rwx--  [ anon ]
FFFFFD7FFF3FB000        8         8     8         - rwx--  ld.so.1
FFFFFD7FFF3FD000        8         8     8         - rwx--  ld.so.1
FFFFFD7FFFDFE000        8         8     8         - rw---  [ stack ]
---------------- -------- --------- ----- ---------
        total Kb  1050280   1049692   156   1048576 

Mais où était mon problème ? Oracle doit en faire un peu plus ? J'ai donc tracé les appels systèmes lors du démarrage d'une instance. 

[...]
6362:   shmget(672617948, 1073754112, 0660|IPC_CREAT|IPC_EXCL) = 83886086
6362:   shmget(672617949, 0, 0)                         Err#2 ENOENT
6362:   shmget(672617950, 0, 0)                         Err#2 ENOENT
6362:   shmget(672617951, 0, 0)                         Err#2 ENOENT
6362:   shmat(83886086, 0x60000000, 040000)             Err#22 EINVAL
6362:   shmat(83886086, 0x60000000, 0)                  = 0x60000000
[...]

Oracle s'attache en spécifiant une adresse mémoire 0x60000000. J'ai donc modifié mon petit programme C en spécifiant la même adresse d'attachement et j'ai obtenu à ma grande surprise l'erreur suivante : 

# ./ishm
shmat: Invalid argument

J'ai obtenu la même erreur que le démarrage de la base Oracle. Bingo ! Lors de l'appel à la fonction shmat (si on spécifie l'adresse 0x60000000) l'attachement ne s'effectue pas. Mais pourquoi ? Dépassant un peu mes compétances j'ai ouvert un call au support Oracle. 

Réponse du support Oracle : la valeur 0x60000000 n'est pas divisible (valeur entière) par l'ensemble des tailles de pages disponibles sur le système Solaris 10x86. Il faut donc désactiver la taille de pages posant problème (option désactivée dans le kernel patch suivant 144489-17). Le workaround n'est pas applicable en production (boot en mode kernel debugging + modification avant chargement du kernel de la valeur largepagesupport). 

En vérifiant mes tailles de pages disponibles sur mon serveur DL380 G7, j'obtiens le résultat suivant : 

# pagesize -a
4096
2097152
1073741824 

Tiens donc, on peut utiliser des tailles de pages de 1Go !? Et bizarrement c'est avec cette taille de pages où la valeur 0x60000000 n'est pas divisible en une valeur entière. L'application du patch supprime la possibilité d'utiliser cette taille de pages. 

Voilà donc la fin de la 1er partie sur ISM et Solaris 10x86. La 2ème partie fait référence à un bug dans la gestion de l'ISM uniquement pour Solaris 10x86 (et Solaris 11x86). Bug que j'ai eu le privilège de découvrir en exclusivité... 

Ci-joint quelques références sur ce sujet : 

• Chapitre 4 "Interprocess Communication" dans Solaris internals 
• Shared memory uncovered par Jim Mauro
• Operating systems are lazy allocating memory par Tanel Poder
• Optimizing Applications with large working sets

Petit sujet qui m'a tenu en haleine un petit moment... Pour situer un peu le contexte, nous obtenions des hangs sur plusieurs bases de données Oracle (hang pouvant dépasser l'heure) situés sur plusieurs serveurs et plusieurs baies SAN. La seule alerte obtenue était ce message d'erreur "WARNING: aiowait timed out" dans l'alert.log des bases. Pour le support Oracle bases de données, ce type de message provient d'un problème sur la couche IO du serveur.

Analysons déjà ce que veut dire cette alerte : Oracle effectue une écriture de type KAIO sur un fichier. Le temps de réalisation de cette écriture ne doit pas dépasser 10 minutes sinon Oracle l'indique via ce message d'erreur. Ce qui veut dire qu'entre la demande et la réalisation de cette écriture il y a eu un délai supérieur à 10 minutes... 10 minutes pour réaliser une IO ??? De quoi devenir fou...

Ne disposant d'aucune alerte système, l'investigation commençait difficilement. La première chose à faire dans ce type de cas s'est d'obtenir un maximum de traces pour pouvoir investiguer correctement le problème. Nous avons donc mis en place un script détectant l'anomalie dans l'alert.log des bases. Ce script exécute à la fois un Livecore et une prise de traces via l'outil Guds (je me suis inspiré de l'article suivant).

Je vous passe le fait que le script n'a pas fonctionné tout le temps... Les prises de traces exploitables n'ont absolument rien montré qui pouvaient expliquer notre problème (rien dans les traces iostat, la charge des systèmes était correcte, etc..). Je me suis concentré uniquement sur les IO. Pour ne pas m'éparpiller entre les différents serveurs, baies, bases, j'ai décidé d'analyser le problème sur une seule base (un serveur et une baie mutualisés).

J'ai écrit un petit script Dtrace me permettant de calculer le temps passé pour chaque appel KAIO. Ceci m'a permis de vérifier, cette latence de 10 minutes que la base de données Oracle indiquée.

# cat ./aiowait.d
#!/usr/sbin/dtrace -qs

 fbt:kaio:aiowait:entry
/execname == "oracle"/
{
        self->ts = timestamp;
}

fbt:kaio:aiowait:return
/self->ts && (timestamp - self->ts)/1000000 > 60/
{
        self->duration = (timestamp - self->ts)/1000000;
        printf("%Y %20s %8d %12d %12d\n", walltimestamp, execname, pid, tid, self->duration);
        self->duration = 0;
}

# ./aiowait.d
[...]
2011 Jul 19 23:45:40       oracle    14583       1        67
2011 Jul 19 23:45:39       oracle    14583       1        89
2011 Jul 19 23:45:40       oracle    14583       1        61
2011 Jul 19 23:45:40       oracle      714       1       127
[...]
2011 Jul 19 23:58:39       oracle    14583       1    600100
2011 Jul 19 23:58:39       oracle    14583       1      3014
2011 Jul 19 23:58:38       oracle    14583       1       908
2011 Jul 19 23:58:39       oracle    14583       1     36730 
[...] 

Si vous interprétez correctement cet output, on remarque des temps de latence entre l'entrée et la sortie de la fonction aiowait supérieurs à 60 millisecondes pour la plupart des KAIO mais surtout une latence supérieur à 10 minutes. Incroyable voilà ce que je me suis dis... Une latence de 10 minutes pour une écriture... Oracle dit vrai !!!

Ce qu'il faut bien comprendre c'est qu'une demande de lecture et / ou écriture se décompose en plusieurs couches dans le système. Une couche logique (opération vfs, opération vnode, file system, cache) et ensuite une couche physique. Suite à ma première constatation j'ai d'abord vérifié la couche physique (c'est la plus facile à analyser). Pour ce faire, j'ai utilisé le petit script Dtrace suivant.

# cat ./fsiolantency.d
#!/usr/sbin/dtrace -Cs

#pragma D option quiet
#pragma D option defaultargs

dtrace:::BEGIN
{
#if defined(ZONENAME)
        uzone = ZONENAME;
#else
        uzone = "";
#endif

#if defined(EXECNAME)
        uexec = EXECNAME;
#else
        uexec = "";
#endif

#define PROBE_SWITCH \
        ((uzone == "" || uzone == zonename) && \
                (uexec == "" || uexec == execname))
}

io:::start
/PROBE_SWITCH/
{
        start[arg0] = timestamp;
}

io:::done
/start[arg0]/
{
        @time["disk I/O latency (ns)", args[2]->fi_mount, args[0]->b_flags & B_READ ? "R" : "W"] = quantize(timestamp - start[arg0]);
        start[arg0] = 0;
}

# ./fsiolantency.d -D ZONENAME='"zone1'" -D EXECNAME='"oracle"'
^C 

disk I/O latency (ns)     /zones/zone01/root/ZONE01/oradata02         W                                              
           value  ------------- Distribution ------------- count
         1048576 |                                         0
         2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@           1112
         4194304 |@@@@@@@@@@                               104
         8388608 |                                         0

 disk I/O latency (ns)    /zones/zone01/root/ZONE01/oradata03         R                                             
           value  ------------- Distribution ------------- count
          131072 |                                         0
          262144 |@@@@@@@@@@@@@@@@@@@                      2408
          524288 |@@                                       231
         1048576 |@@                                       230
         2097152 |                                         0
         4194304 |@@@@@                                    1023
         8388608 |@@@@@@@@@@@@                             1940
        16777216 |                                         0

 disk I/O latency (ns)    /zones/zone01/root/ZONE01/oraredo01         W                                             
           value  ------------- Distribution ------------- count
         1048576 |                                         0
         2097152 |@@@@@@@@@@@@@@@@@@@@@@@                  2013
         4194304 |@@@@@@@@@@@@@@@@@                        1870
         8388608 |                                         0

 disk I/O latency (ns)    /zones/zone01/root/ZONE01/oradata01         R                                              
           value  ------------- Distribution ------------- count
          131072 |                                         0
          262144 |@@@@@@@                                  498
          524288 |@@                                       156
         1048576 |                                         0
         2097152 |                                         0
         4194304 |@@@@@@@@@@@@                             750
         8388608 |@@@@@@@@@@@@@@@@@@                       1134
        16777216 |@@                                       134
        33554432 |                                         0

 disk I/O latency (ns)    <none>                                      R                                              
           value  ------------- Distribution ------------- count
          131072 |                                         0
          262144 |@@@@@@@@@@@@@@@                          158
          524288 |@@                                       27
         1048576 |                                         0
         2097152 |                                         0
         4194304 |@@@@@@@@@@@@@                            139
         8388608 |@@@@@@@@@@@                              114
        16777216 |                                         0

 disk I/O latency (ns)    /zones/zone01/root/ZONE01/oradata01         W                                              
          value  ------------- Distribution ------------- count
          524288 |                                         0
         1048576 |@@@@@@@                                  44
         2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@           202
         4194304 |@@@                                      519
         8388608 |                                         153
        16777216 |                                         0

 disk I/O latency (ns)    /zones/zone01/root/ZONE01/oradata03         W                                             
           value  ------------- Distribution ------------- count
          524288 |                                         0
         1048576 |@@@@@@@                                  968
         2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@           2309
         4194304 |@@@                                      528
         8388608 |                                         42
        16777216 |                                         0

 disk I/O latency (ns)    <none>                                      W                                             
           value  ------------- Distribution ------------- count
          524288 |                                         0
         1048576 |@@@@@@@@@@@                              913
         2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@             13482
         4194304 |@                                        418
         8388608 |                                         25
        16777216 |                                         0

Les résultats obtenus étaient correctes. Les IO physiques (lecture et écriture) se déroulaient dans des temps très convenables. Le problème ne se situait donc pas sur les baies. Donc dans le système... Mais où ? Je me suis donc plonger dans la lecture de "Solaris Internals" et "Configuring and Tuning Databases on the Solaris Platform" pour compendre ce qui se passait entre l'écriture demandée par Oracle (usermode) et l'écriture sur le device (IO physique). J'imaginais qu'il y avait un lock mais lequel ?

Une chose s'est révélée intéressante : les "Reader/Writer" locks (voir chapitre 17.6 dans "Solaris Internals"). Un seul thread à la fois peut accéder en écriture à un fichier. Voilà quelque chose de fort intéressant... J'ai donc écrit un petit script Dtrace en utilisant la probe lockstat (spécifiquement rw-block) pour obtenir les temps d'attente pour ce type de lock.

# cat rwlock.d
#!/usr/sbin/dtrace -Cs

#pragma D option quiet

lockstat::rw_enter:rw-block
/execname == "oracle" && arg1 > 1000000000 && zonename == "zone01"/
{
          printf("%Y %20s %8d %12d %12d %12d",walltimestamp,execname,pid,tid,arg1,arg2);
}

# ./rwlock.d
2011 Jul 21 00:01:13     oracle    21289       223   4238043920        0
2011 Jul 21 00:01:13     oracle    21289        88   4628837600        0
2011 Jul 21 00:01:13     oracle    21289       212   4351952245        0
2011 Jul 21 00:01:13     oracle    21289       238   4929624480        0
[...]
2011 Jul 21 00:01:18     oracle    21289       208   8635095680        0
[...]
2011 Jul 21 00:01:20     oracle    21289       195  12103783200        0
2011 Jul 21 00:01:20     oracle    21289       235  11806798240        0
2011 Jul 21 00:01:20     oracle    21289        43  11860924640        0
^C
2011 Jul 21 00:01:21     oracle    21289       226  13598520640        0
2011 Jul 21 00:01:21     oracle    21289        26  13602492640        0
2011 Jul 21 00:01:21     oracle    21289        46  13493121680        0
2011 Jul 21 00:01:21     oracle    21289        56  13310176960        0
2011 Jul 21 00:01:21     oracle    21289        64  13236565680        0
2011 Jul 21 00:01:21     oracle    21289        73  13197836080        0
2011 Jul 21 00:01:21     oracle    21289        75  13198641840        0
2011 Jul 21 00:01:21     oracle    21289        76  13199566320        0
2011 Jul 21 00:01:21     oracle    21289        71  12498137520        0

J'obtenais des "Writer" Locks supérieurs à 12 secondes !!! J'ai donc décicidé de faire tourner ces deux petits scripts (rwlock.d et aiowait.d) en même temps afin de voir si mes soupçons étaient corrects. Et bingo... Lors d'un message "WARNING: aiowait timed out", la somme des temps pour les "Writer Locks" était supérieur à 10 minutes (certains "Writer Lock" dépassaient 1 minute).

Mon gros soucis avec cette analyse était la suivante. J'avais la conviction que le soucis se situer sur ce type de lock mais impossible de l'affirmer. En effet, l'analyse s'avère exact si et seulement si il s'agit du même fichier qui est accéder. J'ai donc demandé au support Oracle système de me fournir un script Dtrace pouvant m'indiquer à la fois le type de lock "Reader/Writer", le temps de lock mais surtout le nom du fichier sur lequel le lock attendait. Le script fournit par le support - un grand Merci à Alexandre et Alain - nous a permis de mettre en relation l'alerte Oracle "WARNING: aiowait timed out" avec le nom du fichier (le plus souvent les fichiers undo et les tempfiles). 

Résumons la situation : des temps IO vu d'Oracle dépassant les 10 minutes, des IO physiques inférieurs à 30 millisecondes, des "Writers Locks" dépensant la minutes... ???!!! Lors d'une demande d'écriture sur un fichier, le système vérifie si le fichier est déjà accédé, si celui-ci est accédé alors il place cette demande dans une queue de type turnstile. Une fois la ressource disponible (ici le fichier) l'écriture physique peut s'effectuer. Lors d'une forte activité d'écriture sur un fichier, toutes les demandes s'empilent dans la queue. La dernière requête de la queue prendra donc un certains à se réaliser (c'est une FIFO). Il s'agit du mode fonctionnement POSIX d'un système de fichiers (UFS, VxFS, TMPFS).

Comment contourner ce problème ? Plusieurs solutions possibles : l'une d'elles est d'augmenter le nombre de fichiers (pour nous il s'agissait des fichiers undo et tempfiles). En augmentant le nombre de fichiers on augmente le nombre de queues (donc moins de locks par queue). L'autre solution consite à passer les systèmes de fichiers en accès directio. En effet le mode directio supprime les "Reader/Writer" locks : la couche applicative se débrouille pour gérer les accès concurents aux fichiers. Les bases de données Oracle savent très bien le faire (quelques infos dans cette article). Mais voilà, le passage en directio supprime certes ces locks mais supprime aussi l'effect du "cache filesystem". Toutes les lectures s'effectueront directement sur les disques physiques (pour pallier à ce problème il faut augmenter impérativement les SGA de vos bases de données).

Un sacré problème réglé...

P.S. : c'est pas évident d'être clair, n'hésitez pas à me demander des informations supplémentaires sur ces aspects. Je tiens à le souligner encore mais sans un outil comme Dtrace (n'oublions pas mdb) ce type d'analyse est pratiquement impossible. Un grand merci au support Oracle (base de données et système) pour toute l'aide apporté à la résolution de ce problème.