Recently, I worked with one of the customer who wanted assistance in implementing the logging and capturing the perfview traces for aspnet core web application.
So, I decided to blog on this topic and explain how to enable the logging, capture and analyze perfview trace.
I am making use of a simple ASPNET Core MVC application here to explain this.
I have the below lines in my Program.cs file:
| static void Main(string[] args)
{ BuildWebHost(args).Run(); } public static IWebHost BuildWebHost(string[] args) => WebHost.CreateDefaultBuilder(args) .CaptureStartupErrors(true) // THE ABOVE LINE IS FOR THE STARTUP RELATED ISSUES .UseSetting(WebHostDefaults.DetailedErrorsKey,"true") //THE ABOVE LINE WILL GIVE A DETAILED ERROR PAGE IN CASE OF ANY FAILURE .UseStartup<Startup>() .UseKestrel() .ConfigureLogging((hostingContext,logging)=> { logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging")); logging.AddConsole(); //THE ABOVE LINE WILL DISPLAY THE LOGS IN CONSOLE WHILE RUNNING THE APP FROM THE CMD LINE logging.AddDebug(); //THE ABOVE LINE WILL DISPLAY THE LOGS IN DEBUG OUTPUT WINDOW logging.AddEventSourceLogger(); //THE ABOVE LINE IS FOR THE PERFVIEW }) .Build(); |
Ensure that you have placed the below namespaces within your Program.cs
using Microsoft.AspNetCore.Hosting;
using Microsoft.Extensions.Logging;
using Microsoft.AspNetCore;
You can make use of the Nuget PM to install the Microsoft.Extensions.Logging component.
Go to your concerned Controller and ensure that you have referenced the logging component
| public class HomeController : Controller { // GET: /<controller>/
private readonly ILogger _logger; public HomeController(ILogger<HomeController> logger) { _logger = logger; } public IActionResult Index() { // This code specifies the loglevel. // Ex: LogInformation, LogWarning, LogCritical, LogDebug etc _logger.LogInformation(1000, "In Index method.............."); return View(); } } |
Ensure that you have placed the below namespaces within your Controller:
using Microsoft.AspNetCore.Mvc;
using Microsoft.Extensions.Logging;
After doing the above changes, you will see the Logging information within your Debug Output window and the CMD console.
In the Debug window:
| Microsoft.AspNetCore.Hosting.Internal.WebHost:Information: Request starting HTTP/1.1 GET http://localhost:5761/home/index Microsoft.AspNetCore.Hosting.Internal.WebHost:Information: Request starting HTTP/1.1 GET http://localhost:5761/home/index ------------------------------------
Demo.Controllers.HomeController:Information: In Index method.............. Demo.Controllers.HomeController:Information: In Index method.............. |
In the CMD console:
| info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1] Request starting HTTP/1.1 GET http://localhost:5762/home/index info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
Request starting HTTP/1.1 GET http://localhost:5762/home/index info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1] Executing action method Demo.Controllers.HomeController.Index (Demo) with arguments ((null)) - ModelState is Valid info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1] Executing action method Demo.Controllers.HomeController.Index (Demo) with arguments ((null)) - ModelState is Valid infoinfo: Demo.Controllers.HomeController[1000] In Index method.............. : Demo.Controllers.HomeController[1000] In Index method.............. info: Microsoft.AspNetCore.Mvc.ViewFeatures.Internal.ViewResultExecutor[1] Executing ViewResult, running view at path /Views/Home/Index.cshtml. info: Microsoft.AspNetCore.Mvc.ViewFeatures.Internal.ViewResultExecutor[1] Executing ViewResult, running view at path /Views/Home/Index.cshtml. info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2] Executed action Demo.Controllers.HomeController.Index (Demo) in 4628.1449ms info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2] Executed action Demo.Controllers.HomeController.Index (Demo) in 4628.1449ms info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2] Request finished in 4686.3757ms 200 text/html; charset=utf-8 info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2] Request finished in 4686.3757ms 200 text/html; charset=utf-8 |
Perfview Data Collection:
Download the Perfview from the below location and place it on the machine where you have the ASPNET Core app running:
https://www.microsoft.com/en-us/download/details.aspx?id=28567
Data Capture:
- Open Perfview.
- Go to Collect and select Collect option as shown below:
- Expand the Advanced Options.
- Enable the Thread Time and IIS providers. (This will help us give some additional Information while troubleshooting) Note: IIS provider is needed if the app is hosted on IIS. Else you can skip it. This provider can be used only if the IIS Tracing feature is installed.
- Place the *Microsoft-Extensions-Logging section within Additional Providers section as shown below:
Perfview Analysis:
After we open the perfview ETL trace we see our logging information being logged:
| Event Name | Time MSec | Process Name | Rest |
| Microsoft-Extensions-Logging/FormattedMessage | 39,706.201 | dotnet (25292) | ThreadID="285,016" Level="2" FactoryID="1" LoggerName="Demo.Controllers.HomeController" EventId="1000" FormattedMessage="In Index method.............." ActivityID="//1/3/1/" |
| Microsoft-Extensions-Logging/Message | 39,708.668 | dotnet (25292) | ThreadID="285,016" Level="2" FactoryID="1" LoggerName="Demo.Controllers.HomeController" EventId="1000" Exception="{ TypeName="", Message="", HResult=0, VerboseMessage="" }" Arguments="[{ Key="{OriginalFormat}", Value="In Index method.............." }]" ActivityID="//1/3/1/" |
| Microsoft-Extensions-Logging/MessageJson | 39,708.700 | dotnet (25292) | ThreadID="285,016" Level="2" FactoryID="1" LoggerName="Demo.Controllers.HomeController" EventId="1000" ExceptionJson="{}" ArgumentsJson="{"{OriginalFormat}":
"In Index method.............."}" ActivityID="//1/3/1/" |
Hope this helps :)
Author: Naveen Baliga