Skip to content

Commit

Permalink
Log jit decisions in PMI
Browse files Browse the repository at this point in the history
This adds two flags that allows PMI to output inlining and tail-call
decisions to stdout.
  • Loading branch information
jakobbotsch committed Aug 14, 2019
1 parent 9542bbd commit 589d838
Show file tree
Hide file tree
Showing 8 changed files with 242 additions and 2 deletions.
2 changes: 1 addition & 1 deletion build.cmd
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ goto :argLoop
:build

REM Declare the list of projects
set projects=jit-diff jit-dasm jit-analyze jit-format cijobs pmi jit-dasm-pmi
set projects=jit-diff jit-dasm jit-analyze jit-format cijobs pmi jit-dasm-pmi jit-decisions-analyze

REM Build each project
for %%p in (%projects%) do (
Expand Down
2 changes: 1 addition & 1 deletion build.sh
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,7 @@ while getopts "hpfbt:" opt; do
done

# declare the array of projects
declare -a projects=(jit-dasm jit-diff jit-analyze jit-format cijobs pmi jit-dasm-pmi)
declare -a projects=(jit-dasm jit-diff jit-analyze jit-format cijobs pmi jit-dasm-pmi jit-decisions-analyze)

# for each project either build or publish
for proj in "${projects[@]}"
Expand Down
15 changes: 15 additions & 0 deletions jitutils.sln
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,8 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "pmi", "src\pmi\pmi.csproj",
EndProject
Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "jit-dasm-pmi", "src\jit-dasm-pmi\jit-dasm-pmi.csproj", "{2C846294-79D4-40EA-8ED3-0F01E033BE32}"
EndProject
Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "jit-decisions-analyze", "src\jit-decisions-analyze\jit-decisions-analyze.csproj", "{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}"
EndProject
Global
GlobalSection(SolutionConfigurationPlatforms) = preSolution
Debug|Any CPU = Debug|Any CPU
Expand Down Expand Up @@ -130,6 +132,18 @@ Global
{2C846294-79D4-40EA-8ED3-0F01E033BE32}.Release|x64.Build.0 = Release|Any CPU
{2C846294-79D4-40EA-8ED3-0F01E033BE32}.Release|x86.ActiveCfg = Release|Any CPU
{2C846294-79D4-40EA-8ED3-0F01E033BE32}.Release|x86.Build.0 = Release|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Debug|Any CPU.ActiveCfg = Debug|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Debug|Any CPU.Build.0 = Debug|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Debug|x64.ActiveCfg = Debug|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Debug|x64.Build.0 = Debug|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Debug|x86.ActiveCfg = Debug|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Debug|x86.Build.0 = Debug|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Release|Any CPU.ActiveCfg = Release|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Release|Any CPU.Build.0 = Release|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Release|x64.ActiveCfg = Release|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Release|x64.Build.0 = Release|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Release|x86.ActiveCfg = Release|Any CPU
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B}.Release|x86.Build.0 = Release|Any CPU
EndGlobalSection
GlobalSection(NestedProjects) = preSolution
{5B781D3D-308C-4415-8C68-17D557B143B8} = {69D45FDC-948D-464B-BF14-5675F291FC62}
Expand All @@ -140,5 +154,6 @@ Global
{19436C6B-39C9-4A88-8021-3242D098637E} = {69D45FDC-948D-464B-BF14-5675F291FC62}
{829E459B-EE3D-46A9-AD4D-4F2B03D5188C} = {69D45FDC-948D-464B-BF14-5675F291FC62}
{2C846294-79D4-40EA-8ED3-0F01E033BE32} = {69D45FDC-948D-464B-BF14-5675F291FC62}
{59FB3663-C16C-4C3B-90A7-AF7259C8A39B} = {69D45FDC-948D-464B-BF14-5675F291FC62}
EndGlobalSection
EndGlobal
1 change: 1 addition & 0 deletions src/jit-decisions-analyze/README.md
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
# jit-decisions-analyze - Managed JIT decisions analysis tool
152 changes: 152 additions & 0 deletions src/jit-decisions-analyze/jit-decisions-analyze.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,152 @@
using System;
using System.Collections.Generic;
using System.IO;
using System.Linq;

namespace jit_decisions_analyze
{
internal class Program
{
private static void Main(string[] args)
{
List<Event> events = new List<Event>();
int malformed = 0;
static void WriteProgress(double pct)
{
Console.CursorLeft = 0;
Console.Write("{0:F2}% done", pct);
}

using (var sr = new StreamReader(File.OpenRead(args[0])))
{
int lines = 0;
string line;
while ((line = sr.ReadLine()) != null)
{
if (!line.StartsWith("JITTracing: "))
continue;

line = line.Substring("JITTracing: ".Length);
Event evt = ToEvent(line);
if (evt != null)
events.Add(evt);
else
malformed++;

if (lines++ % 10000 == 0)
WriteProgress(sr.BaseStream.Position / (double)sr.BaseStream.Length * 100);
}
}

WriteProgress(100);
Console.WriteLine();

Console.WriteLine("{0} total well-formed events ({1} filtered away because they were malformed)", events.Count, malformed);
List<TailCallEvent> tailCalls = events.OfType<TailCallEvent>().ToList();
WriteInfo("Implicit", tailCalls.Where(t => !t.TailPrefix));
WriteInfo("Explicit", tailCalls.Where(t => t.TailPrefix));
WriteInfo("Inlining", events.OfType<InliningEvent>());
}

private static Event ToEvent(string l)
{
string[] data = l.Split("@!@!@");
if (data.Length % 2 == 0)
return null;

Dictionary<string, string> payload = new Dictionary<string, string>();
for (int i = 1; i < data.Length; i += 2)
payload.Add(data[i], data[i + 1]);

string tailPrefix;
string failReason;
switch (data[0])
{
case "MethodJitTailCallSucceeded":
tailPrefix = payload.GetValueOrDefault("TailPrefix");
if (tailPrefix == null)
return null;

return new TailCallSucceededEvent { TailPrefix = tailPrefix == "True" };
case "MethodJitTailCallFailed":
tailPrefix = payload.GetValueOrDefault("TailPrefix");
failReason = payload.GetValueOrDefault("FailReason");
if (failReason == null || tailPrefix == null)
return null;

return new TailCallFailedEvent { FailReason = failReason, TailPrefix = tailPrefix == "True" };
case "MethodJitInliningSucceeded":
return new InliningSucceededEvent();
case "MethodJitInliningFailed":
failReason = payload.GetValueOrDefault("FailReason");
if (failReason == null)
return null;

return new InliningFailedEvent { FailReason = failReason };
default:
return null;
}
}

private static void WriteInfo(string name, IEnumerable<Event> events)
{
List<Event> list = events.ToList();
int sites = list.Count;
int sitesSuccessful = list.Count(IsSuccessEvent);
Console.WriteLine("{0} call sites: {1}/{2} converted", name, sitesSuccessful, sites);
if (sites == 0)
return;

string GetInfoString(Event e)
{
switch (e)
{
case TailCallSucceededEvent f: return "Successfully converted";
case InliningSucceededEvent f: return "Successfully converted";
case TailCallFailedEvent f: return f.FailReason;
case InliningFailedEvent f: return f.FailReason;
default: throw new ArgumentException("No fail reason on event");
}
}

var groupedFailures = list.GroupBy(GetInfoString).OrderByDescending(g => g.Count());
foreach (var g in groupedFailures)
Console.WriteLine("[{0:00.00}%] {1}", g.Count() / (double)sites * 100, g.Key);

Console.WriteLine();
}

private static bool IsSuccessEvent(Event e) => e is TailCallSucceededEvent || e is InliningSucceededEvent;
}

internal abstract class Event
{
}

internal abstract class TailCallEvent : Event
{
public bool TailPrefix { get; set; }
}

internal class TailCallSucceededEvent : TailCallEvent
{
}

internal class TailCallFailedEvent : TailCallEvent
{
public string FailReason { get; set; }
}

internal abstract class InliningEvent : Event
{
}

internal class InliningSucceededEvent : InliningEvent
{
}

internal class InliningFailedEvent : InliningEvent
{
public string FailReason { get; set; }
}
}
14 changes: 14 additions & 0 deletions src/jit-decisions-analyze/jit-decisions-analyze.csproj
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
<Project Sdk="Microsoft.NET.Sdk">

<Import Project="$([MSBuild]::GetPathOfFileAbove(target-framework.props))" />
<Import Project="$([MSBuild]::GetPathOfFileAbove(jit-include.props))" />

<PropertyGroup>
<OutputType>Exe</OutputType>
</PropertyGroup>

<ItemGroup>
<Compile Include="..\util\util.cs" Link="util.cs" />
</ItemGroup>

</Project>
41 changes: 41 additions & 0 deletions src/pmi/JITDecisionEventListener.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,41 @@
using System;
using System.Collections.Generic;
using System.Diagnostics.Tracing;

namespace pmi
{
internal class JITDecisionEventListener : EventListener
{
// We cannot use a parameter to this event listener because
// EventListener constructor calls OnEventWritten, which will happen
// before we have been able to run our own constructor.
internal static readonly HashSet<string> s_enabledEvents = new HashSet<string>();

protected override void OnEventSourceCreated(EventSource eventSource)
{
if (eventSource.Name != "Microsoft-Windows-DotNETRuntime")
return;

EventKeywords jitTracing = (EventKeywords)0x1000; // JITTracing
EnableEvents(eventSource, EventLevel.Verbose, jitTracing);
}

protected override void OnEventWritten(EventWrittenEventArgs data)
{
if (!s_enabledEvents.Contains(data.EventName))
return;

List<string> dataStrings = new List<string> { data.EventName };

for (int i = 0; i < data.Payload.Count; i++)
{
dataStrings.Add(data.PayloadNames[i]);
dataStrings.Add(data.Payload[i] != null ? data.Payload[i].ToString() : "");
}

// Log payload separated by @!@!@. This is somewhat ugly, but easy enough to parse
// and avoids pulling in a dependency here.
Console.WriteLine("JITTracing: {0}", string.Join("@!@!@", dataStrings));
}
}
}
17 changes: 17 additions & 0 deletions src/pmi/pmi.cs
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
// The .NET Foundation licenses this file to you under the MIT license.
// See the LICENSE file in the project root for more information.

using pmi;
using System;
using System.Collections.Generic;
using System.IO;
Expand Down Expand Up @@ -1411,6 +1412,22 @@ public static int Main(string[] args)
}

bool runCctors = command.IndexOf("CCTORS") > 0;
bool logTailCallDecisions = command.IndexOf("TAILCALLS") > 0;
bool logInliningDecisions = command.IndexOf("INLINES") > 0;

if (logTailCallDecisions)
{
JITDecisionEventListener.s_enabledEvents.Add("MethodJitTailCallSucceeded");
JITDecisionEventListener.s_enabledEvents.Add("MethodJitTailCallFailed");
}
if (logInliningDecisions)
{
JITDecisionEventListener.s_enabledEvents.Add("MethodJitInliningSucceeded");
JITDecisionEventListener.s_enabledEvents.Add("MethodJitInliningFailed");
}

using var eventListener =
logTailCallDecisions || logInliningDecisions ? new JITDecisionEventListener() : null;

Worker w = new Worker(v, runCctors);
int result = 0;
Expand Down

0 comments on commit 589d838

Please sign in to comment.