Identificar qué es «lento» con PerfView y dotnet-trace — introducción práctica a la investigación de rendimiento en .NET

El artículo anterior, Introducción al registro de eventos de Windows y ETW, explicó qué es ETW y cómo definir eventos propios con EventSource, dejando el análisis con PerfView fuera de alcance. Este artículo continúa desde allí: muestra cómo identificar la función causante cuando una aplicación de negocio va lenta, mantiene la CPU al máximo o se queda congelada ocasionalmente mediante PerfView y dotnet-trace.

El objetivo aquí es CPU y tiempo de respuesta. Para separar memoria que sigue creciendo, consulte Distinguir espera de GC y fuga de memoria en .NET; para bloqueos por caída, Leer volcados de bloqueo con WinDbg + SOS.

1. La conclusión primero

• Hay dos clases de «lento»: lento porque la CPU está completamente ocupada (CPU bound) y lento aunque la CPU esté libre porque algo espera o se bloquea. El primero requiere muestreo de CPU; el segundo, recogida ThreadTime (cambios de contexto). La recogida de CPU predeterminada no muestra la causa del segundo.¹
• En caso de duda, empiece por dotnet-trace. Es una herramienta multiplataforma basada en EventPipe y, si ejecuta el proceso objetivo con el mismo usuario, permite recoger datos sin privilegios de administrador.² El .nettrace resultante puede abrirse en PerfView o Visual Studio.³
• Use PerfView cuando necesite máquina completa, código nativo o tiempo bloqueado. Al estar basado en ETW puede tratar eventos del kernel y pilas nativas, pero iniciar la sesión ETW exige privilegios de administrador.³
• El muestreo de CPU toma de forma predeterminada una muestra cada milisegundo por procesador. Lea una muestra como aproximadamente 1 ms de tiempo de CPU y juzgue después de reunir al menos 1.000, preferiblemente unas 5.000. Con pocas muestras, las funciones superiores pueden ser casualidad.¹
• La lectura de cifras comienza por distinguir inclusive (la función y lo llamado por ella) de exclusive (solo la función). Un exclusive alto indica dónde se consume realmente CPU; un inclusive alto indica que algo bajo esa función es costoso.
• Antes de medir, fije «qué es lento» en una sola operación. Una captura de «todo va pesado» no se puede leer. Fije operación y tiempo, por ejemplo «este informe tarda 40 segundos», antes de recoger. Para comparar antes y después, consulte Cómo comparar correctamente la velocidad de versiones de programas en Windows.

2. Relación entre herramientas — ETW y EventPipe

Parece que hay muchas herramientas, pero solo hay dos bases.

• ETW (Event Tracing for Windows): infraestructura de trazas de todo el sistema. Puede registrar del kernel a la aplicación en la misma línea temporal; requiere privilegios de administrador para iniciar o detener sesiones y es exclusiva de Windows.³
• EventPipe: mecanismo de trazas integrado en el runtime .NET. No necesita privilegios de administrador y funciona igual en todos los sistemas, pero solo alcanza código administrado y runtime; no recoge eventos del kernel ni pilas nativas.²

Con esta relación resulta natural usar primero una recogida ligera con dotnet-trace y, si no basta, recoger ETW completo con PerfView.

3. Antes de recoger — observar diez minutos con dotnet-counters

Antes de tomar una traza es frecuente que sea más rápido observar las métricas principales del runtime con dotnet-counters.⁴

dotnet tool install --global dotnet-counters
dotnet-counters ps
dotnet-counters monitor --process-id <PID> --counters System.Runtime

Mire uso de CPU, tamaño y número de GC del heap, longitud de cola y número de hilos de ThreadPool, y número de excepciones. Si ya se ve que «el GC se ejecuta varias veces por segundo» o «la cola de ThreadPool sigue creciendo», se puede limitar el tipo de traza siguiente, por ejemplo a asignaciones o bloqueo. Para leer tendencias de memoria, consulte el artículo sobre distinguir espera de GC y fuga de memoria.

4. Recoger una traza con dotnet-trace

dotnet-trace es una herramienta de recogida basada en EventPipe.⁵ La instalación y recogida básica son:

dotnet tool install --global dotnet-trace
dotnet-trace ps
dotnet-trace collect --process-id <PID> --duration 00:00:00:30

Sin indicar opciones, se recoge con la configuración de perfil predeterminada, que incluye eventos principales del runtime y muestreo de hilos. El perfil llamado cpu-sampling, que existió antes, se retiró; actualmente el predeterminado combina dotnet-common y dotnet-sampled-thread-time.⁵ Según el objetivo también se puede usar --profile gc-verbose, para GC y muestreo de asignaciones de objetos, o --profile gc-collect, que registra solo la aparición de GC con poca carga.

Para recoger junto con el proveedor propio de EventSource creado en el artículo anterior, añada --providers.

dotnet-trace collect --process-id <PID> --providers KomuraSoft-OrderService

El resultado es un archivo .nettrace. Hay tres maneras de abrirlo: Visual Studio, PerfView o convertirlo a formato speedscope para verlo en un navegador.⁵

dotnet-trace convert trace.nettrace --format Speedscope

El formato speedscope se abre en speedscope.app como un gráfico de llamas ligero y es adecuado para observar intuitivamente «bajo qué función se gastó el tiempo». Para una inspección que identifique la función, el visor de pilas de PerfView es más potente; pasemos al siguiente capítulo.

5. Investigar la CPU con PerfView — cómo leer el visor de pilas

PerfView es una herramienta gratuita de investigación de rendimiento publicada por Microsoft. Basta descargar PerfView.exe desde la página de versiones de GitHub; no requiere instalación.⁶

5.1 Recoger

Abra el diálogo con «Collect > Collect» en la GUI y siga el flujo Start Collection → reproducir la operación objetivo → Stop Collection. En línea de comando es así; ejecútelo como administrador porque inicia una sesión ETW.³

PerfView collect /nogui /acceptEULA /maxCollectSec:30

La recogida predeterminada incluye muestras de CPU cada milisegundo en todos los procesadores, con pila de llamadas, y eventos principales de CLR.¹ Se considera que la sobrecarga de esta configuración es de unos pocos puntos porcentuales.⁷

5.2 Leer CPU Stacks

Abra el resultado, .etl.zip, y seleccione el proceso objetivo en «CPU Stacks» para abrir el visor de pilas. Mire primero las dos columnas de la pestaña By Name:

• Exc (exclusive): número de muestras mientras se ejecutaba esa función. Es donde realmente se consume CPU.
• Inc (inclusive): total de muestras de la función y todo lo que llama. Indica que algún lugar bajo ella es costoso.

La forma de lectura es empezar por los mayores Exc y clasificar si son código propio, runtime o biblioteca. Si aparece código propio arriba, el algoritmo o bucle de esa función es un objetivo directo. Si System.String o un serializador JSON aparecen arriba en Exc, sígalos por Inc en la pestaña Callers para identificar desde qué parte de su código se llaman masivamente.

También es esencial comprobar el número de muestras. Las muestras de CPU son estadísticas a intervalos de 1 ms y, con pocas, el resultado está sujeto al azar. Como referencia, reúna al menos 1.000 y preferiblemente unas 5.000 antes de decidir; si no basta, repita la operación objetivo y amplíe la recogida.¹

Si los nombres de funciones de módulos propios aparecen como direcciones, no se han resuelto los símbolos PDB. Tener a mano los PDB de los resultados de compilación determina directamente la capacidad de investigar. Se explica con detalle en Qué es PDB (Program Database).

6. «La CPU está libre, pero es lento» — ver tiempo bloqueado con ThreadTime

Más de la mitad de los casos prácticos de «lento» no son CPU, sino espera: espera de bloqueo, respuesta de base de datos o HTTP, E/S de archivos o una espera cercana a interbloqueo por Task.Result. En muestreo de CPU esos problemas no aparecen porque son tiempo en el que no se usó CPU.

Si activa la opción Thread Time al recoger con PerfView, se registran además eventos de cambio de contexto y se puede seguir para cada hilo tanto «tiempo usando CPU» como «tiempo bloqueado».¹

PerfView collect /nogui /acceptEULA /threadTime /maxCollectSec:30

Abra «Thread Time Stacks» para analizar. Usa el mismo visor de pilas que CPU Stacks, pero las muestras incluyen no solo tiempo de CPU sino BLOCKED_TIME, tiempo bloqueado. Limite el rango temporal a la operación lenta y vea en qué pila —qué espera— se acumula BLOCKED_TIME del hilo que ejecutaba el trabajo. Así se obtiene un desglose como «de 40 segundos totales, 35 fueron espera de esta llamada HTTP».

Los síntomas de congelación de UI, como no responder durante segundos al operar, también suelen ser bloqueo del hilo de interfaz. Identifique el destino de bloqueo del hilo UI con ThreadTime y, como solución permanente, rediseñe las esperas síncronas como asincrónicas. Para la parte de diseño, consulte Async y el hilo UI de WPF/WinForms en una sola hoja.

ThreadTime registra un evento por cada cambio de contexto, por lo que produce claramente más datos que la recogida predeterminada. Limite la recogida a periodos cortos y evite hacerla durante mucho tiempo en producción.

7. Combinar con EventSource — dividir «qué tramo fue lento» en lenguaje de negocio

CPU Stacks y Thread Time agregan todo el proceso. Si se quiere dividir por una unidad de negocio, como «qué parte del procesamiento de un pedido es lenta», resultan útiles los eventos Start/Stop de EventSource tratados en el artículo anterior.

• Instrumente eventos como OrderProcessingStart / OrderProcessingStop en la aplicación; la implementación está en el artículo anterior.
• Compruebe la hora de los eventos en la vista «Events» de PerfView y limite el rango temporal del visor de pilas mediante filtros Start/End a ese intervalo.
• Lea el desglose de CPU y tiempo bloqueado dentro del intervalo limitado.

Así se puede analizar solo «esa una vez que fue lenta» sin quedar enterrado en el ruido de operaciones normales. Los eventos propios también se recogen con dotnet-trace, de modo que una vez introducida la instrumentación se aplica el mismo método en desarrollo y producción. En la práctica, la dificultad de investigar rendimiento depende más de «si la aplicación tiene puntos de observación» que de la habilidad con la herramienta.

Resumen

• Separar «lento» en CPU bound y bloqueo es el punto de partida. El primero se ve con muestreo de CPU —una muestra ≒ 1 ms—; el segundo no aparece sin ThreadTime.
• El reparto básico es dotnet-trace, que no necesita administrador, y PerfView cuando se requiere máquina completa, nativo o tiempo bloqueado. Leer en PerfView el .nettrace recogido es también una combinación habitual.
• El núcleo de lectura del visor de pilas es distinguir exclusive de inclusive y comprobar siempre que hay suficientes muestras.
• Si se pueden dividir las operaciones de negocio mediante eventos propios de EventSource, la precisión de la investigación sube un nivel.

KomuraSoft LLC aborda la investigación de problemas de rendimiento de aplicaciones de negocio Windows, como lentitud, congelación o CPU sostenida, y la consulta de instrumentación y diseño para que sean más fáciles de medir. Si existen pasos de reproducción y un archivo de traza, también se puede solicitar solo el análisis a partir de ellos.

Artículos relacionados

• Introducción al registro de eventos de Windows y ETW — llevar los registros de aplicaciones de negocio al mecanismo estándar del sistema operativo
• Distinguir espera de GC y fuga de memoria en .NET — procedimiento práctico para observar, comparar y demostrar memoria que crece
• Leer volcados de bloqueo con WinDbg + SOS — introducción práctica al análisis posterior a la recogida
• Introducción a la recogida de volcados de Windows — WER/ProcDump/WinDbg
• Qué es PDB (Program Database) — entender información de depuración, símbolos y Source Link
• Cómo comparar correctamente la velocidad de versiones de programas en Windows
• Async y el hilo UI de WPF/WinForms en una sola hoja

Ámbitos de consulta relacionados

• Investigación de fallos y análisis de causa
• Desarrollo de aplicaciones Windows
• Consultoría técnica y revisión de diseño
• Contacto

Enlaces de referencia

Artículos relacionados

Artículos recientes con las mismas etiquetas para profundizar en temas cercanos.

Temas relacionados

Estas páginas sitúan el tema en un contexto más amplio de servicios y decisiones.

Servicios relacionados con este tema

El artículo está directamente relacionado con los siguientes servicios.

Preguntas frecuentes

Preguntas habituales en las consultas sobre el tema del artículo.

¿Debo usar PerfView o dotnet-trace?

Recomendamos probar primero dotnet-trace. Puede usarse sin privilegios de administrador, recoger datos solo del proceso objetivo y la operación se resuelve en una línea de comando. En cambio, si necesita ver pilas de código nativo, la situación de toda la máquina —influencia de otros procesos o del kernel— o seguir el tiempo bloqueado por cambio de contexto, hace falta PerfView basado en ETW. También es habitual recoger un archivo .nettrace y abrirlo después con PerfView para analizarlo.

¿Cómo se relaciona con el generador de perfiles de Visual Studio?

Si el problema se reproduce en una máquina de desarrollo, las herramientas de uso de CPU y memoria de Visual Studio son más sencillas y normalmente bastan para empezar. PerfView y dotnet-trace son útiles al recoger datos en equipos de prueba o producción donde no se puede instalar Visual Studio, al separar recogida y análisis en equipos distintos o al necesitar eventos ETW, incluidos EventSource propios y eventos del kernel. Visual Studio también puede abrir los archivos .nettrace producidos por dotnet-trace.

¿Es seguro ejecutarlo en un servidor de producción?

Ambas herramientas están pensadas para recogidas breves en producción, pero no sin condiciones. Limite la duración a decenas de segundos o unos minutos, pruebe primero el mismo comando en un entorno de validación para comprobar la sobrecarga y el tamaño del archivo, y confirme el espacio libre en disco. En especial, la recogida ThreadTime —cambios de contexto— y las trazas de asignación producen muchos eventos y el archivo crece rápido. Además, una traza puede contener información como argumentos de línea de comandos, por lo que hay que manejar los archivos recogidos con cuidado.

¿Cómo se reparten con WPR/WPA?

WPR (Windows Performance Recorder) y WPA (Windows Performance Analyzer) son herramientas de investigación más orientadas al sistema operativo y basadas en el mismo ETW. Para análisis detallado de toda la máquina, como E/S de disco, energía o tiempo de arranque, WPR/WPA es fuerte; para investigar CPU, GC y tiempo bloqueado de una aplicación .NET, PerfView suele ser más legible porque su presentación está optimizada para código administrado. Si el objetivo es una aplicación de negocio, PerfView y dotnet-trace cubren la mayor parte de los casos.

Perfil del autor

Página de presentación del autor del artículo.

Go Komura

Representante de KomuraSoft LLC

Especializado en desarrollo de software para Windows, consultoría técnica e investigación de fallos, sobre todo en proyectos con sistemas existentes y errores difíciles de reproducir.