lunes, 6 de septiembre de 2021

Tutorial de PerfView para monitoreo de Garbage Collector en IIS .NET

Introducción

"Los problemas de una aplicación relacionados con la memoria son los mas cabrones", una frase clásica.

¿Les ha pasado que tienen una aplicación grande en .Net, Web, con muchos usuarios, se pone lenta a diario, más o menos a la misma hora, y no se explican por qué? Lo más seguro sea el Garbage Collector de .Net que hace de las suyas. Cada cierto rato actúa, solo, de forma automática, así lo dice Microsoft, pausando todos los hilos de ese proceso (si tienes un solo Worker process, es un solo proceso w3wp.exe afectado, pero si tienes toda la aplicación con ese WP, toda la aplicación se afecta).

Para esto está una herramienta fabulosa que encontré PerfView, gratuita de Microsoft.

Descarga

Ir a https://github.com/Microsoft/perfview/releases y bajar la última versión, en mi caso encontré PerfView 2.0.71. Se bajará "PerfView.exe".

Dejarla en el servidor que quieras tracear. En el disco C, en alguna carpeta. En mi caso lo dejé en: C:\apps


Ejecutarla y se verá esto.


Usar la opción Collect -> Collect que es la más simple.
(En el futuro puedes usar Collect -> Run que es más manual pero tiene más opciones avanzadas)
Sacar el check "Kernal Base".
Agregar check de "CG Collect Only"
Presionar Start Collection

En ambiente de producción lo recomendado es dejarlo 2 horas en los momentos que crees hay más carga. Al finalizar colocar Stop Collection
Carga y saldrá este mensaje, selecciona Use Microsoft Symbol Server


Y en este mensaje solo presiona OK.


Carga un momento toda la información, puede demorar unos minutos.


Al finalizar se verán ciertas páginas y carpetas. Entra a CGStats.


En el menú se verá un resumen por cada Application Pool. Puedes hacer clic en un Application Pool en particular.


Aquí se verá mucha información. El punto clave es "Mean Pause" o Pausa Media. Cuando el GEN 2 tiene muchos elementos, el mismo GC empieza a detener los hilos. En este caso se ve sin datos, pero en un ambiente real de producción pueden verse hasta 1 o 2 segundos en caso de miles de objetos en el Gen 2.

Si tienes suerte verás un tabla que indica: Pause > 200 Msec GC Events for Process xxxx: w3wp
Que son las pausas más largas del GC. Objetos de más de 85,000 bytes son creados en el LOH — Large Object Heap)


Como exportar el reporte

Si estás en un servidor y quieres que otro vea el reporte para su análisis. En la herramienta, con el botón derecho selecciona Open in Browser.



Ser abrirá el browser por defecto con la URL, ejemplo

C:\Users\pepe\AppData\Local\Temp\3\PerfView\PerfViewData.etl_1234.GCStats.html

Abre esa carpeta y copia solo el archivo .GCStats.html

C:\Users\pepe\AppData\Local\Temp\3\PerfView\


Ese archivo html lo copias en otro equipo, por ejemplo de algún técnico y lo podrá abrir fácilmente.

Resumen de Objetos eliminados en Gen 2

Ejecutar Collect -> Collect -> check en GC Only (aparte de .Net y .Net Calls)


Esto generará un reporte llamado Gen 2 Objects Deaths. Ahí se ven los objetos destruidos por el GC en el ciclo Gen 2.


Al entrar se ven los procesos, selecciona el w3wp asociado al App-Pool de la aplicación que estás escaneando.


Se pueden ver los objetos en memoria, quien los llama o quien llaman.



Ese mismo Collect, permite ver justo abajo del anterior otro reporte GC Heap Alloc Ignore Free que son los objetos que se mantienen vivos en Gen 2 incluso luego de la liberación de memoria.
Al entrar debes seleccionar el proceso, lo mismo que antes w3wp.exe pero del App-Pool que buscas.




Conclusión

Con estos simples pasos tenemos medido cuando demora cada "frenada" del Garbage Collector para Gen 0, Gen 1 y Gen 2.
En futuros post veremos como medir otros elementos de la memoria.