Skip to content

Commit eae6d50

Browse files
lzybkrTravisEz13
lzybkr
authored and
TravisEz13
committed
Add tools for PowerShell perf analysis (#7595)
1 parent 087de5b commit eae6d50

9 files changed

Lines changed: 1040 additions & 0 deletions

‎.spelling‎

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1096,3 +1096,20 @@ interactivetesting
10961096
allowprerelease
10971097
prereleases
10981098
url
1099+
- tools/performance/README.md
1100+
analyze
1101+
wpa
1102+
wpaProfile
1103+
PerfView
1104+
etl
1105+
perfview
1106+
wpr
1107+
wprui.exe
1108+
perfview.exe
1109+
GC.Regions.xml
1110+
JIT.Regions.xml
1111+
PowerShell.Regions.xml
1112+
PowerShell.stacktags
1113+
PowerShell.wpaProfile
1114+
PowerShell.wprp
1115+
Invoke-PerfviewPS

‎tools/performance/GC.Regions.xml‎

Lines changed: 106 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,106 @@
1+
<?xml version='1.0' encoding='utf-8' standalone='yes'?>
2+
<!-- See definitions in C:\Windows\Microsoft.NET\Framework\v4.0.30319\CLR-ETW.man for .NET events -->
3+
<!--
4+
Unlike JIT GC is largely single threaded and the times correlate very well with PerfView where we can drill down into each GC
5+
generation in the region graph in WPA.
6+
We use bascially the GC Start/Stop events where the GC Start event has also the generation traced which enables us to create
7+
regions for each GC type.
8+
GC suspensions work a bit different were I use the GCSuspendEE_V1 as start and GCRestartEEEnd as end event. This allows us
9+
to capture in principle also the time where the suspension or resumption itself takes an abnormally long time whic would indicate
10+
a GC bug or a thread priority problem.
11+
-->
12+
<InstrumentationManifest>
13+
<Instrumentation>
14+
<Regions>
15+
<RegionRoot Guid="{d8d639a0-cf4c-45fb-976a-0000DEADBEEF}" Name="GC" FriendlyName="GC Activity">
16+
<Region Guid="{d8d639a1-cf4c-45fb-976a-100000000101}" Name="Gen 0" FriendlyName="GCs">
17+
<Region Guid="{d8d639a1-cf4c-45fb-976a-000000000001}" Name="Gen 0" FriendlyName="Gen 0">
18+
<Start>
19+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="1"/>
20+
<PayloadIdentifier FieldName="Depth" FieldValue="0"/>
21+
<!-- Depth is the Generation number -->
22+
</Start>
23+
<Start>
24+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="2"/>
25+
<!-- .NET 4.6 has a new GC Start event -->
26+
<PayloadIdentifier FieldName="Depth" FieldValue="0"/>
27+
</Start>
28+
29+
<Stop>
30+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="2" Version="1"/>
31+
</Stop>
32+
<Match>
33+
<Event PID="true"/>
34+
</Match>
35+
<Naming>
36+
<PayloadBased NameField="Depth"/>
37+
</Naming>
38+
</Region>
39+
</Region>
40+
41+
<Region Guid="{d8d639a1-cf4c-45fb-976b-100000000101}" Name="Gen 1" FriendlyName="GCs">
42+
<Region Guid="{d8d639a1-cf4c-45fb-976a-000000000005}" Name="Gen 1" FriendlyName="Gen 1">
43+
<Start>
44+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="1"/>
45+
<PayloadIdentifier FieldName="Depth" FieldValue="1"/>
46+
</Start>
47+
<Start>
48+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="2"/>
49+
<!-- .NET 4.6 has a new GC Start event -->
50+
<PayloadIdentifier FieldName="Depth" FieldValue="1"/>
51+
</Start>
52+
53+
<Stop>
54+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="2" Version="1"/>
55+
</Stop>
56+
<Match>
57+
<Event PID="true"/>
58+
</Match>
59+
<Naming>
60+
<PayloadBased NameField="Depth"/>
61+
</Naming>
62+
</Region>
63+
</Region>
64+
65+
<Region Guid="{d8d639a1-cf4c-45fb-976c-100000000101}" Name="Gen 2" FriendlyName="GCs">
66+
<Region Guid="{d8d639a1-cf4c-45fb-976a-000000000006}" Name="Gen 2" FriendlyName="Gen 2">
67+
<Start>
68+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="1"/>
69+
<PayloadIdentifier FieldName="Depth" FieldValue="2"/>
70+
</Start>
71+
<Start>
72+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="2"/>
73+
<!-- .NET 4.6 has a new GC Start event -->
74+
<PayloadIdentifier FieldName="Depth" FieldValue="2"/>
75+
</Start>
76+
77+
<Stop>
78+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="2" Version="1"/>
79+
</Stop>
80+
<Match>
81+
<Event PID="true"/>
82+
</Match>
83+
<Naming>
84+
<PayloadBased NameField="Depth"/>
85+
</Naming>
86+
</Region>
87+
</Region>
88+
89+
<Region Guid="{d8d639a2-cf4c-45fb-976a-000000000003}" Name="GCSuspends" FriendlyName="GC Suspensions">
90+
<Region Guid="{d8d639a2-cf4c-45fb-976a-000000000002}" Name="GCSuspend" FriendlyName="GC Suspension">
91+
<Start>
92+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="9" Version="1"/>
93+
</Start>
94+
<Stop>
95+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="3" Version="1"/>
96+
</Stop>
97+
<Match>
98+
<Event PID="true"/>
99+
</Match>
100+
</Region>
101+
</Region>
102+
103+
</RegionRoot>
104+
</Regions>
105+
</Instrumentation>
106+
</InstrumentationManifest>

‎tools/performance/Invoke-PerfviewPS.ps1‎

Lines changed: 55 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,55 @@
1+
#requires -RunAsAdministrator
2+
3+
param(
4+
$ETLFileName = '.\PerfViewData.etl',
5+
6+
[Parameter(Mandatory)]
7+
[scriptblock]
8+
$ScriptBlock,
9+
10+
$LogFileName = '.\perfview.log',
11+
12+
$PowerShellPath = $(Get-Command pwsh.exe).Source)
13+
14+
$EncodedScriptBlock = [System.Convert]::ToBase64String([System.Text.Encoding]::UNICODE.GetBytes($ScriptBlock.ToString()))
15+
$perfViewArgs = @(
16+
'/AcceptEula'
17+
'/ThreadTime'
18+
"/LogFile=$LogFileName"
19+
"/DataFile:$ETLFileName"
20+
'/noRundown'
21+
'/Merge'
22+
'/Zip:False'
23+
# GCSampledObjectAllocationHigh is sometimes useful, but quite expensive so not included by default
24+
# '/ClrEvents=default+GCSampledObjectAllocationHigh'
25+
'/Providers:*Microsoft-PowerShell-Runspaces,*Microsoft-PowerShell-CommandDiscovery,*Microsoft-PowerShell-Parser,*Microsoft.Windows.PowerShell'
26+
'run'
27+
"""$PowerShellPath"""
28+
'-NoProfile'
29+
'-EncodedCommand'
30+
$EncodedScriptBlock
31+
)
32+
33+
$process = Start-Process -FilePath (Get-Command PerfView.exe).Source -ArgumentList $perfViewArgs -PassThru
34+
35+
$rs = [runspacefactory]::CreateRunspace($host)
36+
$rs.Open()
37+
$ps = [powershell]::Create()
38+
$ps.Runspace = $rs
39+
40+
$null = $ps.AddCommand("Get-Content").
41+
AddArgument($LogFileName).
42+
AddParameter("Wait").
43+
AddParameter("Tail", 0)
44+
$null = $ps.AddCommand("Out-Host")
45+
46+
# If log file doesn't exist yet, wait a little bit so Get-Content doesn't fail
47+
while (!(Test-Path $LogFileName))
48+
{
49+
Start-Sleep -Seconds 1
50+
}
51+
52+
$null = $ps.BeginInvoke()
53+
$process.WaitForExit()
54+
$ps.Stop()
55+

‎tools/performance/JIT.Regions.xml‎

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,34 @@
1+
<?xml version='1.0' encoding='utf-8' standalone='yes'?>
2+
<!-- See definitions in C:\Windows\Microsoft.NET\Framework\v4.0.30319\CLR-ETW.man for .NET events -->
3+
<!-- Created by Alois Kraus. Free for public use.
4+
The JIT time is determined by the MethodJitStart event and the directly on this thread following MethodLoadUnload event which signals when the JIT compilation for this
5+
method is complete.
6+
Unfortunately the Region sums as it is currently in WPA it will sum not the JIT times of all threads but if e.g. 2 threads JIT for one second each then the WPA sum accross all threads will be only 1s.
7+
WPA seems to sum on a timeline only the active time accross all threads and uses this as sum which is not a good measure to compare results. This should be changed although this logic might
8+
be well suited for regions where each region signals a bottleneck on which others have to wait e.g. during boot.
9+
-->
10+
<InstrumentationManifest>
11+
<Instrumentation>
12+
<Regions>
13+
<RegionRoot Guid="{d8d639a0-1f4c-45fb-976a-0000DEADBEEF}" Name="JIT" FriendlyName="JIT Activity">
14+
<Region Guid="{d8d639a1-2f4c-45fb-976a-100000000101}" Name="JITs" FriendlyName="JITs">
15+
<Region Guid="{d8d639a1-3f4c-45fb-976a-000000000001}" Name="Method" FriendlyName="Method">
16+
<Start>
17+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="145" Version="1"/> <!-- MethodJittingStarted_V1 -->
18+
</Start>
19+
<Stop>
20+
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="143" Version="1"/> <!-- MethodLoadUnloadVerbose_V1 -->
21+
</Stop>
22+
<Match>
23+
<Event TID="true"/>
24+
</Match>
25+
<Naming>
26+
<PayloadBased NameField="MethodNamespace" />
27+
</Naming>
28+
</Region>
29+
</Region>
30+
</RegionRoot>
31+
</Regions>
32+
</Instrumentation>
33+
</InstrumentationManifest>
34+

0 commit comments

Comments
 (0)