Dans un article précédent daté de Janvier 2009, nous vous parlions des problèmes de fuites mémoire et de l'utilisation de Debug Diagnostics pour pouvoir les investiguer : http://blogs.msdn.com/friis/archive/2009/01/13/cr-er-une-r-gle-en-mode-memory-leak-avec-debug-diagnostics.aspx

Il s'avère que dans certains cas, l'injection de la DLL Leaktrack et ce qu'elle capture n'est pas suffisant pour récupérer des informations pertinentes sur ce qui consomme la mémoire. Ceci principalement lorsque la fuite mémoire provient de nombreuses allocations différentes et qu'il est difficile de cerner une allocation à l'origine du problème. Il est aussi possible que DebugDiag ne soit pas capable de bâtir une pile d'appels suffisamment détaillée. Par exemple, la pile d'appels (callstack) suivante permet de déterminer que le "runtime C" a effectué un grand nombre d'allocations sans cependant fournir une callstack complète :

Dans ce cas, nous utilisons un autre utilitaire qui se nomme UMDH. Il va permettre l'analyse d'allocations mémoires au niveau des tas (heaps) Windows. De plus, nous allons pouvoir réaliser une analyse comparative entre deux logs afin de voir quelles allocations ont consommées le plus de mémoire entre deux intervalles de temps.

!!Attention !! : UMDH est également fortement impactant pour les performances de l'application et nécessite un IISRESET après son activation/désactivation

Pour l'utiliser :

  • Téléchargez et installez les Debugging Tools for Windows sur le serveur IIS
  • Mise en place du gflags et de l'UMDH
    • Ouvrez une invite de commande CMD
    • Naviguez vers le répertoire d'installation des "Debugging Tools for Windows" (par défaut C:\Program Files\Debugging Tools for Windows)
    • Tapez la commande suivante
      • Gflags.exe -i W3WP.exe +ust

    Cette commande a pour effet de demander au système d'enregistrer les piles d'appels provoquant des allocations sur la heap (« create user mode stack trace database »). Nous y reviendrons un peu plus loin dans cet article.

    • Exécutez un IISRESET
    • Lancez une page web accédant à l'application pour démarrer un W3WP.exe
    • Tapez les commandes suivantes
      • set _NT_SYMBOL_PATH=SRV*c:\location
        • Où "location" correspond à l'emplacement des symboles de l'application
      • tlist.exe
        • Relevez le PID du processus W3WP.exe
    • Si vous avez plusieurs W3WP, voici comment trouver celui qui correspond à votre application
      • Ouvrez une invite de commande CMD
      • Allez dans "C:\WINDOWS\System32"
      • Tapez la commande suivante
        • cscript iisapp.vbs


    • Pour générer un log UMDH tapez la commande suivante
      • umdh.exe -p:XXXX -f:W3WP.log
        • Où XXXX est le PID du processus W3WP.exe
      • L'idéal serait que vous génériez un log environ 30 à 45 minutes après le lancement de l'application puis à différents moments de la vie de l'application jusqu'à l'out of memory
      • A chaque fois que vous générez un log UMDH, générez un dump en mode hang de manière manuelle avec Debug Diag
      • N'oubliez pas de modifier le nom du log (ici W3WP.log) afin de ne pas écraser le log précédemment généré
  • Générer un dump en mode Hang avec l'utilitaire Debug Diagnostics
  • Une fois les logs générés, il faut supprimer le gflags
    • Ouvrez une invite de commande CMD
    • Naviguez vers le répertoire d'installation des "Debugging Tools for Windows" (par défaut C:\Program Files\Debugging Tools for Windows)
    • Tapez la commande suivante
      • Gflags.exe -i W3WP.exe -ust
    • Exécutez un IISRESET
  • Pour lancer l'étude comparative
    • Tapez la commande suivante :
      • UMDH W3WP.log W3WP2.log > result.txt

En éditant le fichier result.txt généré, vous pourrez visualiser les allocations entre le premier et le second log. Les plus grosses allocations seront au début du fichier :

+ 64000 ( c8000 - 64000) c800 allocs BackTrace1338
+ 6400 ( c800 - 6400) BackTrace1338 allocations
    ntdll!RtlAllocateHeapSlowly+00000041
    ntdll!RtlAllocateHeap+00000E9F
    MSVCR90!malloc+00000079 (f:\dd\vctools\crt_bld\self_x86\crt\src\malloc.c, 163)
    BuggyBitsUnmanaged!CBuggyBitsObject::FragmentMemory+00000033 c:\\buggybitsunmanaged\buggybitsunmanaged\buggybitsobject.cpp, 68)

Nous avons vu que la commande "Gflags.exe -i W3WP.exe +ust" permettait au système d'enregistrer les piles d'appels provoquant des allocations sur la heap. Cette fonctionnalité peut être utilisée directement sous le débogueur lorsqu'on connait l'adresse d'un bloc alloué sur la heap. Pour récupérer cette adresse, nous pouvons utiliser la commande "!heap –stat" qui permet de lister les heaps  et les allocations associées :

0:025> !heap –stat
_HEAP 03ba0000
Segments 00000006
Reserved bytes 01f10000
Committed bytes 01a8f000
VirtAllocBlocks 00000000
VirtAlloc bytes 00000000
_HEAP 00080000
Segments 00000001
Reserved bytes 00100000
Committed bytes 0006e000
VirtAllocBlocks 00000000
VirtAlloc bytes 00000000
…

La commande "!heap -stat –h" peut ensuite être utilisée pour obtenir des statistiques sur les allocations effectuées sur une heap spécifique. Nous nous intéresserons ici à la heap ayant réalisée le plus d'allocations :

0:025> !heap -stat -h 03ba0000
heap @ 03ba0000
group-by: TOTSIZE max-display: 20
size #blocks total ( %) (percent of total busy bytes)
10 6400 - 64000 (98.27)
800 2 - 1000 (0.98)
214 2 - 428 (0.26)
220 1 - 220 (0.13)
80 2 - 100 (0.06)
a0 1 - a0 (0.04)
…

Nous voyons ici que 98% des allocations concernent des blocs de 10 octets. Nous pouvons afficher les adresses des blocs de 10 octets en utilisant la commande "!heap –flt" :

0:025> !heap -flt s 10
...
_HEAP @ 3ba0000
03ba2998 0005 0003 [07] 03ba29a0 00010 - (busy)
03ba29c0 0005 0005 [07] 03ba29c8 00010 - (busy)
03ba29e8 0005 0005 [07] 03ba29f0 00010 - (busy)
03ba2a10 0005 0005 [07] 03ba2a18 00010 - (busy)
...

Remarque : la commande suivante peut aussi être utilisée pour afficher les blocs compris entre, par exemple, 10 et 100 octets : "!heap -flt r 0n10 0n100".

Comme le "flag" +ust  été positionné sur notre processus W3WP, nous pouvons prendre un bloc spécifique et visualiser la « callstack » à l'origine d'une allocation de 10 octets grâce à la commande !heap -p -a  <adresse du bloc> :

0:025> !heap -p -a 03ba2998
address 03ba2998 found in
_HEAP @ 3ba0000
HEAP_ENTRY Size Prev Flags UserPtr UserSize – state
03ba2998 0005 0000 [07] 03ba29a0 00010 - (busy)
Trace: 1312
7c855014 ntdll!RtlAllocateHeapSlowly+0x00000041
7c83d9aa ntdll!RtlAllocateHeap+0x00000e9f
78583a58 MSVCR90!malloc+0x00000079
     3b710c3 BuggyBitsUnmanaged!CBuggyBitsObject::FragmentMemory+0x00000033

Nous pouvons voir ici que c'est la fonction "CBuggyBitsObject::FragmentMemory" du module "BuggyBitsUnmanaged" qui est à l'origine de l'allocation de 10 octets (l'analyse de quelques autres blocs confirmant cette hypothèse).

Cette technique de déboguage présente un certain nombre d'avantages :

  • Elle est facile à mettre en œuvre (Gflags.exe -i monappli.exe +ust )
  • Elle n'est pas limitée au déboguage de IIS
  • Les callstacks de toutes les allocations effectuées sur la heap sont enregistrées
  • Elle peut être utilisée en analyse post-mortem (à condition d'avoir créé des dumps ou des logs umdh) mais aussi en déboguant un processus en temps réel

2 éléments viennent cependant pondérer notre enthousiasme :

  • Les performances de l'application seront impactées en raison de coût CPU nécessaire pour enregistrer les piles d'appels et de l'espace mémoire consommé pour les stocker
  • Cette technique ne fonctionne que pour des allocations effectuées sur la heap. Si votre application est une application .NET ou qu'elle appelle directement VirtualAlloc(), l'utilisation de Gflags.exe +ust/UMDH ne sera d'aucune utilité

Nous verrons dans un prochain article comment contourner ces difficultés…

Sylvain Lecerf & Emmanuel Boersma