microsoft / perfview

PerfView is a CPU and memory performance-analysis tool
http://channel9.msdn.com/Series/PerfView-Tutorial
MIT License
4.14k stars 707 forks source link

Add ASP.NET Core Stats view #2001

Closed mahamr closed 5 months ago

mahamr commented 7 months ago

This PR adds the ASP.NET Core Stats view to the "Advanced" folder (placement was based on where the current IIS Stats and ASP.NET Stats views are located, but can definitely be changed). At the moment it relies on the presence of Microsoft.AspNetCore.Hosting events, such as Request/Start and Request/Stop. This view is added for both regular ETL files, as well as EventPipe files - it's only built/generated in one place so it looks the same from either type of dataset.

While right now it only consumes those Hosting events, the goal for future output is to be able to consume Microsoft.Extensions.Logging events as well to supplement output, or even base the calculations on those events instead of Hosting (say, when Hosting events aren't available but ILogger events are). Another possibility is using DiagnosticSource events if available, such as the Activity Start/Stop events that correspond to Hosting events. One benefit to those latter events, if available, is those contain the status code of the response, whereas the regular Hosting's Request/Stop events do not.

I was using the IIS Stats view as reference output here, although, one feature I have not currently implemented is the ability to open the Events view and feed it specific ActivityIDs like what IIS Stats does in the Slow Requests section. I did try this initially but the opening of the Events window in IIS Stats view seems to have been built specifically for ETL files, and it didn't work for EventPipe files. The PR code does contain some remnants of this testing in the PerfViewAspNetCoreStats.DoCommand method, but right now nothing triggers DoCommand. This is something I hope to fix sometime soon in the near-ish future, as it would be useful to have IMO.

In a PerfView-captured and compressed file, here's how it's surfaced when the Hosting events are present: image

And in a dotnet-trace EventPipe file: image

Some example output: image image

A bit more complex output with multiple processes emitting events: image

brianrob commented 7 months ago

FYI @davidfowl

mahamr commented 7 months ago

Also, this looks like it will work with events that are emitted via nettrace, so we should add this to the nettrace path as well.

Thanks @brianrob! This part should be done already in the submitted code unless there's something I missed - check the stuff in EventPipePerfViewData.

brianrob commented 7 months ago

Also, this looks like it will work with events that are emitted via nettrace, so we should add this to the nettrace path as well.

Thanks @brianrob! This part should be done already in the submitted code unless there's something I missed - check the stuff in EventPipePerfViewData.

You're right - I missed that this was done for ETW and EventPipe. Thanks!

mahamr commented 6 months ago

Pushing a commit soon with lots of changes to add more output, as well changes to address requests and concerns so far.

Some updated screenshots are below.

Incomplete requests (1 each where the request was started before the trace but ended during the trace, and another where the trace captures a request start but not the end): image

full page of a bit more complex output with multiple processes and some slow requests: image

and another: image

mahamr commented 6 months ago

added a quick/small commit to prevent EventCounters events from spamming the "General Events" section

mahamr commented 6 months ago

@brianrob I noticed when opening a trace and opening this stats view, then closing it and reopening it, the WriteHtmlBody is run again causing the main data structures to be populated with a second set of events, doubling everything. If closed and reopened again, a new/third set is added, etc. etc. I notice the PerfViewAspNetStats view declares the main m_requests data structure within its WriteHtmlBody method, effectively doing all the work again:

   public class PerfViewAspNetStats : PerfViewHtmlReport
   {
       public PerfViewAspNetStats(PerfViewFile dataFile) : base(dataFile, "Asp.Net Stats") { }
       protected override void WriteHtmlBody(TraceLog dataFile, TextWriter writer, string fileName, TextWriter log)
       {
           var dispatcher = dataFile.Events.GetSource();
           var aspNet = new AspNetTraceEventParser(dispatcher);

           m_requests = new List<AspNetRequest>();

What's the best way to approach this in the new view? Should I do the same thing and just re-process everything? Or perhaps set a flag that is used to check whether WriteHtmlBody has already run and skip the trace processing part if so? Or is there some other better solution?

Here's what happens right now, first run: image

Then close the view and reopen it: image

and so on

Thanks!

mahamr commented 6 months ago

I'll work on those this week - thanks! There's one other issue I brought up before that I'd like to get your thoughts on the best way to fix: https://github.com/microsoft/perfview/pull/2001#issuecomment-1998507979

Thanks!

brianrob commented 6 months ago

I'll work on those this week - thanks! There's one other issue I brought up before that I'd like to get your thoughts on the best way to fix: #2001 (comment)

Thanks!

Ah, sorry, I missed that one. There are a couple of patterns that get employed here, but the most common one is just to re-process all of the data for each invocation of the report. This is what I would recommend that you do.

You'll also see that some of the subcommands will cache their files. Here's an example: https://github.com/microsoft/perfview/blob/main/src/PerfView/PerfViewData.cs#L3679. This could be done with the html file as well, but given that none of them do this as far as I can tell, feel free to follow the pattern, and perhaps at some point, we'll fix this for all.

mahamr commented 6 months ago

Hey @brianrob also, any comment on the location of the view? This was mentioned as something to discuss previously. Right now it's in the Advanced view for both ETL (next to IIS and regular ASP.NET stats view) and EventPipe traces -- is this appropriate or should it be changed?

brianrob commented 5 months ago

Hey @brianrob also, any comment on the location of the view? This was mentioned as something to discuss previously. Right now it's in the Advanced view for both ETL (next to IIS and regular ASP.NET stats view) and EventPipe traces -- is this appropriate or should it be changed?

Thanks for checking. I think Advanced is fine for now. I can see about organization of the Advanced group separately.

mahamr commented 5 months ago

@brianrob I believe everything has been addressed, including the merge conflict that existed. I do have continued plans to add to this view some enhancements, but where it's at I feel is a good v1. Let me know if there's anything else you'd like to see here - thanks!