Skip to content

[tests] Track evaluation time across performance runs #12390

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
jonathanpeppers merged 1 commit into from
Aug 14, 2026
+18 −12
Merged

[tests] Track evaluation time across performance runs #12390

Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
30 changes: 18 additions & 12 deletions tests/MSBuildDeviceIntegration/Tests/PerformanceTest.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -62,11 +62,12 @@ void Profile (ProjectBuilder builder, int iterations, Action<ProjectBuilder> act
}

double total = 0;
StructuredBuild build = null;
double maxEvaluationTime = 0;
for (int i=0; i < iterations; i++) {
action (builder);
build = ReadBinLog (builder);
var build = ReadBinLog (builder);
var actual = GetDuration (build, builder);
maxEvaluationTime = Math.Max (maxEvaluationTime, GetMaxEvaluationTime (build));
TestContext.Out.WriteLine ($"run {i} took: {actual}ms");
total += actual;
if (afterRun is not null)
Expand All @@ -75,7 +76,7 @@ void Profile (ProjectBuilder builder, int iterations, Action<ProjectBuilder> act
total /= iterations;
TestContext.Out.WriteLine ($"expected: {expected}ms, actual: {total}ms");
if (total > expected) {
AssertSlowMachine (build, expected, total);
AssertSlowMachine (maxEvaluationTime, expected, total);
Assert.Fail ($"Exceeded expected time of {expected}ms, actual {total}ms");
}
}
Expand All @@ -86,32 +87,37 @@ void ProfileTask (ProjectBuilder builder, string task, int iterations, Action<Pr
Assert.Fail ($"No timeout value found for a key of {caller}");
}
double total = 0;
StructuredBuild build = null;
double maxEvaluationTime = 0;
for (int i=0; i < iterations; i++) {
action (builder);
build = ReadBinLog (builder);
var build = ReadBinLog (builder);
var duration = GetTaskDuration (build, builder, task);
maxEvaluationTime = Math.Max (maxEvaluationTime, GetMaxEvaluationTime (build));
TestContext.Out.WriteLine($"run {i} took: {duration}ms");
total += duration;
}
total /= iterations;
TestContext.Out.WriteLine($"expected: {expected}ms, actual: {total}ms");
if (total > expected) {
AssertSlowMachine (build, expected, total);
AssertSlowMachine (maxEvaluationTime, expected, total);
Assert.Fail ($"Exceeded expected time of {expected}ms, actual {total}ms");
}
}

void AssertSlowMachine (StructuredBuild build, int expected, double actual)
void AssertSlowMachine (double maxEvaluationTime, int expected, double actual)
{
var evaluations = build.FindChildrenRecursive<ProjectEvaluation> ();
var maxEval = evaluations.Any () ? evaluations.Max (e => e.Duration.TotalMilliseconds) : 0;
TestContext.Out.WriteLine ($"max evaluation time: {maxEval}ms (threshold: {MaxEvaluationTimeInMs}ms)");
if (maxEval > MaxEvaluationTimeInMs) {
Assert.Inconclusive ($"Exceeded expected time of {expected}ms, actual {actual}ms, but evaluation time was {maxEval:F0}ms (threshold: {MaxEvaluationTimeInMs}ms), indicating a slow CI machine.");
TestContext.Out.WriteLine ($"max evaluation time: {maxEvaluationTime}ms (threshold: {MaxEvaluationTimeInMs}ms)");
if (maxEvaluationTime > MaxEvaluationTimeInMs) {
Assert.Inconclusive ($"Exceeded expected time of {expected}ms, actual {actual}ms, but evaluation time was {maxEvaluationTime:F0}ms (threshold: {MaxEvaluationTimeInMs}ms), indicating a slow CI machine.");
}
}

double GetMaxEvaluationTime (StructuredBuild build)
{
var evaluations = build.FindChildrenRecursive<ProjectEvaluation> ();
return evaluations.Any () ? evaluations.Max (e => e.Duration.TotalMilliseconds) : 0;
}
Comment thread
jonathanpeppers marked this conversation as resolved.

StructuredBuild ReadBinLog (ProjectBuilder builder)
{
var binlog = Path.Combine (Root, builder.ProjectDirectory, $"{Path.GetFileNameWithoutExtension (builder.BuildLogFile)}.binlog");
Expand Down