Skip to content

Add tools for PowerShell perf analysis #7595

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
adityapatwardhan merged 2 commits into from
Aug 30, 2018
Merged

Add tools for PowerShell perf analysis #7595

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
683cc79
Add tools for PowerShell perf analysis
lzybkr Aug 21, 2018
5d2c5d2
Updated spellings file
adityapatwardhan Aug 30, 2018
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 17 additions & 0 deletions .spelling
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1090,3 +1090,20 @@ interactivetesting
allowprerelease
prereleases
url
- tools/performance/README.md
analyze
wpa
wpaProfile
PerfView
etl
perfview
wpr
wprui.exe
perfview.exe
GC.Regions.xml
JIT.Regions.xml
PowerShell.Regions.xml
PowerShell.stacktags
PowerShell.wpaProfile
PowerShell.wprp
Invoke-PerfviewPS
106 changes: 106 additions & 0 deletions tools/performance/GC.Regions.xml
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,106 @@
<?xml version='1.0' encoding='utf-8' standalone='yes'?>
<!-- See definitions in C:\Windows\Microsoft.NET\Framework\v4.0.30319\CLR-ETW.man for .NET events -->
<!--
Unlike JIT GC is largely single threaded and the times correlate very well with PerfView where we can drill down into each GC
generation in the region graph in WPA.
We use bascially the GC Start/Stop events where the GC Start event has also the generation traced which enables us to create
regions for each GC type.
GC suspensions work a bit different were I use the GCSuspendEE_V1 as start and GCRestartEEEnd as end event. This allows us
to capture in principle also the time where the suspension or resumption itself takes an abnormally long time whic would indicate
a GC bug or a thread priority problem.
-->
<InstrumentationManifest>
<Instrumentation>
<Regions>
<RegionRoot Guid="{d8d639a0-cf4c-45fb-976a-0000DEADBEEF}" Name="GC" FriendlyName="GC Activity">
<Region Guid="{d8d639a1-cf4c-45fb-976a-100000000101}" Name="Gen 0" FriendlyName="GCs">
<Region Guid="{d8d639a1-cf4c-45fb-976a-000000000001}" Name="Gen 0" FriendlyName="Gen 0">
<Start>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="1"/>
<PayloadIdentifier FieldName="Depth" FieldValue="0"/>
<!-- Depth is the Generation number -->
</Start>
<Start>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="2"/>
<!-- .NET 4.6 has a new GC Start event -->
<PayloadIdentifier FieldName="Depth" FieldValue="0"/>
</Start>

<Stop>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="2" Version="1"/>
</Stop>
<Match>
<Event PID="true"/>
</Match>
<Naming>
<PayloadBased NameField="Depth"/>
</Naming>
</Region>
</Region>

<Region Guid="{d8d639a1-cf4c-45fb-976b-100000000101}" Name="Gen 1" FriendlyName="GCs">
<Region Guid="{d8d639a1-cf4c-45fb-976a-000000000005}" Name="Gen 1" FriendlyName="Gen 1">
<Start>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="1"/>
<PayloadIdentifier FieldName="Depth" FieldValue="1"/>
</Start>
<Start>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="2"/>
<!-- .NET 4.6 has a new GC Start event -->
<PayloadIdentifier FieldName="Depth" FieldValue="1"/>
</Start>

<Stop>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="2" Version="1"/>
</Stop>
<Match>
<Event PID="true"/>
</Match>
<Naming>
<PayloadBased NameField="Depth"/>
</Naming>
</Region>
</Region>

<Region Guid="{d8d639a1-cf4c-45fb-976c-100000000101}" Name="Gen 2" FriendlyName="GCs">
<Region Guid="{d8d639a1-cf4c-45fb-976a-000000000006}" Name="Gen 2" FriendlyName="Gen 2">
<Start>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="1"/>
<PayloadIdentifier FieldName="Depth" FieldValue="2"/>
</Start>
<Start>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="1" Version="2"/>
<!-- .NET 4.6 has a new GC Start event -->
<PayloadIdentifier FieldName="Depth" FieldValue="2"/>
</Start>

<Stop>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="2" Version="1"/>
</Stop>
<Match>
<Event PID="true"/>
</Match>
<Naming>
<PayloadBased NameField="Depth"/>
</Naming>
</Region>
</Region>

<Region Guid="{d8d639a2-cf4c-45fb-976a-000000000003}" Name="GCSuspends" FriendlyName="GC Suspensions">
<Region Guid="{d8d639a2-cf4c-45fb-976a-000000000002}" Name="GCSuspend" FriendlyName="GC Suspension">
<Start>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="9" Version="1"/>
</Start>
<Stop>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="3" Version="1"/>
</Stop>
<Match>
<Event PID="true"/>
</Match>
</Region>
</Region>

</RegionRoot>
</Regions>
</Instrumentation>
</InstrumentationManifest>
55 changes: 55 additions & 0 deletions tools/performance/Invoke-PerfviewPS.ps1
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,55 @@
#requires -RunAsAdministrator

param(
$ETLFileName = '.\PerfViewData.etl',

[Parameter(Mandatory)]
[scriptblock]
$ScriptBlock,

$LogFileName = '.\perfview.log',

$PowerShellPath = $(Get-Command pwsh.exe).Source)

$EncodedScriptBlock = [System.Convert]::ToBase64String([System.Text.Encoding]::UNICODE.GetBytes($ScriptBlock.ToString()))
$perfViewArgs = @(
'/AcceptEula'
'/ThreadTime'
"/LogFile=$LogFileName"
"/DataFile:$ETLFileName"
'/noRundown'
'/Merge'
'/Zip:False'
# GCSampledObjectAllocationHigh is sometimes useful, but quite expensive so not included by default
# '/ClrEvents=default+GCSampledObjectAllocationHigh'
'/Providers:*Microsoft-PowerShell-Runspaces,*Microsoft-PowerShell-CommandDiscovery,*Microsoft-PowerShell-Parser,*Microsoft.Windows.PowerShell'
'run'
"""$PowerShellPath"""
'-NoProfile'
'-EncodedCommand'
$EncodedScriptBlock
)

$process = Start-Process -FilePath (Get-Command PerfView.exe).Source -ArgumentList $perfViewArgs -PassThru

$rs = [runspacefactory]::CreateRunspace($host)
$rs.Open()
$ps = [powershell]::Create()
$ps.Runspace = $rs

$null = $ps.AddCommand("Get-Content").
AddArgument($LogFileName).
AddParameter("Wait").
AddParameter("Tail", 0)
$null = $ps.AddCommand("Out-Host")

# If log file doesn't exist yet, wait a little bit so Get-Content doesn't fail
while (!(Test-Path $LogFileName))
{
Start-Sleep -Seconds 1
}

$null = $ps.BeginInvoke()
$process.WaitForExit()
$ps.Stop()

34 changes: 34 additions & 0 deletions tools/performance/JIT.Regions.xml
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
<?xml version='1.0' encoding='utf-8' standalone='yes'?>
<!-- See definitions in C:\Windows\Microsoft.NET\Framework\v4.0.30319\CLR-ETW.man for .NET events -->
<!-- Created by Alois Kraus. Free for public use.
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
method is complete.
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.
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
be well suited for regions where each region signals a bottleneck on which others have to wait e.g. during boot.
-->
<InstrumentationManifest>
<Instrumentation>
<Regions>
<RegionRoot Guid="{d8d639a0-1f4c-45fb-976a-0000DEADBEEF}" Name="JIT" FriendlyName="JIT Activity">
<Region Guid="{d8d639a1-2f4c-45fb-976a-100000000101}" Name="JITs" FriendlyName="JITs">
<Region Guid="{d8d639a1-3f4c-45fb-976a-000000000001}" Name="Method" FriendlyName="Method">
<Start>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="145" Version="1"/> <!-- MethodJittingStarted_V1 -->
</Start>
<Stop>
<Event Provider="{e13c0d23-ccbc-4e12-931b-d9cc2eee27e4}" Id="143" Version="1"/> <!-- MethodLoadUnloadVerbose_V1 -->
</Stop>
<Match>
<Event TID="true"/>
</Match>
<Naming>
<PayloadBased NameField="MethodNamespace" />
</Naming>
</Region>
</Region>
</RegionRoot>
</Regions>
</Instrumentation>
</InstrumentationManifest>

Loading