Visual Studio 2010 Profiling Tools - Solucionando problemas de rendimiento - Parte 1

Autor: Nestor Guadarrama – Revisión Técnica: Ivanov Cepeda

En el mundo del soporte técnico a desarrollo de software, muchas veces nos encontramos frente a dilemas que nos permiten pensar en nuevas formas de estudiar un problema relacionado con las aplicaciones a las cuales estamos realizando dicho soporte.

Hoy les quiero presentar una característica de Visual Studio que permite a los equipos de desarrollo medir, evaluar e identificar problemas relacionados con el rendimiento de las aplicaciones .NET. Se trata de Microsoft Visual Studio Profiling Tools. Esta herramienta esta totalmente integrada con la IDE de Visual Studio 2010, pero además, posee una versión stand-alone que puede ser instalada en ambientes de producción, sin necesidad de instalar Visual Studio, para apoyar el proceso de análisis de escenarios de bajo rendimiento en esquemas cliente/servidor o incluso en esquemas locales.

En términos prácticos, perfilar una aplicación en Microsoft Visual Studio Profiling Tools es muy sencillo. La idea fundamental de perfilar una aplicación para detectar problemas de rendimiento se basa en los siguientes pasos:

  1. Crear una sesión de rendimiento (se mide inicialmente el performance de la aplicación).
  2. Con la data recolectada por la primera sesión de rendimiento, se analizan potenciales problemas de consumo de memoria, cuellos de botella (bottleneck), problemas de código, alto consumo de procesamiento.
  3. Con la detección inicial, y posterior corrección de las evidencias encontradas, se crea una nueva sesión de rendimiento que permita realizar comparaciones sobre los cambios realizados y determinar los umbrales de rendimiento que la aplicación puede alcanzar.

Iniciemos esta serie de cuatro (4) artículos, creando un escenario de pruebas para poder evaluar el comportamiento de una aplicación web, que consuma servicios web y que presente problemas de rendimiento en las respuestas a los requerimientos de los clientes. La aplicación que vamos a utilizar para probar Visual Studio Profiling Tools se llama AdventureWorks HRProfiler. Como lo pueden imaginar, creamos una pequeña aplicación web (.NET Framework 4.0), que publica información de la base de datos de ejemplos AdventureWorks:

image

Figura 1: Adventure Works Web Site

La aplicación AdventureWorks HRProfiler fue diseñada para trabajar en un modelo básico de dos (2) capas:

a) Capa de presentación básica (ASP .NET 4.0)

b) Capa de datos (Entity Framework 4.0)

image

Figura 2: Esquema de dos (2) capas de la aplicación Adventure Works

Tal y como indicamos previamente, la primera tarea que debemos realizar es identificar el tipo de prueba de rendimiento que deseamos aplicar para nuestra aplicación. En esta etapa, Microsoft Visual Studio Profiling Tools nos brinda las siguientes opciones:

Método

Descripción

Sampling

Captura información estadística sobre el trabajo ejecutado por una aplicación. El método Sampling es útil para realizar las siguientes tareas:

· Exploración inicial del rendimiento general de la aplicación.

· Investigación sobre problemas de rendimiento que involucren utilización del procesador (CPU).

El método de perfilamiento basado en Sampling, interrumpe el ciclo del procesador del computador en intervalos determinados y colecta la pila de llamada de funciones, código fuente e instrucciones de la aplicación. La información recabada se utiliza para medir los tiempos de procesamiento entre llamadas y los ciclos de uso del procesador en el momento en que las llamadas se estaban ejecutando.

Instrumentation

Captura información detallada sobre los tiempos de ejecución de llamadas de cada función de la aplicación. Este método es útil en los siguientes escenarios:

· Investigación de cuellos de botella (bottleneck) de tipo entrada/salida como por ejemplo procesos de escritura/lectura de disco (disk I/O).

· Análisis detallado de un módulo en particular o un conjunto de funciones.

El método Instrumentation inyecta código dentro de los archivos binarios para capturar información sobre los tiempos de ejecución de cada función primaria en el archivo instrumentado y por cada llamada a función realizada por dichas funciones primarias. Además, identifica cuando una función, llama al sistema operativo para operaciones de escritura/lectura como escribir un archivo.

Concurrency

Captura información detallada sobre tareas multi-hilo (multi-threaded) para las aplicaciones. El perfilamiento de contención de recursos colecta información detallada sobre la pila de llamadas cada vez que hilos que están compitiendo por ser atendidos son forzados a esperar para tener acceso a recursos compartidos. Además, las visualizaciones ofrecidas por el método Concurrency colectan información general acerca de cómo las aplicaciones multi-hilo interactúan entre ellas, el hardware, el sistema operativo y con otros procesos dentro del computador huésped:

· Los reportes de contención de recursos muestran el número total de contenciones y la cantidad total de tiempo que fue invertido por cada uno de los módulos, funciones, líneas de código fuente e instrucciones en los cuales la espera ocurrió. Además, el grafico de línea de tiempo muestra la contención en cada periodo en que esta ocurre.

· El visualizados de concurrencia muestra información gráfica que puede ser utilizada para localizar cuellos de botella de rendimiento, subutilización del CPU, contención de hilos de ejecución, migración de hilos de ejecución, problemas o demoras de sincronización de hilos y áreas de solapamiento (overlapping) de escritura (/O). Cuando es posible, el grafico genera enlaces de llamada (hyperlinks) a las pilas de información de llamada del código fuente.

.NET Memory

El método .NET Memory realiza interrupciones del procesador en el computador en cada carga de datos en memoria (allocation) realizada por un objeto .NET Framework dentro de la aplicación perfilada. Cuando el tiempo de vida de la data llega a su fin, por ejecución realizada por el Garbage Collector, el método también interrumpe al procesador para capturar la información disponible de limpieza y compresión, antes de liberar la memoria.

· Cuando la carga de bloques de datos en memoria ocurre, el perfilador colecta información adicional sobre la pila de llamadas a funciones. El contador de carga de data en memoria se incrementa por la función que actualmente es ejecutada. El reporte .NET presenta el total de los contadores para los módulos, funciones, líneas de código fuente e instrucciones perfiladas en el proceso.

· Cuando un proceso de colección del Grabage Collector ocurre, el perfilador colecta información acerca de los objetos que fueron destruidos e información acerca de los objetos en cada generación del Grabage Collector. Al final del proceso de perfilación, el perfilador graba toda la información acerca de los objetos que no fueron explícitamente destruidos. El reporte de Línea de Tiempo de Objetos (Object Lifetime) muestra la información de los totales por cada tipo de datos cargado en la ejecución del perfilador.

Tier interaction

El método Tier Interaction, agrega información al archivo de datos del perfilador sobre las llamadas síncronas ADO .NET hacia paginas ASP .NET u otras aplicaciones y bases de datos SQL Server. La información incluye la cantidad, tiempo de las llamadas, cantidad máxima y mínima de veces que dichas llamadas son realizadas, etc. La información colectada por el metodo Tier Interaction, puede ser agregada a la información colectada por un perfilador de tipo Sampling, Instrumentation, .NET Memory o Concurrency.

PREREQUISITOS

Antes de iniciar un proceso de perfilamiento, es necesario asegurarse de que las siguientes condiciones se cumplan y así evitar lecturas de rendimiento incorrectas:

  • Ejecute el perfilador como “Administrator” . Si su cuenta no es “Administrator” del equipo que Ud. está utilizando, Ud. debería ejecutar Visual Studio como “Administrator” para asegurar que el proceso posee los permisos necesarios para algunas de las características de la herramienta de perfilamiento.
  • Configure el valor de compilación activa como “Release” . La compilación en modo “Debug”, inserta código de diagnóstico adicional en la aplicación y no incluye optimizaciones claves que el compilador ejecuta en la construcción del ensamblado. Perfilar la versión en modo “Release” de su aplicación provee mayor exactitud en la información sobre el rendimiento del proceso.
  • Obtenga los archivos de símbolos de Windows. Si Ud. perfila código que hace llamadas a funciones de Windows, Ud. debería asegurarse que tiene los más recientes archivos .PDB. Sin estos archivos, los informes que serán presentados por el perfilador en las llamadas a las funciones de Windows, serán crípticos y difíciles de comprender. Para conocer cómo hacer referencia a los archivos de símbolos de Windows, puede hacer click en el siguiente enlace: How to- Reference Windows Symbol Information.

INTRODUCCION AL PERFORMANCE WIZARD

El primer paso para iniciar el perfilamiento de la aplicación es utilizar el asistente de rendimiento (“Performance Wizard”), para seleccionar el tipo de método de perfilamiento que deseamos aplicar:

image

Figura 3: Menú de acceso al asistente de rendimiento

La pantalla de bienvenida del asistente, mostrara las distintas opciones de perfilación disponibles para la aplicación. Para esta primera fase, seleccionaremos la opción por defecto CPU Sampling:

image

Figura 4: Selección del método de perfilamiento

El asistente nos solicitara seleccionar el proyecto que deseamos perfilar. Para esta ocasión, seleccionare el proyecto HRWeb:

image

Figura 5: Selección del proyecto a perfilar

En el siguiente paso, el asistente solicitará información sobre la habilitación o no del proceso de perfilación entre capas (Tier Interaction Profiling). Para esta etapa, dejaremos los valores pode defecto:

image

Figura 6: Selección del perfilamiento Tier Interaction

Finalmente, el asistente culminara el proceso de selección y estará listo para iniciar el proceso de perfilamiento de la aplicación. En este momento, no seleccionaremos la opción “Launch profiling after the wizard finishes”:

image

Figura 7: Finalización del proceso de asistencia del perfilador

Una vez finaliza el asistente del proceso de perfilamiento de la aplicación, Visual Studio activará la ventana de dialogo Performance Explorer:

image

Figura 8: Ventana de dialogo Performance Explorer en Visual Studio 2010:

El menú superior de la ventana Performance Explorer, mostrará los accesos y acciones que pueden ser ejecutadas a través de los iconos indicados a continuación:

image

Figura 9: Ejecución del Asistente de Perfilamiento

image

Figura 10: Creación de nueva sesión de perfilamiento

image

Figura 11: Inicio del proceso de perfilamiento

CONCEPTOS BASICOS

Cuando se utiliza el Perfromance Profiler Wizard, automáticamente se crea una Sesión de Rendimiento o Performance Session, la cual contiene los datos de configuración del perfilador para colectar información y el resultado de uno o más ejecuciones del mismo perfilador:

image

Figura 12: Performance Explorer

  1. El nombre de la sesión de perfilamiento
  2. La carpeta de Reports, la cual contiene los archivos de datos de perfilamiento de una o más ejecuciones. Se puede seleccionar vistas de la información de rendimiento como llamadas a funciones, cargas de datos en memoria (memory allocations) e información detallada sobre funciones específicas, haciendo click en el nombre de un cualquier archivo dentro de esta carpeta.
  3. La carpeta Targets, la cual muestra los proyectos o binarios que son perfilados en la sesión.

SESION DE RENDIMIENTO

Ahora, con la sesión de rendimiento creada, el siguiente paso es ejecutar la sesión de rendimiento para colectar información de línea base. Para realizar esta operación tenemos dos (2) opciones:

  • Utilizando el asistente de asistente de rendimiento (Performance Wizard). Cuando se está creando la sesión, si se selecciona la opción Launch profiling after wizard finishes, el asistente iniciara una sesión de manera automática:

image

Figura 13: Ventana del Peformance Wizard – Page 4 of 4

  • Utilizando el boto Start Profiling de la ventana de diálogo Perfomance Explorer ubicada al lado izquierdo de la interfaz de Visual Studio 2010:

image

Figura 14: Botón Start Profiling en la ventana del Performance Explorer

Al iniciar la sesión de colección de datos de rendimiento, sucederán 2 acciones:

  • Se iniciara una sesión de su navegador o de la aplicación que este perfilando, para realizar el proceso de navegación y de ejecución de acciones que se desean analizar.
  • Visual Studio 2010 presentara una ventana indicando que el proceso de ejecución del perfilador de rendimiento se esta ejecutando. Usted puede pausar la ejecución o detenerla en cualquier momento utilizando los enlaces que dicha ventana le proporcional:

image

Figura 15: Ventana de información de Visual Studio 2010 que indica que el proceso de perfilamiento se esta ejecutando.

Une vez realizada la navegación de la aplicación que usted desea analizar, Visual Studio 2010 iniciará el proceso de análisis de toda la data recolectada durante la navegación y presentará una venta con el resumen del Sample Profiling Report, con las siguientes secciones:

  • CPU Usage: Este grafico permite filtrar la información del reporte de perfilamiento. Resaltar una región del gráfico y escoger la opción Filter by selection, muestra solamente la data que fue colectada para dicho periodo de tiempo. Cuando se selecciona una región del gráfico, las secciones Hot Path y Functions Doing Most Individual Work mostraran solamente los valores asociados a la región seleccionada.

image

Figura 16: Sección CPU Usage (Línea de Tiempo) del reporte de perfilamiento

  • Hot Path: Esta sección lista todas las llamadas que han consumido mayor cantidad de tiempo. El árbol de llamadas muestra las funciones más activas cuando la data fue colectada por el perfilador. Esta sección muestra dos (2) columnas: Inclusive Samples % y Exclusive Samples % :

o Inclusive Samples indican cuanto trabajo fue realizado por cada función y cualquier función asociada a la primera llamada.

o Exclusive Samples indican cuanto trabajo fue realizado por el código dentro del cuerpo de la funcion, excluyendo el trabajo realizado por las funciones que fueron ejecutadas por esta llamada.

image

Figura 17. Sección Hot Path del reporte de perfilamiento

  • Functions Doing Most Individual Work: Esta sección lista las funciones que están haciendo la mayor cantidad de trabajo en la aplicación (Exclusive Samples).

image

Figura 18. Sección Functions Doing Most Individual Work del reporte de perfilamiento

Para el caso del análisis realizado por el perfilador para nuestra aplicación HRWeb, iniciamos el proceso en la sección Hot Path¸para investigar cuales llamadas consumieron mayor cantidad de tiempo. Lo primero que llama la atención en el análisis es que las funciones de concatenación de cadena System.String.Concat consumen más del 60% del costo total de ejecución de la aplicación:

image

Figura 19. Sección Hot Path mostrando las llamadas que consumieron más tiempo.

Haciendo el análisis sugerido por la sección, se identifica que esta llamada es realizada desde la ruta HRweb.Benefits.BuildParagraph() . Lo interesante de esta sección es que si usted hace click en cualquiera de las funciones identificadas en la sección, Visual Studio 2010 lo llevara directamente a la línea de código dentro del cuerpo de la función que hace la llamada identificada (Exclusive Samples):

image

Figura 20. Sección detallada de la llamada a la función HRWeb.Benefits.BuildParagraph()

En la figura anterior, se puede observar como el perfilador de Visual Studio 2010 muestra una gráfica de barras que indica el porcentaje de tiempo consumido por las llamadas que originan la instrucción analizada, por las funciones que son ejecutadas desde la llamada inicial a la función HRWeb.Benefits.BuildParagraph() y resalta en color rojo, la línea de código que realiza la invocación al proceso de concatenación de cadenas (System.String.Concat() ), lo cual, como se aprecia en el código, es una muy mala práctica de construcción de HTML de manera dinámica.

Otra característica esencial del perfilador de Visual Studio 2010, es la sección View Guidance, la cual muestra la ventana Error List, con las recomendaciones que el perfilador genera para la aplicación, basadas en reglas definidas dentro de Visual Studio 2010:

image

Figura 21. Ventana de recomendaciones (View Guidance)

image

Figura 22. Venta Error List, con las recomendaciones realizadas por el perfilador

Además, el reporte nos brinda otras vistas alternativas de la data colectada, para que podamos hacer análisis en profundidad de las secciones de rendimiento de código colectadas por el perfilador (de estas vistas y análisis, hablaremos en los próximos artículos):

image

Figura 23. Lista despegable Current View, que muestra las distintas vistas que el reporte nos ofrece para análisis.

En este punto, grabaremos el reporte creado por el perfilador, utilizando el menú contextual ubicado a la izquierda del reporte llamado Report:

image

Figura 24. Menú contextual del reporte del perfilador.

Ahora, dado que el perfilador nos recomienda que realicemos una mejor inicial cambiando el patrón de concatenación para utilizar la función StringBuilder() , realizaremos este cambio en el código sugerido (cambio omitido en el presente artículo), y procederemos a tomar una nueva muestra de perfilamiento para identificar como este cambio afecta el desempeño de la aplicación. Al analizar el nuevo reporte, notamos rápidamente que la llamada inicial a las funciones de concatenación de cadenas identificadas en el reporte inicial, han desaparecido y en su lugar se muestran llamadas a otras funciones de carga de datos:

image

Figura 25. Sección Hot Path del nuevo reporte de perfilamiento, donde se identifican otras llamadas distintas al reporte original.

Pero además, Visual Studio nos ofrece una excelente alternativa denominada Compare Reports, ubicada en el menú contextual del reporte:

image

Figura 26. Menú contextual mostrando la opción Compare Reports

Esta opción permite realizar la comparación de dos (2) reportes asociados al mismo proyecto para establecer los valores de diferencia (Delta) entre cada ejecución:

image

Figura 27. Ventana Comparison Report, mostrando las diferencias de valores entre funciones de llamado para los reportes comparados

En los próximos artículos, trabajaremos en comprender algunos de los análisis realizados por el perfilador, así como la identificación de otras técnicas para mejorar el rendimiento de la aplicación HRWeb y por supuesto, utilizar otras técnicas de perfilamiento.

Estamos en contacto!!