Runtime Loader advanced event view by davidwrighton · Pull Request #1232 · microsoft/perfview

davidwrighton · 2020-07-20T20:56:57Z

Add support for viewing various when various runtime load operations occur during process execution. This is a view much like jit stats, but somewhat more flexible and less specialized to just the JIT.

Events visible are

JIT
R2R
Assembly load
Type load (When the runtime accepts pr Add events around type load and r2r usage dotnet/runtime#39656)

The view is presented linearly per thread, and can be shown nested or not (nested allows understanding of which operations occur as a result of other operations)

In addition, which events are shown is configurable via checkbox.

davidwrighton · 2020-07-20T20:57:26Z

@BILLwer @brianrob Could one of you review this?

brianrob · 2020-07-21T00:59:13Z

Yes, I will take a look @davidwrighton.

brianrob · 2020-07-21T21:40:42Z

src/PerfViewCollect/PerfViewCollect.csproj

    <Compile Include="..\PerfView\ClrStats.cs" />
    <Compile Include="..\PerfView\GcStats.cs" />
    <Compile Include="..\PerfView\JitStats.cs" />
+    <Compile Include="..\PerfView\RuntimeLoaderStats.cs" />


Are you wanting to enable this via the PerfViewCollect tool?

Eventually... yes. But for now, I'm settling for it just building cleanly. This change was required for that. The rest of these changes, are VS doing something I didn't want.

brianrob · 2020-07-21T21:41:04Z

src/PerfViewCollect/PerfViewCollect.csproj


  <ItemGroup>
    <PackageReference Include="Microsoft.Diagnostics.Tracing.TraceEvent.SupportFiles" Version="$(MicrosoftDiagnosticsTracingTraceEventSupportFilesVersion)" />
-    <PackageReference Include="Microsoft.SourceLink.GitHub" Version="1.0.0-beta-63127-02" PrivateAssets="All"/>


It looks like there is a bunch of whitespace change here. Can you revert these please? Let me know if I missed an actual change here.

brianrob · 2020-07-21T21:42:38Z

src/PerfView/SupportFiles/HtmlReportUsersGuide.htm

+        To enable data about all loader operations set the ".NET Loader" checkbox when collecting data.
+        Otherwise, the data captured will be restricted to JIT and assembly load operations. The /RuntimeLoading switch may also be used.
+
+        Also see the Runtime Loader stacks view, which ties this data into a view of CPU activity, to allow investigating CPU usage during specific loader operations.


Thanks for adding help for this. Can you also add a note that this only works on .NET Core (assuming we're not porting this to desktop)?

It actually works to some extent on desktop. You can see JIT and assembly load events there.

brianrob · 2020-07-21T22:18:00Z

src/PerfView/Dialogs/RunCommandDialog.xaml


-                    <CheckBox Grid.Row="0" Grid.Column="13" Name="Unused2" Visibility="Hidden" VerticalAlignment="Center"/>
+                    <TextBlock Grid.Row="0" Grid.Column="12" VerticalAlignment="Center" HorizontalAlignment="Right" Margin="8,2,5,2" 
+                               ToolTip="Log information about .NET Runtime loading." >


It might be good to disambiguate this a bit in the tooltip to be clear that this is for more than just assembly loading, but also type loading, method loading, etc.

brianrob · 2020-07-21T22:21:59Z

src/PerfView/RuntimeLoaderStats.cs

+
+            foreach (var proc in runtimeOps.EventSource.TraceLog.Processes)
+            {
+                if (proc.ProcessID == incompleteStatsProc.ProcessID)


There are a couple of ways that you can match processes, while handing the fact that process IDs can be re-used. One is to use TraceProcess.ProcessIndex, which is a unique value across the entire trace. The second is to use ProcessID and timestamp, and find the closest match - TraceLog.Processes has an API for this. If you leave this as is, it's possible that PID re-use will impact the results here.

In RuntimeLoaderStats.cs, you are using Microsoft.Diagnostics.Tracing.Etlx.TraceProcess, but here you're using Microsoft.Diagnostics.Tracing.Analysis.TraceProcess. They are slightly different. The first is layered on top of TraceLog, while this one is a level lower at TraceEventSource. Since you already require Etlx.TraceProcess, I'd recommend just using that everywhere, and then you can use ProcessIndex rather than PID.

In reply to: 458422874 [](ancestors = 458422874)

brianrob · 2020-07-21T22:22:27Z

src/PerfView/RuntimeLoaderStats.cs

+
+            foreach (var proc in runtimeOps.EventSource.TraceLog.Processes)
+            {
+                if (proc.ProcessID == incompleteStatsProc.ProcessID)


Same PID re-use issue here.

brianrob · 2020-07-21T22:27:50Z

src/PerfView/PerfViewData.cs


            advanced.Children.Add(new PerfViewJitStats(this));
-
+            advanced.Children.Add(new PerfViewRuntimeLoaderStats(this));


Can you condition this on having enough data in the trace to show something? You're just looking for the specific types of events that you need. We do this so that there aren't views that don't show anything.

brianrob

Thanks for submitting this @davidwrighton. Overall looks good - some comments and recommendations. Also, can you share a trace that you've captured with these events? I'm interested to see the view in action.

brianrob · 2020-07-21T22:33:57Z

src/TraceEvent/Computers/CLRRuntimeActivityComputer.cs

+            source.Clr.LoaderTypeLoadStart += Clr_LoaderTypeLoadStart;
+            source.Clr.LoaderTypeLoadStop += Clr_LoaderTypeLoadStop;
+            source.Process();
+            source.Clr.MethodJittingStarted -= Clr_MethodJittingStarted;


You should not need to unsubscribe these delegates. The pattern used is to provide a fresh EventSource so that you are sure that other machinery isn't subscribed if you are concerned about this. I don't think you'll find many, if any, places in where we attempt to unsubscribe in order to re-use the EventSource.

…instead of inscrutqable commands.

…manner

…instead of inscrutqable commands.

…ctored stats page

Add support for generating csv as well as txt and make output generally acceptable to excel

- Consistently use the Microsoft.Diagnostics.Tracing.Analysis.TraceProcess - Refactor CLRRuntimeActivityComputer to be more pluggable into the existing Process once model - Only display view when it has data - Properly segregate process local data and handle process id reuse

- Update help text and documentation to be more accurate

davidwrighton · 2020-08-12T21:38:48Z

@brianrob I've addressed all of the feedback you've given me. As it turns out it was more difficult to consolidate on using the Etlx TraceProcess, so instead I consolidated on working with the Analysis TraceProcess, and some modestly dodgy logic involving pids and timestamps.

brianrob

LGTM. Thanks!

brianrob reviewed Jul 21, 2020

View reviewed changes

davidwrighton mentioned this pull request Jul 23, 2020

ReadyToRun images are not as efficient for .NET Core 3 as NGen for .NET Framework dotnet/runtime#13339

Open

davidwrighton added 14 commits August 11, 2020 18:31

It buidls but doesn't work

fd385d6

Make it work and progress towards capturing R2R data with a checkbox …

99a082c

…instead of inscrutqable commands.

Add support for displaying runtime operations data in a hierarchical …

883308a

…manner

R2R data successfully captured, and obvious fixes applied

4c62638

Make it work and progress towards capturing R2R data with a checkbox …

b1a21d6

…instead of inscrutqable commands.

AddSupportForExaminingTypeLoadOperations

7bc4c9e

Remove non-functioning StartStopMingledComputer in favor of better fa…

b669d1b

…ctored stats page

Provide control over what events are visible, and cleanup codebase

0c79248

Fix naming so that tests pass

0c9a16c

Add support for generating csv as well as txt and make output generally acceptable to excel

Cleanup Csv output so that jitted functions reliably are displayed

ae92616

Address changes to event suggested by code review in runtime repo

fb80753

Use updates task/opcodes for TypeLoad events

91f525a

- Do not show incorrect exclusive time data in non-tree view

48b4d15

- Update help text and documentation to be more accurate

davidwrighton force-pushed the runtimeops_v2 branch from ec3b44c to 48b4d15 Compare August 12, 2020 21:36

brianrob approved these changes Aug 21, 2020

View reviewed changes

brianrob merged commit b33df66 into microsoft:master Aug 21, 2020


		advanced.Children.Add(new PerfViewJitStats(this));

		advanced.Children.Add(new PerfViewRuntimeLoaderStats(this));

Conversation

davidwrighton commented Jul 20, 2020

Uh oh!

davidwrighton commented Jul 20, 2020

Uh oh!

brianrob commented Jul 21, 2020

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

brianrob Jul 21, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

brianrob left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

davidwrighton commented Aug 12, 2020

Uh oh!

brianrob left a comment

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

brianrob Jul 21, 2020 •

edited

Loading