Overblog Suivre ce blog
Administration Créer mon blog
27 décembre 2011 2 27 /12 /décembre /2011 19:18

 

Le 25 janvier prochain Oracle France organise l'évènement suivant : Oracle Hardware Systems - The Extreme Performance Tour. Je me permet d'évoquer cette manifestation pour plusieurs raisons :

  • C'est toujours très enrichissant de rencontrer, échanger avec d'autres clients et / ou experts
  • Une présentation du Sparc Super Cluster (à base du T4-4)
  • Un témoignage du GUSES : Solaris plate-forme optimal pour les bases de données

 

Je vous invite donc rapidement à vous inscrire à cet évènement via l'agenda du GUSES ou directement sur Oracle.

Published by gloumps - dans divers
commenter cet article
19 décembre 2011 1 19 /12 /décembre /2011 21:18

 

Le 15 décembre dernier, lors de la commission "Unix vs Linux" organisée par l'AUFO, je suis intervenu (au nom du GUSES et d'ORNESS) pour développer le sujet suivant : Pourquoi choisir Solaris ?

 

Que retenir de cette commission ? Les témoignages utilisateurs indiquent une forte progression des migrations des environnements Unix (notamment HP-UX) vers Linux (notamment RedHat mais aussi Oracle Linux). Cependant dès qu'il s'agit d'adresser des problèmatiques de performances et de haute disponibilité, Solaris reste le système d'exploitation utilisé. Les personnes définissent à tort ou à raison l'association suivante : entrée de gamme Linux, milieu de gamme Linux ou Solaris, haut de gamme Solaris.

 

Solaris (tout comme Linux dans certaines mesures) est capable d'adresser toutes ces gammes en apportant plusieurs améliorations. D'abord, Solaris est aussi bien disponible sur plate-forme x86-x64 que sur plate-forme sparc. Ensuite, la gestion optimisée de la mémoire permet d'obtenir des gains notables notamment sur l'interaction avec les bases de données. Enfin, les outils de diagnostics disponibles (dont Dtrace) permettent d'analyser facilement tous les incidents qui survient sur le système.

 

J'ai été surpris de constater que plusieurs sociétés (petites ou grandes) commencent à utiliser Oracle Linux avec le noyau modifié d'Oracle (Unbreakable Linux). Ce noyau modifié affiche des performances bien supérieurs au noyau RedHat (à voir !?). Mais ce qui m'intéresse le plus dans ce noyau est l'inclusion des sondes Dtrace (enfin un outil de diagnostic correcte). Affaire à suivre.

 

Vous pouvez consulter ma présentation si vous le souhaitez.

Published by gloumps - dans divers
commenter cet article
18 décembre 2011 7 18 /12 /décembre /2011 15:55

 

Pour tous les retardataires vous trouverez ci-joint quelques liens utiles sur la dernière version de l'os Solaris 11. Disponible depuis fin novembre cette nouvelle version est très prometteuse en corrigeant les défauts des anciennes version de Solaris (système de packages modifié, amélioration de ZFS) tout en apportant des fonctionnalités forts intéressantes (crossbow, gestion des zones). Côté performance, Solaris 11 est bien présent : amélioration dans la gestion des ISM, NUMA I/O, nouvelle probe Dtrace, etc. J'ai eu l'opportunité de rencontrer les principaux ingénieurs de l'équipe kernel lors du dernier Oracle Open World et j'ai été assez impressionné.

 

Solaris n'est pas mort, Solaris 11 est là pour le prouver. Bonne lecture et bon vissonnage :

 

Quelques informations supplémentaires sur le blog d'Eric concernant Solaris 11 et Oracle Open World.

 

Oracle-Open-World 0173

Published by gloumps - dans divers
commenter cet article
17 décembre 2011 6 17 /12 /décembre /2011 19:05

 

Petite astuce sur une problématique connue par tous les administrateurs Solaris utilisants des baies du types CLX et VNX (baie clariion chez EMC) avec le gestionnaire de multipath natif de Solaris MPxIO.

 

En simplifiant grandement, lors de la première attribution de Lun(s) sur le serveur Solaris, le mécanisme de la baie utilise un type de lun spécifique appelé LUNZ. Il s'agit ni plus ni moins d'une lun d'administration qui à l'image des Gatekeeper sous DMX ne s'intégre pas à la configuration MPxIO du serveur (je ne détaille pas ici les raisons). Une fois l'attribution des luns effectuée sur le serveur, cette LUNZ est substituée par une lun classique. Mais voilà le probléme, la configuration MPxIO n'est plus correct. En effet la Lun qui reprend la position de la LUNZ n'est pas sous contrôle MPxIO. Le plus simple est de rebooter le serveur en mode reconfiguration mais en production ce n'est pas toujours possible.

 

Voilà donc la solution de ce petit problème que j'ai plaisir à répéter un peu trop souvent à mes collégues :)

 

# luxadm probe | more
No Network Array enclosures found in /dev/es

Found Fibre Channel device(s):
  Node WWN:50060160b9a01d49  Device Type:Disk device
    Logical Path:/dev/rdsk/c2t5006016839A01D49d0s2
    Logical Path:/dev/rdsk/c2t5006016039A01D49d0s2
    Logical Path:/dev/rdsk/c3t5006016A39A01D49d0s2
    Logical Path:/dev/rdsk/c3t5006016239A01D49d0s2
  Node WWN:50060160bb205594  Device Type:Disk device
    Logical Path:/dev/rdsk/c4t60060160FB112900A477E76B20CADF11d0s2
  Node WWN:50060160bb205594  Device Type:Disk device
    Logical Path:/dev/rdsk/c4t60060160FB112900C041CD7320CADF11d0s2
  Node WWN:50060160bb205594  Device Type:Disk device
    Logical Path:/dev/rdsk/c4t60060160FB112900C241CD7320CADF11d0s2
  Node WWN:50060160bb205594  Device Type:Disk device
    Logical Path:/dev/rdsk/c4t60060160FB112900C441CD7320CADF11d0s2
  Node WWN:50060160bb205594  Device Type:Disk device
...

# luxadm disp /dev/rdsk/c2t5006016839A01D49d0s2
DEVICE PROPERTIES for disk: /dev/rdsk/c2t5006016839A01D49d0s2
  Vendor:               DGC
  Product ID:           RAID 5
  Revision:             0326
  Serial Num:           CK200070200964
  Unformatted capacity: 34818.750 MBytes
  Read Cache:           Enabled
    Minimum prefetch:   0x0
    Maximum prefetch:   0x0
  Device Type:          Disk device
  Path(s):
  /dev/rdsk/c2t5006016839A01D49d0s2
  /devices/pci@1,700000/SUNW,emlxs@0/fp@0,0/ssd@w5006016839a01d49,0:c,raw
    LUN path port WWN:          5006016839a01d49
    Host controller port WWN:   10000000c9991aae
    Path status:                O.K.
  /dev/rdsk/c2t5006016039A01D49d0s2
  /devices/pci@1,700000/SUNW,emlxs@0/fp@0,0/ssd@w5006016039a01d49,0:c,raw
    LUN path port WWN:          5006016039a01d49
    Host controller port WWN:   10000000c9991aae
    Path status:                O.K.
  /dev/rdsk/c3t5006016A39A01D49d0s2
  /devices/pci@11,700000/SUNW,emlxs@0/fp@0,0/ssd@w5006016a39a01d49,0:c,raw
    LUN path port WWN:          5006016a39a01d49
    Host controller port WWN:   10000000c99920a4
    Path status:                O.K.
  /dev/rdsk/c3t5006016239A01D49d0s2
  /devices/pci@11,700000/SUNW,emlxs@0/fp@0,0/ssd@w5006016239a01d49,0:c,raw
    LUN path port WWN:          5006016239a01d49
    Host controller port WWN:   10000000c99920a4
    Path status:                O.K.

 

La LUNZ prenant la première position, on nomme fréquemment ce dysfonctionnement de problème entre LUNZ et LUN0. 

 

# fcinfo hba-port
HBA Port WWN: 10000000c99920a4
        OS Device Name: /dev/cfg/c3
        Manufacturer: Emulex
        Model: LPe12000-S
        Firmware Version: 1.11a5 (U3D1.11A5)
        FCode/BIOS Version: Boot:5.03a4 Fcode:3.10a3
        Serial Number: 0999BT0-10380003HU
        Driver Name: emlxs
        Driver Version: 2.50o (2010.01.08.09.45)
        Type: N-port
        State: online
        Supported Speeds: 2Gb 4Gb 8Gb
        Current Speed: 4Gb
        Node WWN: 20000000c99920a4
HBA Port WWN: 10000000c9991aae
        OS Device Name: /dev/cfg/c2
        Manufacturer: Emulex
        Model: LPe12000-S
        Firmware Version: 1.11a5 (U3D1.11A5)
        FCode/BIOS Version: Boot:5.03a4 Fcode:3.10a3
        Serial Number: 0999BT0-10380003EC
        Driver Name: emlxs
        Driver Version: 2.50o (2010.01.08.09.45)
        Type: N-port
        State: online
        Supported Speeds: 2Gb 4Gb 8Gb
        Current Speed: 4Gb
        Node WWN: 20000000c9991aae

# fcinfo remote-port -p 10000000c99920a4 -s
Remote Port WWN: 5006016a39a01d49
        Active FC4 Types: SCSI
        SCSI Target: yes
        Node WWN: 50060160b9a01d49
        LUN: 0
          Vendor: DGC
          Product: RAID 5
          OS Device Name: /dev/rdsk/c3t5006016A39A01D49d0s2
        LUN: 1
          Vendor: DGC
          Product: RAID 5
          OS Device Name: /dev/rdsk/c4t600601600C421C00E0BF020FE0A5DF11d0s2
        LUN: 2
          Vendor: DGC
          Product: RAID 5
          OS Device Name: /dev/rdsk/c4t600601600C421C00B827016B604BDE11d0s2
        LUN: 3
          Vendor: DGC
          Product: RAID 5
          OS Device Name: /dev/rdsk/c4t600601600C421C00347A5E80604BDE11d0s2
... 

 

Il suffit simplement de déconfigurer tous les paths de cette Lun et de la redécouvrir. Attention tout de même qu'aucune ressource utilise l'in des paths de cette Lun, par exemple : des datas, dans la configuration d'un gestionnaire de volumes, un agent type Navisphere, etc.

 

# luxadm -e offline /dev/rdsk/c2t5006016839A01D49d0s2
devctl: I/O error

# vxdisk -e list | grep -i 5006016039A01D49d0
c2t5006016039A01D49d0s2 auto:sliced - - online c2t5006016039A01D49d0s2

# vxdisk rm c2t5006016039A01D49d0s2 

# luxadm -e offline /dev/rdsk/c2t5006016839A01D49d0s2
# luxadm -e offline /dev/rdsk/c2t5006016039A01D49d0s2
# luxadm -e offline /dev/rdsk/c3t5006016A39A01D49d0s2
# luxadm -e offline /dev/rdsk/c3t5006016239A01D49d0s2

# cfgadm -al
...
c2                             fc-fabric    connected    configured   unknown
c2::5006016039a01d49           disk         connected    configured   unusable
c2::500601603b205594           disk         connected    configured   unknown
c2::500601603b206f30           disk         connected    configured   unknown
c2::5006016230603a09           disk         connected    configured   unknown
c2::5006016839a01d49           disk         connected    configured   unusable
c2::500601683b205594           disk         connected    configured   unknown
c2::500601683b206f30           disk         connected    configured   unknown
c2::5006016a30603a09           disk         connected    configured   unknown
c3                             fc-fabric    connected    configured   unknown
c3::5006016130603a09           disk         connected    configured   unknown
c3::5006016239a01d49           disk         connected    configured   unusable
c3::500601623b205594           disk         connected    configured   unknown
c3::500601623b206f30           disk         connected    configured   unknown
c3::5006016930603a09           disk         connected    configured   unknown
c3::5006016a39a01d49           disk         connected    configured   unusable
c3::5006016a3b205594           disk         connected    configured   unknown
c3::5006016a3b206f30           disk         connected    configured   unknown
... 

# cfgadm -o unusable_FCP_dev -c unconfigure c2::5006016039a01d49
# cfgadm -o unusable_FCP_dev -c unconfigure c2::5006016839a01d49
# cfgadm -o unusable_FCP_dev -c unconfigure c3::5006016239a01d49
# cfgadm -o unusable_FCP_dev -c unconfigure c3::5006016a39a01d49

 

La déconfiguration de cette Lun par ces quatres paths est terminée. Il suffit donc de la réintégrer au serveur.

 

# cfgadm -c configure c2::5006016039a01d49
# cfgadm -c configure c2::5006016839a01d49
# cfgadm -c configure c3::5006016239a01d49
# cfgadm -c configure c3::5006016a39a01d49

 

# devfsadm -Cv
devfsadm[25244]: verbose: removing file: /dev/rdsk/c2t5006016839A01D49d0s3
devfsadm[25244]: verbose: removing file: /dev/rdsk/c3t5006016239A01D49d0s6
devfsadm[25244]: verbose: removing file: /dev/rdsk/c3t5006016A39A01D49d0s5
devfsadm[25244]: verbose: removing file: /dev/rdsk/c2t5006016039A01D49d0s2
devfsadm[25244]: verbose: removing file: /dev/rdsk/c3t5006016A39A01D49d0s2
devfsadm[25244]: verbose: removing file: /dev/rdsk/c2t5006016039A01D49d0s5
devfsadm[25244]: verbose: removing file: /dev/rdsk/c3t5006016239A01D49d0s1
... 

 

Une petite vérification simpose toujours.

 

# fcinfo remote-port -p 10000000c99920a4 -s
Remote Port WWN: 5006016a39a01d49
        Active FC4 Types: SCSI
        SCSI Target: yes
        Node WWN: 50060160b9a01d49
        LUN: 0
          Vendor: DGC
          Product: RAID 5
          OS Device Name: /dev/rdsk/c4t600601600C421C00CA9ECD0544A5DF11d0s2
        LUN: 1
          Vendor: DGC
          Product: RAID 5
          OS Device Name: /dev/rdsk/c4t600601600C421C00E0BF020FE0A5DF11d0s2
        LUN: 2
          Vendor: DGC
          Product: RAID 5
          OS Device Name: /dev/rdsk/c4t600601600C421C00B827016B604BDE11d0s2
        LUN: 3
          Vendor: DGC
          Product: RAID 5
          OS Device Name: /dev/rdsk/c4t600601600C421C00347A5E80604BDE11d0s2
...

# luxadm disp /dev/rdsk/c4t600601600C421C00CA9ECD0544A5DF11d0s2
DEVICE PROPERTIES for disk: /dev/rdsk/c4t600601600C421C00CA9ECD0544A5DF11d0s2
  Vendor:               DGC
  Product ID:           RAID 5
  Revision:             0326
  Serial Num:           CK200070200964
  Unformatted capacity: 34818.750 MBytes
  Read Cache:           Enabled
    Minimum prefetch:   0x0
    Maximum prefetch:   0x0
  Device Type:          Disk device
  Path(s):

  /dev/rdsk/c4t600601600C421C00CA9ECD0544A5DF11d0s2
  /devices/scsi_vhci/ssd@g600601600c421c00ca9ecd0544a5df11:c,raw
   Controller           /devices/pci@1,700000/SUNW,emlxs@0/fp@0,0
    Device Address              5006016039a01d49,0
    Host controller port WWN    10000000c9991aae
    Class                       secondary
    State                       ONLINE
   Controller           /devices/pci@1,700000/SUNW,emlxs@0/fp@0,0
    Device Address              5006016839a01d49,0
    Host controller port WWN    10000000c9991aae
    Class                       primary
    State                       ONLINE
   Controller           /devices/pci@11,700000/SUNW,emlxs@0/fp@0,0
    Device Address              5006016239a01d49,0
    Host controller port WWN    10000000c99920a4
    Class                       secondary
    State                       ONLINE
   Controller           /devices/pci@11,700000/SUNW,emlxs@0/fp@0,0
    Device Address              5006016a39a01d49,0
    Host controller port WWN    10000000c99920a4
    Class                       primary
    State                       ONLINE

 

Et voilà rien de plus facile. Quelques commandes dans un autre bien précis pour corriger un dysfonctionnement de MPxIO avec ce type de baie. Juste une dernière précision, si vous retirez cette Lun (en position 0), lors d'un prochain ajout il est possible que vous retombiez sur ce cas de figure. Mais bon vous avez l'astuce maintenant.

Published by gloumps - dans lvm
commenter cet article
24 octobre 2011 1 24 /10 /octobre /2011 20:05

 

Petite anlyse d'un problème survenu sur un serveur Solaris 10. Le contexte était le suivant : dysfonctionnement applicatif, impossible de se connecter au serveur bien que la couche IP semblait active.

 

Généralement je me pose pas de question dans ce genre de cas : je force une prise de dump (afin d'analyser le problème) et reboote le serveur (minimiser l'impact utilisateurs).

 

Avant de se lancer dans l'analyse du core, essayons de comprendre ce message. Le système tente de créer de nouveaux "processus" mais n'y parvient pas par manque de ressource.

 

Questions :

 

- Quelles sont les ressources nécessaires pour la création d'un nouveau processus ?

- Quelles sont les limites possibles ?

 

Un petit tour dans notre librairie : Solaris Internals et plus spécifiquement le chapitre 2 "The Solaris Process Model". La lecture est un peu longue mais très enrichissante... Bref, en vulgarisant beaucoup (désolé pour les puristes), il existe deux limites possibles : une est appliquée au Process, l'autre au Thread.

 

Le système Solaris est capable de créer un nombre déterminé de processus et de threads. Les deux limites Process et Thread sont utilisées à cet effet. La 1er ressource nécessaire à la création d'un processus (ou d'un thread) reste la mémoire (notons cela dans le coin de notre tête). 

 

Revenons un peu à notre crash... Qu'avons nous ?

 

> ::showrev
Hostname: myserver
Release: 5.10
Kernel architecture: sun4u
Application architecture: sparcv9
Kernel version: SunOS 5.10 sun4u Generic_142909-17
Platform: SUNW,SPARC-Enterprise

 

 

Vérifions le nombre de process et threads actif sur le serveur au moment du crash

 

> ::walk proc !wc -l
   14041

> ::walk thread !wc -l
   63017

 

Les limites ne sont pas atteintes, cependant le nombre de threads semble assez important. Une autre façon de savoir si le nombre de process a été atteinte est d'utiliser la variable suivante :

 

> fork_fail_pending/D
fork_fail_pending:
fork_fail_pending:       0  

 

 

Le problème semble provenir d'une allocation mémoire. Deux cas possible, le serveur ne disposait plus de mémoire virtuelle ou la table mémoire d'allocation des process (ou thread) est pleine. Le 1er cas ne semble pas possible (on aurait saturé la totalité de la mémoire virtuelle, ce qui provoque du swap... lire ce petit article). Intéressons nous au 2ème cas. L'allocation mémoire dans la table kernel concerne les threads.

 

> ::kmastat
cache                        buf    buf    buf    memory     alloc alloc
name                        size in use  total    in use   succeed  fail
------------------------- ------ ------ ------ --------- --------- -----
kmem_magazine_1               16  10662  27940    450560    244998     0
kmem_magazine_3               32   5701  32258   1040384    498170     0
kmem_magazine_7               64   5318  23495   1515520    436661     0
kmem_magazine_15             128   4544  24822   3227648    454626     0

[...]

segkp_16384                16384      0      0         0         0     0
segkp_24576                24576      0      0         0         0     0
segkp_32768                32768  63080  63080 2067005440  14589775 1429945523
segkp_40960                40960      0      0         0         0     0
[...]

------------------------- ------ ------ ------ --------- --------- -----
Total [static]                                 110821376 1078194013     0
Total [hat_memload]                            483278848 1120195850     0
[...]
Total [umem_np]                                 12320768    556204     0
Total [segkp]                                  2146041856 186166476 1429945523
Total [zfs_file_data_buf]                      3911852032   9675276     0

[...]

 

 

Nous avons plusieurs demandes d'allocation en erreur pour le cache segkp. La taille de ce cache semble trop petite par rapport au nombre important de threads que le système gére. Pour résoudre ce problème il est nécessaire d'augmenter la taille de ce cache (un peu de lecture).

 

Conseil, si vous utilisez un serveur fortement mutualisé (bcp de process et threads), n'oublie pas d'allouer un peu plus de mémoire au kernel (notamment la table segkp).

Published by gloumps - dans kernel
commenter cet article
25 août 2011 4 25 /08 /août /2011 22:06

 

Comment comprendre les problématiques IO quand on ne dispose pas de serveurs de tests ? Et même si vous en avez, la charge est elle représentative ? Pas évident... non ? Et bien si, filebench est là pour nous aider. Ce petit outil permet de simuler différents types d'activités sur le système de fichiers et ainsi nous permettre de mesurer la performance de nos systèmes de fichiers.

 

Petite démonstration de l'outil sur ma VBox en Solaris 11...

 

gloumps@zlap:-$ pkg info filebench
          Name: benchmark/filebench
       Summary: FileBench
   Description: FileBench Commands, Workloads, Scripts, and Config Files
      Category: Development/System
         State: Installed
     Publisher: solaris
       Version: 0.5.11
 Build Release: 5.11
        Branch: 0.151.0.1
Packaging Date:  4 novembre 2010 23:05:42 
          Size: 750.02 kB
          FMRI: pkg://solaris/benchmark/filebench@0.5.11,5.11-0.151.0.1:20101104T230542Z

 

gloumps@zlap:~$ ls -l /usr/benchmarks/filebench
total 7
drwxr-xr-x 4 root bin  6 2011-03-12 17:17 bin
drwxr-xr-x 2 root bin 11 2011-03-12 17:17 config
drwxr-xr-x 2 root bin  4 2011-03-12 17:17 scripts
drwxr-xr-x 2 root bin 48 2011-03-12 17:17 workloads

 

Toutes les types de workloads présentes sont paramérables. Par exemple pour simuler des lectures séquentielles sur un système de fichiers vous pouvez utilser la workload "filemicro_seqread".

 

gloumps@zlap:~$ su -
Password: 
Oracle Corporation      SunOS 5.11      snv_151a        November 2010

root@zlap:~#
root@zlap:~# cd /usr/benchmarks/filebench/bin
 

root@zlap:~# ./go_filebench 
FileBench Version 1.4.8
Bad terminal type: "xterm-256color". Will assume vt100.
filebench> help
 1353: 2.784: load <personality> (ls /usr/benchmarks/filebench/workloads for list) 

 

filebench> load filemicro_seqread
 1429: 83.956: FileMicro-SeqRead Version 2.1 personality successfully loaded
 1429: 83.956: Usage: set $dir=<dir>
 1429: 83.956:        set $cached=<bool>    defaults to false
 1429: 83.956:        set $filesize=<size>  defaults to 1073741824
 1429: 83.956:        set $iosize=<size>    defaults to 1048576
 1429: 83.956:        set $nthreads=<value> defaults to 1
 1429: 83.956:  
 1429: 83.956:        run runtime (e.g. run 60)

 

 

Pour lancer le workload il faut indiquer obligatoire le système de fichiers. Pour cette démonstration, j'ai assigné un nouveau disque à ma VBox que j'ai introduit dans un pool ZFS.

 

 

gloumps@zlap:~$ zpool list       
NAME    SIZE  ALLOC   FREE    CAP  DEDUP  HEALTH  ALTROOT
dpool  15,9G  1,00G  14,9G     6%  1.00x  ONLINE  -
rpool  19,9G  3,05G  16,8G    15%  1.00x  ONLINE  -

gloumps@zlap:~$ zfs list -r dpool
NAME    USED  AVAIL  REFER  MOUNTPOINT
dpool  1,00G  14,6G  1,00G  /data1

 

gloumps@zlap:~$ cd /data1
gloumps@zlap:~$ ls
gloumps@zlap:~$

 

Revenons à la fenêtre de filebench... Après quelques modifications, on lance le test

 

filebench> set $dir=/data1
filebench> set $filesize=2147483648
filebench> set $iosize=8192
filebench>

filebench> run
 2259: 421.762: Creating/pre-allocating files and filesets
 2259: 421.764: File largefile: mbytes=2048
 2259: 421.788: Removed any existing file largefile in 1 seconds
 2259: 421.788: making tree for filset /data1/largefile
 2259: 421.789: Creating file largefile...
 2259: 507.754: Preallocated 1 of 1 of file largefile in 86 seconds
 2259: 507.754: waiting for fileset pre-allocation to finish
 2259: 507.755: Starting 1 filereader instances
 2330: 508.022: Starting 1 filereaderthread threads
 2259: 509.022: Running...

 

Pendant que le filebench exécute cette workloads, examinons un peu ce qui se passe sur le système...

 

gloumps@zlap:/data1$ iostat -Mxnzt 3
                    extended device statistics              
    r/s    w/s   Mr/s   Mw/s wait actv wsvc_t asvc_t  %w  %b device
  585,3    0,0   73,2    0,0  6,9  3,0   11,8    5,1 100 100 c9t0d0

                    extended device statistics              
    r/s    w/s   Mr/s   Mw/s wait actv wsvc_t asvc_t  %w  %b device
    0,3    0,0    0,0    0,0  0,0  0,0    0,0    1,9   0   0 c7d0
  561,6    6,7   70,2    0,0  6,9  3,0   12,2    5,3 100 100 c9t0d0

 

                    extended device statistics              
    r/s    w/s   Mr/s   Mw/s wait actv wsvc_t asvc_t  %w  %b device
    0,0   41,3    0,0    0,4  0,1  0,1    1,5    1,3   2   3 c7d0
  551,3    1,7   68,9    0,0  6,9  3,0   12,5    5,4 100 100 c9t0d0

                    extended device statistics              
    r/s    w/s   Mr/s   Mw/s wait actv wsvc_t asvc_t  %w  %b device
    1,0    0,0    0,1    0,0  0,0  0,0    0,0    1,1   0   0 c7d0
  602,8    0,0   75,4    0,0  6,9  3,0   11,5    5,0 100 100 c9t0d0

                    extended device statistics              
    r/s    w/s   Mr/s   Mw/s wait actv wsvc_t asvc_t  %w  %b device
    0,3   46,3    0,0    0,5  0,2  0,1    5,1    2,8   6   7 c7d0
  567,0    0,0   70,9    0,0  6,9  3,0   12,2    5,3 100 100 c9t0d0

^C

 

root@zlap:/opt/DTT/FS# ./rfileio.d

Read IOPS, top 20 (count)
/dev/pts/5                                                logical          1
/lib/ld.so.1                                              logical          2
/usr/bin/hostname                                         logical          5
/data1/largefile/00000001/00000001                       physical          6
/devices/pseudo/clone@0:ptm                               logical          7
/data1/largefile/00000001/00000001                        logical      44991
/devices/pseudo/random@0:urandom                          logical      44992
/proc/2330/lwp/2/lwpusage                                 logical      89984

 

Read Bandwidth, top 20 (bytes)
/lib/ld.so.1                                              logical        212
/usr/bin/hostname                                         logical        317
/devices/pseudo/clone@0:ptm                               logical       1273
/devices/pseudo/random@0:urandom                          logical     359936
/data1/largefile/00000001/00000001                       physical     786432
/proc/2330/lwp/2/lwpusage                                 logical   45351936
/data1/largefile/00000001/00000001                        logical  368558080

 

De retour sur la fenêtre filebench, on constate le résulat du test

 

[...]

 2259: 569.066: Run took 60 seconds...
 2259: 569.069: Per-Operation Breakdown

seqread-file   9211ops/s  72.0mb/s      0.1ms/op       26us/op-cpu

 2259: 569.069: 
IO Summary: 553027 ops, 9210.8 ops/s, (9211/0 r/w) 72.0mb/s, 41us cpu/op, 0.1ms latency
 2259: 569.069: Shutting down processes

[...]

 

Sans évoquer l'aspect bench du logiciel, l'utilisation de Filebench pour comprendre le fonctionnement des IO dans Solaris 10 et Solaris 11 est tout à fait possible (lorsque je parle d'IO, j'inclue bien évidemment le système de fichiers). Vous pourrez adapter facilement vos scripts Dtrace et utiliser tous les existants selon vos besoins.

 

Les sources étant disponibles, il est possible (je pense) de le compiler et donc l'utiliser sur d'autres types d'OS (des ports existes pour FreeBSD et Linux). Par contre l'association avec Dtrace est uniquement possible sous FreeBSD (et Mac bien évidemment).

 

Published by gloumps - dans dtrace
commenter cet article
24 août 2011 3 24 /08 /août /2011 20:30

 

Solaris mon amour fait peau neuve... Nouveau thème, mise en forme des articles, mises à jour régulières, modification du feed, nouvelle url... on ne m'arrête plus... La rentrée scolaire 2011 a du bon !!!

 

Certaines pages ont été modifiées mais le contenu est toujours disponible dans les articles. Cela concerne notamment les plus visités :

 

Dernière information, l'association GUSES prépare elle aussi sa rentrée... Modification des statuts, changement d'adresse mais surtout nouveau compte pour nouvelle cotisation...

 

Les membres de l'association vont bientôt se réunir pour valider le planning des présentations mensuelles pour l'année 2011/2012. SI vous qvez des idées de thèmes merci de me les faire parvenir rapidement.

 

En attendant bonne lecture à tous, bonne rentrée et pensez à utiliser Solaris 11 Express...

Published by gloumps - dans divers
commenter cet article
22 août 2011 1 22 /08 /août /2011 21:00

 

Pour bien commencer la rentrée scolaire, Oracle University organise une formation de 3 jours les 5, 6 et 7 septembre dans les locaux de Colombes sur Solaris 11 (pas Solaris 11 Express). Si cela vous intéresse, vous pouvez contacter Oriana Nguyen-Van.

 

Ce cours à pour objectif de couvrir :

  • Install Oracle Solaris 11
  • Manage software updates in Oracle Solaris 11
  • Explain the new ZFS file system features and enhancements
  • Administer Containers in Oracle Solaris 11
  • Manage virtual networks in Oracle Solaris 11
  • Describe the new features and enhancements in Oracle Solaris 11
  • Describe new user management features and enhancements
  • Explain the new security administration features and enhancements


Vous trouverez les détails du contenu de cette formation à l'adresse suivante : TRANSITION TO ORACLE SOLARIS 11 (EARLY ADOPTER).

 

Published by gloumps - dans divers
commenter cet article
20 août 2011 6 20 /08 /août /2011 10:05

 

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.

Published by gloumps - dans kernel
commenter cet article
17 août 2011 3 17 /08 /août /2011 20:26

 

Même si je ne pratique pas depuis longtemps dans le monde Unix (un peu plus de 10 ans) c'est l'une des 1er fois où je rencontre un cas de "Hard Swapping" sous Solaris. Situons un peu le contexte : depuis plusieurs jours un serveur sous Solaris 10 se retrouvait pratiquement tous les jours sur le prompt avec aucun message d'erreur (console et système). Malgrè la mise à jour corrective de l'OBP, rien n'y faisait, le serveur continuait à se retrouver continuellement sur le prompt. En intervenant par hasard sur un autre problème, j'ai intercepté une alerte provenant de ce fameux serveur "serveur non joignable".

 

L'examen via le déport m'indiquait aucune anomalie : alimentation, aucun message à la console, aucune interruption hard. La console répondait bizarrement aux commandes mais aucune réponse du système... Hop un petit break et une génération d'un petit core au passage histoire d'analyser un peu tout ça. Mon expérience dans ce type de cas m'oriente généralement vers un problème de "Swapping".

 

Je commence par vérifier ce que contenait mes queues CPU lors du crash...


# mdb -k 0

>
> ::cpuinfo
ID ADDR        FLG NRUN BSPL PRI RNRN KRNRN SWITCH THREAD      PROC
  0 30003990000  1d    7    0  98  yes    no t-134  2a100781ca0 pageout
  1 30003994000  1d    2    6  -1   no    no t-0    2a100629ca0 (idle)
  2 30003998000  1d    1    0  -1   no    no t-0    2a100679ca0 (idle)
  3 0000183a628  1b    7    0 165  yes    no t-11   2a100047ca0 sched

 

C'est vraiment intéressant cette fonction pageout()... Cela confirme mon soupçon sur un problème provoqué par du "swapping"


> 30003990000::cpuinfo -v

 ID ADDR        FLG NRUN BSPL PRI RNRN KRNRN SWITCH THREAD      PROC
  0 30003990000  1d    7    0  98  yes    no t-134  2a100781ca0 pageout
                  |    |
       RUNNING <--+    +-->  PRI THREAD      PROC
      QUIESCED                60 30008786380 cron
        EXISTS                60 30004861c20 aws_orb
        ENABLE                60 3000e307840 nsrexecd
                              60 300052d41c0 java 
                              60 3000539d0c0 inetd
                              60 300052d8200 svc.configd
                              60 30007789ae0 dataserver

 

Regardons de plus près ce que la cpu "id 3" tentait de faire

 

> 0000183a628::cpuinfo -v
ID ADDR        FLG NRUN BSPL PRI RNRN KRNRN SWITCH THREAD      PROC
  3 0000183a628  1b    7    0 165  yes    no t-11   2a100047ca0 sched
                  |    |    |
       RUNNING <--+    |    +--> PIL THREAD
         READY         |           6 2a100047ca0
        EXISTS         |           - 2a100751ca0 pageout
        ENABLE         |
                       +-->  PRI THREAD      PROC
                              60 30008784360 cron
                              60 30007164760 adclient
                              60 30007fa1c40 dataserver
                              60 30005128400 python
                              60 3000dcc8b00 java
                              60 3000d7b9280 aws_sadmin
                              60 30003b563e0 naviagent

> 2a100751ca0::threadlist -v
            ADDR             PROC              LWP CLS PRI            WCHAN000002a100751ca0      60027254468                0   0  97                0

  PC: ktl0+0x48    THREAD: pageout_scanner()
  stack pointer for thread 2a100751ca0: 2a100750f91
  [ 000002a100750f91 ktl0+0x48() ]
    checkpage+0x78()
    pageout_scanner+0x3f4()
    thread_start+4()

 

Le "Page scanner" est bien en cours de fonctionnement (voir sched.c). Vérifions un peu les valeurs liées aux "Swapping".


> avefree/E

avefree:
avefree:          2871
> minfree/E
minfree:
minfree:          8029
> freemem/E
freemem:
freemem:          2888
> needfree/E
needfree:
needfree:        18322
> freemem_wait/D
freemem_wait:
freemem_wait:      426

 

Pour le coup le rapport avefree < minfree est avéré... confirmation de mon hypothèse... On ne dispose plus beaucoup de pages libre (freemem) et le nombre de thread en attente est de 426 (freemem_wait). Voir dans le code vm_page.c pour les explications.

 

Nous sommes donc en présence d'un cas de "Hard Swapping". Ce mode est beaucoup plus agressif que le "Soft Swapping". Une fois activé l'algorithme peut décider de unloader un module kernel non utilisé pour libérer des pages mémoires. Ce qui explique que mon serveur ne répondait plus...

 

> ::modinfo !grep ip
 58         7b600000   144040   1 ip (IP STREAMS driver 1.47)
 82         7bb61cd8      590   1 ip6 (IP6 STREAMS driver 1.9)
146                0        0   0 ipsecesp (?)
147                0        0   0 ipsecah (?)
200                0        0   0 ippctl (?)
223         7afcc000     83a8   1 fcip (SunFC FCIP v20091105-1.50)
242         7aa42000    2dd90   1 ipf (IP Filter: v4.1.9)
253         7b7f8d38     1300   1 ipc (common ipc code)

 

Pour les habitués il manque le "module ip". Petite vérification sur le serveur en fonctionnement


# modinfo | grep ip

58 7b600000 144040   3   1  ip (IP STREAMS driver 1.47)
58 7b600000 144040   -   1  ip (IP STREAMS module 1.47)
[. . .] 

 

J'ai réussi à mettre en pratique un cas rare que j'avais étudié il y a déjà quelques temps. Faut dire des problèmes de "Swapping" sur les infras actuelles sont de plus en plus rare. Pour les mordus de lecture, je vous renvois au chapitre 10 de "Solaris Internals".

Published by gloumps - dans kernel
commenter cet article