Skip to content
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

Add additional filter capabilities to dotnet-pgo tool. #89853

Merged
merged 6 commits into from
Aug 10, 2023
Merged

Add additional filter capabilities to dotnet-pgo tool. #89853

Show file tree
Hide file tree
Changes from 5 commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
72df5ed
Add additional filter capabilities to dotnet-pgo tool.
lateralusX Aug 2, 2023
817e82a
Review feedback.
lateralusX Aug 4, 2023
930a574
Address feedback
mdh1418 Aug 8, 2023
8b7693f
Align spacing for R2RLoad and jitStart event processing
mdh1418 Aug 8, 2023
f95dc3e
Address more feedback
mdh1418 Aug 8, 2023
c6affef
Select largest range to bound events
mdh1418 Aug 9, 2023
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
12 changes: 12 additions & 0 deletions src/coreclr/tools/dotnet-pgo/PgoRootCommand.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -45,6 +45,14 @@ internal sealed class PgoRootCommand : CliRootCommand
new("--exclude-events-before") { DefaultValueFactory = _ => Double.MinValue, Description = "Exclude data from events before specified time. Time is specified as milliseconds from the start of the trace" };
public CliOption<double> ExcludeEventsAfter { get; } =
new("--exclude-events-after") { DefaultValueFactory = _ => Double.MaxValue, Description = "Exclude data from events after specified time. Time is specified as milliseconds from the start of the trace" };
public CliOption<string> ExcludeEventsBeforeJittingMethod { get; } =
new("--exclude-events-before-jitting-method") { DefaultValueFactory = _ => string.Empty, Description = "Exclude data from events before observing a specific method getting jitted. Method is matched using a regular expression against the method name. Note that the method name is formatted the same as in PerfView which includes typed parameters." };
public CliOption<string> ExcludeEventsAfterJittingMethod { get; } =
new("--exclude-events-after-jitting-method") { DefaultValueFactory = _ => string.Empty, Description = "Exclude data from events after observing a specific method getting jitted. Method is matched using a regular expression against the method name. Note that the method name is formatted the same as in PerfView which includes typed parameters." };
public CliOption<string> IncludeMethods { get; } =
new("--include-methods") { DefaultValueFactory = _ => string.Empty, Description = "Include methods with names matching regular expression. Note that the method names are formatted the same as in PerfView which includes typed parameters." };
public CliOption<string> ExcludeMethods { get; } =
new("--exclude-methods") { DefaultValueFactory = _ => string.Empty, Description = "Exclude methods with names matching regular expression. Note that the method names are formatted the same as in PerfView which includes typed parameters." };
public CliOption<bool> Compressed { get; } =
new("--compressed") { DefaultValueFactory = _ => true, Description = "Generate compressed mibc" };
public CliOption<int> DumpWorstOverlapGraphs { get; } =
Expand Down Expand Up @@ -99,6 +107,10 @@ public PgoRootCommand(string[] args) : base(".NET PGO Tool")
ClrInstanceId,
ExcludeEventsBefore,
ExcludeEventsAfter,
ExcludeEventsBeforeJittingMethod,
ExcludeEventsAfterJittingMethod,
IncludeMethods,
ExcludeMethods,
AutomaticReferences,
_verbosity,
Compressed,
Expand Down
104 changes: 102 additions & 2 deletions src/coreclr/tools/dotnet-pgo/Program.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
using System.Text;
using System.Text.Json;
using System.Text.Encodings.Web;
using System.Text.RegularExpressions;
using System.Threading.Tasks;

using Microsoft.Diagnostics.Tools.Pgo;
Expand Down Expand Up @@ -1343,6 +1344,12 @@ private int InnerProcessTraceFileMain()

double excludeEventsBefore = Get(_command.ExcludeEventsBefore);
double excludeEventsAfter = Get(_command.ExcludeEventsAfter);
Regex excludeEventsBeforeJittingMethod = !string.IsNullOrEmpty(Get(_command.ExcludeEventsBeforeJittingMethod)) ? new Regex(Get(_command.ExcludeEventsBeforeJittingMethod)) : null;
Regex excludeEventsAfterJittingMethod = !string.IsNullOrEmpty(Get(_command.ExcludeEventsAfterJittingMethod)) ? new Regex(Get(_command.ExcludeEventsAfterJittingMethod)) : null;
Regex includeMethods = !string.IsNullOrEmpty(Get(_command.IncludeMethods)) ? new Regex(Get(_command.IncludeMethods)) : null;
Regex excludeMethods = !string.IsNullOrEmpty(Get(_command.ExcludeMethods)) ? new Regex(Get(_command.ExcludeMethods)) : null;

// Find all the R2RLoad events.
if (_command.ProcessR2REvents)
{
foreach (var e in p.EventsInProcess.ByEventType<R2RGetEntryPointTraceData>())
Expand All @@ -1351,6 +1358,7 @@ private int InnerProcessTraceFileMain()
string retArg = e.MethodSignature.Substring(0, parenIndex);
string paramsArgs = e.MethodSignature.Substring(parenIndex);
string methodNameFromEventDirectly = retArg + e.MethodNamespace + "." + e.MethodName + paramsArgs;

if (e.ClrInstanceID != clrInstanceId)
{
if (!_command.Warnings)
Expand All @@ -1359,6 +1367,7 @@ private int InnerProcessTraceFileMain()
PrintWarning($"Skipped R2REntryPoint {methodNameFromEventDirectly} due to ClrInstanceID of {e.ClrInstanceID}");
continue;
}

MethodDesc method = null;
string extraWarningText = null;
bool failedDueToNonloadableModule = false;
Expand All @@ -1382,8 +1391,67 @@ private int InnerProcessTraceFileMain()
continue;
}

if ((e.TimeStampRelativeMSec >= excludeEventsBefore) && (e.TimeStampRelativeMSec <= excludeEventsAfter))
if (e.TimeStampRelativeMSec < excludeEventsBefore)
{
continue;
}

if (e.TimeStampRelativeMSec > excludeEventsAfter)
{
break;
}

string perfviewMethodName = e.MethodNamespace + "." + e.MethodName + paramsArgs;
if (PassesMethodFilter(includeMethods, excludeMethods, perfviewMethodName))
{
methodsToAttemptToPrepare.Add((int)e.EventIndex, new ProcessedMethodData(e.TimeStampRelativeMSec, method, "R2RLoad"));
}
}
}

// In case requesting events before/after jitting a method, discover the
// corresponding excludeEventsBefore/excludeEventsAfter in event stream based
// on filter criterias.
if (_command.ProcessJitEvents && (excludeEventsBeforeJittingMethod != null || excludeEventsAfterJittingMethod != null))
{
foreach (var e in p.EventsInProcess.ByEventType<MethodJittingStartedTraceData>())
{
if (e.ClrInstanceID != clrInstanceId)
{
continue;
}

MethodDesc method = null;
bool failedDueToNonloadableModule = false;
try
{
method = idParser.ResolveMethodID(e.MethodID, out failedDueToNonloadableModule, false);
}
catch { }

if (method == null)
{
continue;
}

int parenIndex = e.MethodSignature.IndexOf('(');
string paramsArgs = e.MethodSignature.Substring(parenIndex);
string perfviewMethodName = e.MethodNamespace + "." + e.MethodName + paramsArgs;
if (e.TimeStampRelativeMSec > excludeEventsBefore && excludeEventsBeforeJittingMethod != null && excludeEventsBeforeJittingMethod.IsMatch(perfviewMethodName))
{
excludeEventsBefore = e.TimeStampRelativeMSec;
}

if (e.TimeStampRelativeMSec < excludeEventsAfter && excludeEventsAfterJittingMethod != null && excludeEventsAfterJittingMethod.IsMatch(perfviewMethodName))
{
excludeEventsAfter = e.TimeStampRelativeMSec;
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is the behavior here on multiple matches the right one? In particular excluding events before the last match instead of before the first match seems odd to me.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

RIght, it would be problematic especially if the method matching had a timestamp order of beforeMethodMatch1 < afterMethodMatch < beforeMethodMatch2. And worst case, if the two matches wer the same, it would be impossible for the user to have a specific enough regex to only match the first (temporally) method.

Are methods in the enumerator of p.EventsInProcess.ByEventType<MethodJittingStartedTraceData>() guaranteed to be ordered temporally?

Maybe it would be better to keep a list of the matches and choose the first temporal match for excludeEventsBeforeJittingMethod and the last temporal match for excludeEventsAfterJittingMethod

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Are methods in the enumerator of p.EventsInProcess.ByEventType() guaranteed to be ordered temporally?

Yes, so we can just have a bool or something to keep track of whether we have already assigned excludeEventsBefore.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

And for excludeEventsAfterJittingMethod we would need to still keep a list of the matches for a scenario like afterMethodMatch1 < beforeMethodMatch < afterMethodMatch2 in case the user wanted to use the bounds [beforeMethodMatch, afterMethodMatch2].

Just realizing, if these events are for jitting methods, is it the case that we would only JIT a particular method once? Meaning no two events will have the same name? Not sure exactly how these events are collected. If thats the case, then maybe we can have it such that the user needs to be more specific with their Regex matching if there happens to be multiple matches?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was able to trace an app and sent over the .nettrace to my windows machine. It looks like caching does happen and a method will only be found once in MethodJittingStartedTraceData? So it seems like users can be more specific with their regular expression matching, but will opt to take the first "before" match and the last "after" match to avoid invalid bounds.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

And for excludeEventsAfterJittingMethod we would need to still keep a list of the matches for a scenario like afterMethodMatch1 < beforeMethodMatch < afterMethodMatch2 in case the user wanted to use the bounds [beforeMethodMatch, afterMethodMatch2].

I don't think this is a scenario we need or should to try to handle. As long as we give a warning or error (which I believe we already do) the user can fix the regex to be specific enough. I would just make sure we pick the largest range that corresponds to the matches.

Just realizing, if these events are for jitting methods, is it the case that we would only JIT a particular method once? Meaning no two events will have the same name? Not sure exactly how these events are collected. If thats the case, then maybe we can have it such that the user needs to be more specific with their Regex matching if there happens to be multiple matches?

coreclr will JIT the same method multiple times at different optimization levels when tiered compilation is enabled, so there can be multiple "JIT started" events for the same method.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added two doubles to track the earliest excludeEventsBeforeJittingMethod match and latest excludeEventsAfterJittingMethod match

}

if (excludeEventsBefore > excludeEventsAfter)
{
PrintError($"Exclude events before timestamp: \"{excludeEventsBefore}\" can't be later than exclude events after timestamp: \"{excludeEventsAfter}\"");
return -1;
}
}

Expand All @@ -1396,6 +1464,7 @@ private int InnerProcessTraceFileMain()
string retArg = e.MethodSignature.Substring(0, parenIndex);
string paramsArgs = e.MethodSignature.Substring(parenIndex);
string methodNameFromEventDirectly = retArg + e.MethodNamespace + "." + e.MethodName + paramsArgs;

if (e.ClrInstanceID != clrInstanceId)
{
if (!_command.Warnings)
Expand Down Expand Up @@ -1428,8 +1497,21 @@ private int InnerProcessTraceFileMain()
continue;
}

if ((e.TimeStampRelativeMSec >= excludeEventsBefore) && (e.TimeStampRelativeMSec <= excludeEventsAfter))
if (e.TimeStampRelativeMSec < excludeEventsBefore)
{
continue;
}

if (e.TimeStampRelativeMSec > excludeEventsAfter)
{
break;
}

string perfviewMethodName = e.MethodNamespace + "." + e.MethodName + paramsArgs;
if (PassesMethodFilter(includeMethods, excludeMethods, perfviewMethodName))
{
methodsToAttemptToPrepare.Add((int)e.EventIndex, new ProcessedMethodData(e.TimeStampRelativeMSec, method, "JitStart"));
}
}
}

Expand Down Expand Up @@ -1783,6 +1865,24 @@ void AddToInstrumentationData(int eventClrInstanceId, long methodID, int methodF
return 0;
}

private static bool PassesMethodFilter(Regex includeMethods, Regex excludeMethods, string methodName)
{
if (includeMethods != null || excludeMethods != null)
{
if (includeMethods != null && !includeMethods.IsMatch(methodName))
{
return false;
}

if (excludeMethods != null && excludeMethods.IsMatch(methodName))
{
return false;
}
}

return true;
}

private static void GenerateJittraceFile(FileInfo outputFileName, IEnumerable<ProcessedMethodData> methodsToAttemptToPrepare, JitTraceOptions jittraceOptions)
{
PrintMessage($"JitTrace options {jittraceOptions}");
Expand Down