Solaris mon amour

Le 18 juin dernier, j'ai eu l'occasion de présenter un retour d'expérience sur la mise en place d'une solution de virtualisation (sous Solaris 10 avec container) lors du salon annuel de l'itiforums (en partenariat avec le CRIP).

Petit résumé des faits :

Différents constats monétaires ou non sont à l'origine de ce projet portant à restructurer l'infrastructure de test/dev/uat. La mise en place d'une solution de virtualisation basée sur les zones Solaris à permis de répondre aux différents besoins buisness exprimés lors de cette étude tout en améliorant les gains de productivités.. Les slides sont disponibles si vous suivez le lien.

Vous trouverez un très bon résumé de la la présentation (un peu plus technique) sur le blog d'Eric Bezille à l'adresse suivante : lien. J'ai présenté ce sujet lors d'une conférence Guses en décembre dernier. Si vous souhaiter obtenir cette présentation merci de me contacter.

Lors de la création d'un snapshot, j'obtiens un message d'erreur EBUSY. Il s'agit d'un bug connu mais j'ai décidé de l'analyser. En voiture...

# zfs snapshot zone01/root@today
cannot create snapshot 'zone01/root@today': dataset is busy

Il s'agit d'un bug déjà connu mais j'ai eu envie de l'analyser un peu. Je commence par tracer le process :

# truss  zfs snapshot zone01/root@today
...
ioctl(3, ZFS_IOC_OBJEST_STATS, 0xFFBFCB90) = 0
ioctl(3, ZFS_IOC_SNAPSHOT, 0xFFBFE478) Err#16 EBUSY
...

L'ioctl passe la main au driver ZFS. On sait juste que le code retour de correspond à EBUSY (16). Je vais donc rechercher avec dtrace les fonctions ZFS lors de la création du snapshot.

# ./zfs.d
FCT Code Retour
... 
3 <- dmu_objest_snapshot_one  16
3    <- dmu_objest_snapshot 16
3  <- zfsdev_ioctl 16

Ce petit script dtrace (script maison) permet de localiser facilement les fonctions ZFS appelées lors de l'exécution de la commande. On remarque les choses suivantes :

• zfsdev_ioctl() transmet le code retour égal 16 à ioctl().
• dmu_objest_snaphot() transmet le code retour égal 16 à zfsdev_ioctl()
• dmu_objest_snaphot_one() transmet le code retour égale 16 à dmu_objest_snaphot()

Après lecture du code source de ZFS, je remarque que la fonction dmu_objest_snaphot_one() récupère le code d'erreur de zil_suspend(). Ci-joint l'extrait de la fonction :

int zil_suspend(zilog_t *zilog)
{
...
mutex_enter(&zilog->zl_lock);

if (zh->zh_claim_txg != 0) {
mutex_exit(&zilog->zl_lock);
return (EBUSY);

} 

Lors de la création du snapshot, la zil doit être vide. Vérifions maintenant si je suis bien dans ce cas :

# zdb -ivv snapshot zone01/root
Dataset zone01/root@today [ZPL], ID 21, cr_txg 14, 370 Mo, 9556 objects

ZIL header : claim_txg 98167, seq 0

Il semble en effet que je sois dans ce cas. J'applique le workround afin de vérifier complètement ces hypothèses :

# zfs list zone01/root
NAME USED AVAIL REFER MOUNTPOINT
zone01/root@today 370 Mo 24.5 Go 370 Mo legacy

# mount | egrep -c zone01/root
0
# zfs set mountpoint=/test zone01/root
# zfs umount zone01/root
# zfs mount zone01/root
# zdb -ivv snapshot zone01/root

Dataset zone01/root@today [ZPL], ID 21, cr_txg 14, 370 Mo, 9556 objects

ZIL header : claim_txg 0, seq 0

Comme on peut le voir la zil est vide. J'essaye de créer mon snapshot :

# zfs snapshot zone01/root@today
# zfs list -t snapshot | egrep zone01/root@today
zone01/root@today 0 - 370 Mo -

J'ai pu créer mon snapshot ce qui prouve que mon analyse semble correct. J'ai réussi à démontrer le bug 6462803 corrigé dans le patch kernel 141444-01 (à l'heure actuelle, la version de ce patch n'est plus dispo voir la version 141444-09).

Suite à une mauvaise manipulation (synchronistation baie d'un système de fichiers encore monté), les process associés à ce système de fichiers ne peuvent plus être stopper (killer). A part l'arrêt/relance du serveur rien n'y fait. S'il s'agit d'un container Solaris 10, seul l'arrêt relance de la globale permet de rétablir la situation.

Situons nous un peu :

• Serveur sous Solaris 10u7 avec des containers
• Systèmes de fichiers montés sur la globale zone puis en lofs dans les containers

Soit un container avec une base Oracle où le système de fichiers a été synchronisé (synchro baie) alors qu'il n'était pas démonté au préalable ni dans le container ni dans la globale (normal la base n'a pas été totalement arrêté).

# ps -ef | egrep -i [o]rad3
  oracle 18780     1   1   Nov 25 ?  26455:53 oracleORAD3 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

 # kill -9 18780
 

# ps -ef | egrep -i [o]rad3
  oracle 18780     1   1   Nov 25 ?  26457:39 oracleORAD3 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

Ca commence mal, non ?

# pfiles 18780 
pfiles: no such process: 18780 

# pargs 18780 
pargs: cannot examine 18780: no such process 

# truss -p 18780 
truss: no such process: 18780

C'est encore pire. Voyons ce que dtrace peut nous dire (lancer la commande dtrace dans un 1er shell, et le kill dans un 2ème shell)

# dtrace -n 'fbt::sigtoproc:entry /pid == 18780/ { trace(arg2); trace(execname); }' 
dtrace: description 'fbt::sigtoproc:entry ' matched 1 probe

# kill -9 18780

Aucun signal reçu pour le pid 18780 et pourtant, le kill est bien initialisé

# signal.d 
... 
2009 Dec  2 08:12:25 ksh(pid:19084 uid:0) is sending signal 9 to oracle(pid:18780 ppid:1 uid:100) 
...

Regardons côté kernel

# ls /proc/18780 
as   contracts ctl   fd      lstatus lwp object   path psinfo  root    status     watch 
auxv cred      cwd   lpsinfo lusage  map pagedata priv rmap    sigact  usage      xmap 

# mdb -kw 
> 0t18780::pid2proc 
30155422488 
> 30155422488::kill 
mdb: command is not supported by current target

 > 30155422488::pfiles 
FD   TYPE            VNODE INFO
   0  CHR 0000030023723ec0 /zones/zone01/root/dev/pts/3
   1  CHR 0000030023723ec0 /zones/zone01/root/dev/pts/3
   2  CHR 0000030023723ec0 /zones/zone01/root/dev/pts/3 
   3  CHR 000006010b548b00 /zones/zone01/root/dev/null
   4  CHR 000006010b548b00 /zones/zone01/root/dev/null
[...] 
  11  REG 00000300a2ec6940 /zones/zone01/root/oracle/product/10.2.0/rdbms/mesg/oraus.msb
[...]
 256  REG 0000030095c4f900 /zones/zone01/root/ORAD3/data/ORAD3_01.ctl
 257  REG 00000300a4ba0740 /zones/zone01/root/ORAD3/data/system.256. 662477099
[...]
 279  REG 000003009469edc0 /zones/zone01/root/ORAD3/data/o1_mf_risk_dat_4w6ktdfx_.dbf

 > ::quit

# cd /proc/18780/fd
ksh: /proc/18780/fd:  not found

 # gcore 18780
gcore: cannot grab 18780: no such process

Comme on peut le voir, il y a toujours des fd en mémoire. Reste un à faire un arrêt/relance forcé du système. Si quelqu'un à une solution je suis preneur. Et aller pas me dire de ne pas synchroniser les données quand un système de fichiers est monté...