
A menudo, es necesario recopilar estadísticas sobre el rendimiento de los métodos de aplicación en tiempo real (cuando la aplicación ya se está ejecutando) para identificar sus cuellos de botella y ver qué parte de la aplicación se está ralentizando.
Además, sería bueno, además de los datos de rendimiento en sí (tiempo de desarrollo del método, fecha de inicio y finalización de su llamada) almacenar un contexto de llamada en el que se supervise el rendimiento (como argumentos de invocación de métodos y datos arbitrarios agregados por el desarrollador).
Bueno, la "guinda del pastel" puede considerarse la conveniencia y simplicidad de la herramienta utilizada, que también es importante.
Para resolver estos problemas, se desarrolló una biblioteca .NET de código abierto multiplataforma Unchase.FluentPerformanceMeter .
Introduccion
Por lo tanto, este artículo es una descripción del trabajo con Unchase Fluent Performance Meter , una biblioteca multiplataforma de código abierto .Net Standard 2.0 diseñada para calcular el rendimiento de los métodos.
La biblioteca se puede usar en aplicaciones .NET Core y .NET Framework que admiten .Net Standard 2.0 , y permite:
- Realice mediciones precisas del rendimiento de los métodos públicos para las clases públicas tanto de su código como del código de las bibliotecas utilizadas (con la fijación de la hora exacta del inicio y el final de la medición);
- Agregue datos adicionales (Datos personalizados) a los resultados de la medición. Por ejemplo, los valores de los parámetros de entrada del método y el resultado; o datos de contexto de ejecución del método; o corellationId , mediante el cual será posible vincular varias mediciones del rendimiento de los métodos;
- Divida la medición del rendimiento del método en pasos separados (Pasos) con la fijación de datos propios para cada paso. Además, puede establecer el tiempo de ejecución mínimo , a partir del cual se tendrá en cuenta el paso en la medición (si el paso se completa más rápido, no se medirá);
- Excluir ciertas partes del código de la medición del rendimiento (por ejemplo, llamadas a métodos individuales cuyo tiempo de ejecución no necesita ser tenido en cuenta al medir);
- Agregue sus propios comandos (Comandos), que se garantiza que se ejecutarán inmediatamente después del final de la medición del rendimiento del método (por ejemplo, para agregar un procesamiento adicional de los resultados obtenidos, como el registro o la escritura de datos en el almacenamiento);
- Agregue su propio controlador de excepciones para el código ejecutado en el contexto de medición del rendimiento del método (ambos comunes para todas las mediciones y para cada medición por separado);
- Establezca el tiempo para almacenar los resultados de las mediciones de la productividad de los métodos, después de lo cual se eliminarán los resultados;
- Agregue datos sobre quién llama al método (Llamador) a través de IHttpContextAccesor o la tarea del llamante en el código a los resultados de la medición (por ejemplo, puede especificar el nombre del servicio externo que llamó al método);
- Agregue a los resultados de la medición los datos del lugar donde se inició la medición del rendimiento (nombre del archivo y número de línea con la ubicación de la llamada en el código);
- Interrumpir la medición del rendimiento del método hasta su finalización .
Los datos obtenidos como resultado de la medición del rendimiento de los métodos se pueden utilizar para analizar el rendimiento de la aplicación (sus partes individuales, tanto internas - código nativo, como externas - el código de las bibliotecas utilizadas) y se muestran en una forma gráfica conveniente para usted.
Contenido
Empezando
Para usar la biblioteca, instale el paquete NuGet en su proyecto:
Usando manualmente el Administrador de paquetes NuGet :
Install-Package Unchase.FluentPerformanceMeter
Usando .NET CLI:
dotnet add package Unchase.FluentPerformanceMeter --version {version}
Donde {versión} es la versión del paquete que desea instalar.
Por ejemplo, dotnet add package Unchase.FluentPerformanceMeter --version 1.0.0
Ejemplos de uso
Método de medición del rendimiento
El siguiente es un ejemplo simple de uso de la biblioteca (sin configuración y configuraciones adicionales) para medir el rendimiento del SimpleWatchingMethodStart
(Acción) SimpleWatchingMethodStart
controlador SimpleWatchingMethodStart
(Controlador) PerformanceMeterController
Asp.Net Core 2.2 WebAPI . Para hacer esto, puede usar el método de extensión .WatchingMethod().Start()
o una funcionalidad similar .StartWatching()
.
Desde la versión v1.0.5, también puede usar .WatchingMethod().Start(SimpleWatchingMethodStart)
o .StartWatching(SimpleWatchingMethodStart)
con el nombre del método.
Todos los ejemplos de uso de la biblioteca se pueden encontrar en los proyectos Unchase.FluentPerformanceMeter.Test*
de este repositorio .
/// <summary> /// Test GET method with simple performance watching. /// </summary> [HttpGet("SimpleWatchingMethodStart")] public ActionResult SimpleWatchingMethodStart() { // for C# 8 you can use: //using var pm = PerformanceMeter<PerformanceMeterController>.StartWatching(); using (PerformanceMeter<PerformanceMeterController>.WatchingMethod().Start()) { // put your code with some logic here return Ok(); } }
Para obtener los resultados de las mediciones de rendimiento de los métodos públicos de la clase de controlador PerformanceMeterController
, puede llamar al siguiente método:
/// <summary> /// Get methods performance info for this controller. /// </summary> /// <returns>Returns methods performance info.</returns> [HttpGet("GetPerformanceInfo")] [IgnoreMethodPerformance] public ActionResult<IPerformanceInfo> GetPerformanceInfo() { return Ok(PerformanceMeter<PerformanceMeterController>.PerformanceInfo); }
Después de llamar al método SimpleWatchingMethodStart
al llamar a GetPerformanceInfo
obtenemos:
{ "methodCalls": [ { "methodName": "SimpleWatchingMethodStart", "elapsed": "00:00:00.0016350", "caller": "unknown", "startTime": "2019-12-06T10:27:27.3385385Z", "endTime": "2019-12-06T10:27:27.3401735Z", "customData": {}, "steps": [] } ], "totalActivity": [ { "methodName": "SimpleWatchingMethodStart", "callsCount": 1 } ], "currentActivity": [ { "methodName": "SimpleWatchingMethodStart", "callsCount": 0 } ], "uptimeSince": "2019-12-06T10:27:27.3370183Z", "className": "Unchase.FluentPerformanceMeter.TestWebAPI.Controllers.PerformanceMeterController", "methodNames": [ "SimpleWatchingMethodStart" ], "customData": {}, "timerFrequency": 10000000 }
A partir de la versión v1.1.0 , se hizo posible medir el rendimiento de los métodos en una aplicación AspNetCore MVC utilizando DiagnosticSource
y el atributo especial WatchingWithDiagnosticSourceAttribute
.
Para hacer esto, agregue el paquete Unchase.FluentPerformanceMeter.AspNetCore.Mvc al proyecto NuGet y agregue el siguiente código a Startap.cs
:
public void ConfigureServices(IServiceCollection services) { // ... // allows to measure methods performance for class "MeasurableClass" and "MeasurableSecondClass" services.AddPerformanceDiagnosticObserver<MeasurableClass>(); services.AddPerformanceDiagnosticObserver<MeasurableSecondClass>(); // ... the same for another classes services.AddMvc(); // ... } public void Configure(IApplicationBuilder app, IHostingEnvironment env) { // ... app.UsePerformanceDiagnosticObserver(); app.UseMvc(); }
Luego marque con el atributo WatchingWithDiagnosticSourceAttribute
o métodos individuales:
[HttpGet("SimpleWatchingMethodStart")] [WatchingWithDiagnosticSource] public ActionResult SimpleWatchingMethodStart() { return Ok(); }
o toda la clase:
[ApiController] [Route("api/v1/[controller]")] [Produces("application/json")] [SwaggerTag("Unchase.PerformanceMeter Test WebAPI Controller")] [WatchingWithDiagnosticSource] public class PerformanceMeterController : ControllerBase { // measurable methods }
A partir de la versión v1.2.0 , se hizo posible agregar argumentos de invocación a los datos de medición del rendimiento del método del usuario en una aplicación AspNetCore MVC utilizando el atributo especial AddMethodArgumentsToCustomDataAttribute
junto con el atributo WatchingWithDiagnosticSourceAttribute
:
[HttpPost("SimpleWatchingMethodStartWithArgs")] [WatchingWithDiagnosticSource] [AddMethodArgumentsToCustomData("actionArguments")] public ActionResult SimpleWatchingMethodStartWithArgs(DTOArgument arg) { return Ok(); }
Después de llamar al método SimpleWatchingMethodStartWithArgs
al llamar a GetPerformanceInfo
obtenemos:
{ "methodCalls": [ { "methodName": "SimpleWatchingMethodStartWithArgs", "elapsed": "00:00:00.0016350", "caller": "unknown", "startTime": "2019-12-06T10:27:27.3385385Z", "endTime": "2019-12-06T10:27:27.3401735Z", "customData": { "actionArguments": { "arg": { "data": "<string_in_DTOArgument>" } } }, "steps": [] } ], "totalActivity": [ { "methodName": "SimpleWatchingMethodStartWithArgs", "callsCount": 1 } ], "currentActivity": [ { "methodName": "SimpleWatchingMethodStartWithArgs", "callsCount": 0 } ], "uptimeSince": "2019-12-06T10:27:27.3370183Z", "className": "Unchase.FluentPerformanceMeter.TestWebAPI.Controllers.PerformanceMeterController", "methodNames": [ "SimpleWatchingMethodStartWithArgs" ], "customData": {}, "timerFrequency": 10000000 }
Medición del rendimiento del método utilizado por la biblioteca.
Para medir el rendimiento del método público de la clase pública de la biblioteca de terceros utilizada, debe establecer explícitamente la propia clase y su nombre de método:
[HttpGet("GetThreadSleepPerformance")] public ActionResult<string> GetThreadSleepPerformance() { using (PerformanceMeter<Thread>.WatchingMethod(nameof(Thread.Sleep)).Start()) { Thread.Sleep(1000); } return Ok(PerformanceMeter<Thread>.PerformanceInfo.MethodCalls.FirstOrDefault(ta => ta.MethodName == nameof(Thread.Sleep))?.Elapsed); }
El método ejecutado devolverá:
"00:00:01.0033040"
Puede obtener datos sobre cómo llamar a este método a través de una llamada:
/// <summary> /// Get methods performance info for Thread class. /// </summary> /// <returns>Returns Thread methods performance info.</returns> [HttpGet("GetThreadPerformanceInfo")] [IgnoreMethodPerformance] public ActionResult<IPerformanceInfo> GetThreadPerformanceInfo() { return Ok(PerformanceMeter<Thread>.PerformanceInfo); }
El atributo IgnoreMethodPerformance
diseñado para que el método que IgnoreMethodPerformance
no se tenga en cuenta al medir el rendimiento.
En respuesta a la llamada a este método será:
{ "methodCalls": [ { "methodName": "Sleep", "elapsed": "00:00:01.0033040", "caller": "unknown", "startTime": "2019-12-06T13:08:09.336624Z", "endTime": "2019-12-06T13:08:10.339928Z", "customData": {}, "steps": [] } ], "totalActivity": [ { "methodName": "Abort", "callsCount": 0 }, // ... { "methodName": "Sleep", "callsCount": 1 } // ... ], "currentActivity": [ { "methodName": "Abort", "callsCount": 0 }, // ... { "methodName": "Sleep", "callsCount": 1 } // ... ], "uptimeSince": "2019-12-06T13:08:09.3357028Z", "className": "System.Threading.Thread", "methodNames": [ "Abort", // ... "Sleep", // ... ], "customData": {}, "timerFrequency": 10000000 }
Agregar datos adicionales (datos personalizados) y paginación (pasos)
Puede agregar datos adicionales (Datos personalizados) para todas las mediciones de rendimiento de los métodos de una clase en particular. Por ejemplo, en el constructor estático de la clase de controlador PerformanceMeterController
:
[ApiController] [Route("api/v1/[controller]")] public class PerformanceMeterController : ControllerBase { /// <summary> /// Static constructor. /// </summary> static PerformanceMeterController() { // add common custom data (string) to class performance information PerformanceMeter<PerformanceMeterController>.AddCustomData("Tag", "CustomTag"); // add common custom data (anonymous class) to class performance information PerformanceMeter<PerformanceMeterController>.AddCustomData("Custom anonymous class", new { Name = "Custom Name", Value = 1 }); } // ... actions }
Además, puede agregar datos adicionales (Datos personalizados) para una medición específica utilizando el método de extensión .WithSettingData.CustomData("<key>", <value>)
(incluso a través de un atributo especial del método MethodCustomDataAttribute
) y para cada paso (Paso ) de esta medida, agregada usando el .Step("<step_name>")
extensión .Step("<step_name>")
, usando el .AddCustomData("<key>", <value>)
extensión .AddCustomData("<key>", <value>)
:
/// <summary> /// Test GET method with simple performance watching (with steps). /// </summary> [HttpGet("SimpleStartWatchingWithSteps")] [MethodCustomData("Custom data from attribute", "Attr")] public ActionResult SimpleStartWatchingWithSteps() { using (var pm = PerformanceMeter<PerformanceMeterController> .WatchingMethod() .WithSettingData .CustomData("coins", 1) .CustomData("Coins sets", new { Gold = "Many", Silver = 5 }) .Start()) { // put your code with some logic here // add "Step 1" using (pm.Step("Step 1")) { Thread.Sleep(1000); } // add "Step 2" with custom data using (var pmStep = pm.Step("Step 2").AddCustomData("step2 custom data", "data!")) { // add "Step 3 in Step 2" using (pm.Step("Step 3 in Step 2")) { Thread.Sleep(1000); } // add custom data to "Step 2" pmStep.AddCustomData("step2 another custom data", "data2!"); // get and remove custom data from "Step 2" var customData = pmStep.GetAndRemoveCustomData<string>("step2 custom data"); // get custom data from "Step 2" (without removing) var anotherCustomData = pmStep.GetCustomData<string>("step2 another custom data"); // ... } } }
Como resultado, al llamar a GetPerformanceInfo
obtenemos:
{ "methodCalls": [ { "methodName": "SimpleStartWatchingWithSteps", "elapsed": "00:00:02.0083031", "caller": "unknown", "startTime": "2019-12-06T11:58:18.9006891Z", "endTime": "2019-12-06T11:58:20.9089922Z", "customData": { "Coins sets": { "gold": "Many", "silver": 5 }, "coins": 1, "Custom data from attribute": "Attr" }, "steps": [ { "stepName": "Step 1", "elapsed": "00:00:01.0009758", "startTime": "2019-12-06T11:58:18.9018272Z", "endTime": "2019-12-06T11:58:19.902803Z", "customData": {} }, { "stepName": "Step 3 in Step 2", "elapsed": "00:00:01.0004549", "startTime": "2019-12-06T11:58:19.9046523Z", "endTime": "2019-12-06T11:58:20.9051072Z", "customData": {} }, { "stepName": "Step 2", "elapsed": "00:00:01.0029596", "startTime": "2019-12-06T11:58:19.904534Z", "endTime": "2019-12-06T11:58:20.9074936Z", "customData": { "step2 another custom data": "data2!" } } ] } ], "totalActivity": [ { "methodName": "SimpleStartWatchingWithSteps", "callsCount": 1 } ], "currentActivity": [ { "methodName": "SimpleStartWatchingWithSteps", "callsCount": 0 } ], "uptimeSince": "2019-12-06T11:58:18.8801249Z", "className": "Unchase.FluentPerformanceMeter.TestWebAPI.Controllers.PerformanceMeterController", "methodNames": [ "SimpleStartWatchingWithSteps" ], "customData": { "Tag": "CustomTag", "Custom anonymous class": { "name": "Custom Name", "value": 1 } }, "timerFrequency": 10000000 }
Excepción de la medición (Ignorar)
Puede ignorar las partes individuales del método para medir el rendimiento (usando .Ignore()
o .Executing().WithoutWatching().Start(<Action>)
), y tampoco guardar pasos individuales (método de extensión .StepIf("<step_name>", <minSaveMs>)
) si no satisfacen la condición (el tiempo de ejecución del paso se tendrá en cuenta en el tiempo de ejecución del método):
using (var pm = PerformanceMeter<PerformanceMeterController>.WatchingMethod().Start()) { // put your code with some logic here // sleep 1 sec Thread.Sleep(1000); // ignore this block in performance watching using (pm.Ignore()) { Thread.Sleep(5000); } // skip this step with minSaveMs (not save, but consider duration in method performance watching) using (pm.StepIf("Skipped step", minSaveMs: 1000)) { Thread.Sleep(500); } // execute action without performance watching pm.Executing().WithoutWatching().Start(() => { Thread.Sleep(2000); }); return Ok(); }
Como resultado, obtenemos:
{ "methodCalls": [ { "methodName": "SimpleStartWatchingWithIgnored", "elapsed": "00:00:01.5080227", "caller": "unknown", "startTime": "2019-12-06T12:34:36.9187359Z", "endTime": "2019-12-06T12:34:38.4267586Z", "customData": {}, "steps": [] } ], "totalActivity": [ { "methodName": "SimpleStartWatchingWithIgnored", "callsCount": 1 } ], "currentActivity": [ { "methodName": "SimpleStartWatchingWithIgnored", "callsCount": 0 } ], "uptimeSince": "2019-12-06T12:34:36.9035129Z", "className": "Unchase.FluentPerformanceMeter.TestWebAPI.Controllers.PerformanceMeterController", "methodNames": [ "SimpleStartWatchingWithIgnored" ], "customData": { }, "timerFrequency": 10000000 }
Agregar comandos y acciones
Para agregar un comando que se garantizará que se ejecute al finalizar la medición del rendimiento de un método, debe crear una clase de comando que implemente la interfaz IPerformanceCommand
.
Al mismo tiempo, puede transferir datos arbitrarios a través del constructor del comando creado que se utilizará durante su ejecución. Por ejemplo:
/// <summary> /// Custom executed command. /// </summary> public class ExecutedCommand : IPerformanceCommand { /// <summary> /// Executed commad name. /// </summary> public string CommandName => this.GetType().Name; private string _customString { get; } internal bool IsCommandExecuted { get; private set; } /// <summary> /// Constructor. /// </summary> /// <remarks> /// You can pass any data through the command constructor. /// </remarks> /// <param name="customString"></param> public ExecutedCommand(string customString) { this._customString = customString; } /// <summary> /// Execute command. /// </summary> /// <param name="performanceInfo"><see cref="IPerformanceInfo"/>.</param> public void Execute(IPerformanceInfo performanceInfo) { // for example, write to the debug console some information Debug.WriteLine(this.CommandName); Debug.WriteLine(this._customString); Debug.WriteLine($"Method names count: {performanceInfo.MethodNames.Count}"); this.IsCommandExecuted = true; } }
Puede agregar un comando (IPerformanceCommand) y una acción (Acción) para que se ejecuten al final de la medición, de la siguiente manera:
// custom "ExecutedCommand" will be executed after performance watching is completed using (PerformanceMeter<PerformanceMeterController> .WatchingMethod() .WithExecutingOnComplete .Command(new ExecutedCommand("bla-bla-bla")) .Action((pi) => { Debug.WriteLine($"Class name: {pi.ClassName}"); }) .Start()) { return Ok(); }
Como resultado, al final de medir el rendimiento del método en la consola de depuración , mostrará:
ExecutedCommand bla-bla-bla Method names count: 13 Class name: Unchase.FluentPerformanceMeter.TestWebAPI.Controllers.PerformanceMeterController
Agregar controladores de excepciones
Si necesita manejar las excepciones que pueden ocurrir durante la ejecución de una parte del método para el cual se monitorea el rendimiento, debe agregar un controlador de excepciones de la siguiente manera:
using (var pm = PerformanceMeter<PerformanceMeterController>.StartWatching()) { // execute action throws Exception with exception handler pm.Executing() .WithExceptionHandler((ex) => Debug.WriteLine(ex.Message)) .Start(() => throw new Exception("Exception")); // execute action throws custom Exception with exception handler pm.Executing<CustomException>() .WithExceptionHandler((ex) => { Debug.WriteLine(ex.Message); }) .Start(() => { throw new CustomException("Custom exception was occured!"); }); return Ok(); }
¿Dónde está la clase CustomException
, por ejemplo:
/// <summary> /// Custom exception. /// </summary> public class CustomException : Exception { public CustomException(string message) : base(message) { } public CustomException(string message, Exception innerException) : base(message, innerException) { } public CustomException() { } }
Como resultado, la consola de depuración mostrará:
Exception Custom exception was occured!
Además, puede especificar un controlador de excepciones que se usará de manera predeterminada para medir el rendimiento de cualquier método de esta clase, por ejemplo, a través del constructor estático de la clase de controlador PerformanceMeterController
:
[ApiController] [Route("api/v1/[controller]")] public class PerformanceMeterController : ControllerBase { /// <summary> /// Static constructor. /// </summary> static PerformanceMeterController() { // set default exception handler for PerformanceMeterController class PerformanceMeter<PerformanceMeterController>.SetDefaultExceptionHandler((ex) => Debug.WriteLine(ex.Message)); } // ... actions }
Configuración del tiempo de almacenamiento de datos (Establecer tiempo de caché)
Puede establecer el tiempo de almacenamiento para los datos de las mediciones de rendimiento de los métodos, después de lo cual se eliminarán estos datos. Para cada clase para la que se realiza la medición, este tiempo se establece por separado. Por ejemplo, el tiempo se puede establecer a través del constructor estático de la clase de controlador PerformanceMeterController
:
[ApiController] [Route("api/v1/[controller]")] public class PerformanceMeterController : ControllerBase { /// <summary> /// Static constructor. /// </summary> static PerformanceMeterController() { // set cache time for PerformanceMeterController class PerformanceMeter<PerformanceMeterController>.SetMethodCallsCacheTime(5); } // ... actions }
Agregar datos sobre el método de llamada y el lugar de la llamada (e interrumpir la medición del rendimiento)
Puede especificar quién llama al método utilizando el método de extensión .CallerFrom("<caller_name>")
( se le pasa una cadena o IHttpContextAccessor ) o un atributo especial del método [MethodCaller("<caller_name>")]
. Además, si se utilizan tanto el atributo como el método de extensión, entonces el valor se tomará de este último.
El método de extensión .WithSettingData.CallerSourceData()
usa para agregar un punto de llamada para medir el rendimiento.
Para dejar de medir el rendimiento dentro del bloque de uso, use el método de extensión .StopWatching()
o el método Dispose()
directamente:
[HttpPost("StartWatchingWithCallerName")] [MethodCaller("testCaller")] public ActionResult<string> StartWatchingWithCallerName([FromBody] string value) { // method performance info will reach with caller name (if internal HttpContextAccessor is null) using (var pm = PerformanceMeter<PerformanceMeterController> .WatchingMethod() .WithSettingData .CallerSourceData() .CallerFrom("Test caller") .Start()) { pm.StopWatching(); // stop watching here (or you can use "pm.Dispose();") Thread.Sleep(2000); return Ok(value); } }
Como resultado de llamar al método GetPerformanceInfo
, obtendrá:
{ "methodCalls": [ { "methodName": "StartWatchingWithCallerName", "elapsed": "00:00:00.0019172", "caller": "Test caller", "startTime": "2019-12-06T13:35:45.3164507Z", "endTime": "2019-12-06T13:35:45.3183679Z", "customData": { "customData123": 123, "callerSourceLineNumber": 525, "callerSource": "D:\\GitHub\\Unchase.FluentPerformanceMeter\\Unchase.FluentPerformanceMeter.TestWebAPI\\Controllers\\PerformanceMeterController.cs" }, "steps": [] } ], "totalActivity": [ { "methodName": "StartWatchingWithCallerName", "callsCount": 1 } ], "currentActivity": [ { "methodName": "StartWatchingWithCallerName", "callsCount": 0 } ], "uptimeSince": "2019-12-06T13:35:45.2601668Z", "className": "Unchase.FluentPerformanceMeter.TestWebAPI.Controllers.PerformanceMeterController", "methodNames": [ "StartWatchingWithCallerName" ], "customData": { }, "timerFrequency": 10000000 }
Conclusión
Por lo tanto, la solución presentada nos permite automatizar parcialmente la recopilación de información sobre el rendimiento de los métodos de aplicación .NET de una manera bastante conveniente. Los datos recopilados se pueden visualizar de una manera que sea más adecuada para cada desarrollador específico.
Por supuesto, la biblioteca no resuelve todos los problemas asociados con la recopilación de datos sobre el rendimiento de los métodos, pero busca simplificar los más comunes.
La biblioteca es una solución de código abierto, cualquier sugerencia y sugerencia para su desarrollo es bienvenida, al igual que los informes de errores (todos pueden seguir el enlace ; ¡el autor agradecerá cualquier ayuda!).