Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
81 changes: 32 additions & 49 deletions tests/MSBuildDeviceIntegration/Tests/PerformanceTest.cs
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
using System.Runtime.CompilerServices;
using Microsoft.Build.Framework;
using Microsoft.Build.Logging.StructuredLogger;
using StructuredBuild = Microsoft.Build.Logging.StructuredLogger.Build;
using NUnit.Framework;
using Xamarin.ProjectTools;

Expand All @@ -15,6 +16,7 @@ namespace Xamarin.Android.Build.Tests
public class PerformanceTest : DeviceTest
{
const int Retry = 2;
const int MaxEvaluationTimeInMs = 500;
static readonly Dictionary<string, int> csv_values = new Dictionary<string, int> ();

[OneTimeSetUp]
Expand Down Expand Up @@ -57,9 +59,11 @@ void Profile (ProjectBuilder builder, int iterations, Action<ProjectBuilder> act
}

double total = 0;
StructuredBuild build = null;
for (int i=0; i < iterations; i++) {
action (builder);
var actual = GetDurationFromBinLog (builder);
build = ReadBinLog (builder);
var actual = GetDuration (build, builder);
Comment thread
jonathanpeppers marked this conversation as resolved.
TestContext.Out.WriteLine ($"run {i} took: {actual}ms");
total += actual;
if (afterRun is not null)
Expand All @@ -68,6 +72,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);
Assert.Fail ($"Exceeded expected time of {expected}ms, actual {total}ms");
}
}
Expand All @@ -78,47 +83,63 @@ 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;
for (int i=0; i < iterations; i++) {
action (builder);
var duration = GetTaskDurationFromBinLog (builder, task);
build = ReadBinLog (builder);
var duration = GetTaskDuration (build, builder, task);
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);
Assert.Fail ($"Exceeded expected time of {expected}ms, actual {total}ms");
}
}

double GetTaskDurationFromBinLog (ProjectBuilder builder, string task)
void AssertSlowMachine (StructuredBuild build, 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.");
}
}

StructuredBuild ReadBinLog (ProjectBuilder builder)
{
var binlog = Path.Combine (Root, builder.ProjectDirectory, $"{Path.GetFileNameWithoutExtension (builder.BuildLogFile)}.binlog");
FileAssert.Exists (binlog);
return BinaryLog.ReadBuild (binlog);
}

var build = BinaryLog.ReadBuild (binlog);
double GetTaskDuration (StructuredBuild build, ProjectBuilder builder, string task)
{
var duration = build
.FindChildrenRecursive<Task> (t => t.Name == task)
.Aggregate (TimeSpan.Zero, (duration, target) => duration + target.Duration);

if (duration == TimeSpan.Zero)
if (duration == TimeSpan.Zero) {
var binlog = Path.Combine (Root, builder.ProjectDirectory, $"{Path.GetFileNameWithoutExtension (builder.BuildLogFile)}.binlog");
throw new InvalidDataException ($"No task build duration found in {binlog}");
}

return duration.TotalMilliseconds;
}

double GetDurationFromBinLog (ProjectBuilder builder)
double GetDuration (StructuredBuild build, ProjectBuilder builder)
{
var binlog = Path.Combine (Root, builder.ProjectDirectory, $"{Path.GetFileNameWithoutExtension (builder.BuildLogFile)}.binlog");
FileAssert.Exists (binlog);

var build = BinaryLog.ReadBuild (binlog);
var duration = build
.FindChildrenRecursive<Project> ()
.Aggregate (TimeSpan.Zero, (duration, project) => duration + project.Duration);

if (duration == TimeSpan.Zero)
if (duration == TimeSpan.Zero) {
var binlog = Path.Combine (Root, builder.ProjectDirectory, $"{Path.GetFileNameWithoutExtension (builder.BuildLogFile)}.binlog");
throw new InvalidDataException ($"No project build duration found in {binlog}");
}

return duration.TotalMilliseconds;
}
Expand All @@ -140,21 +161,6 @@ XamarinAndroidApplicationProject CreateApplicationProject ()
return proj;
}

[Test]
[Retry (Retry)]
public void Build_From_Clean_DontIncludeRestore ()
{
AssertCommercialBuild (); // If <BuildApk/> runs, this test will fail without Fast Deployment

var proj = CreateApplicationProject ();
using (var builder = CreateBuilderWithoutLogFile ()) {
builder.AutomaticNuGetRestore = false;
builder.Target = "Build";
builder.Restore (proj);
Profile (builder, b => b.Build (proj));
}
}

[Test]
[Retry (Retry)]
public void Build_No_Changes ()
Expand Down Expand Up @@ -255,29 +261,6 @@ public void Build_AndroidAsset_Change ()
}
}

[Test]
[Retry (Retry)]
public void Build_JLO_Change ()
{
AssertCommercialBuild (); // If <BuildApk/> runs, this test will fail without Fast Deployment

var className = "Foo";
var proj = CreateApplicationProject ();
proj.Sources.Add (new BuildItem.Source ("Foo.cs") {
TextContent = () => $"class {className} : Java.Lang.Object {{}}"
});
using (var builder = CreateBuilderWithoutLogFile ()) {
builder.Target = "Build";
builder.Build (proj);
builder.AutomaticNuGetRestore = false;

// Profile Java.Lang.Object rename
className = "Foo2";
proj.Touch ("Foo.cs");
Profile (builder, b => b.Build (proj));
}
}

[Test]
[Retry (Retry)]
public void Build_AndroidManifest_Change ()
Expand Down
2 changes: 0 additions & 2 deletions tests/msbuild-times-reference/MSBuildDeviceIntegration.csv
Original file line number Diff line number Diff line change
Expand Up @@ -2,13 +2,11 @@
# First non-comment row is human description of columns
Test Name,Time in ms (int)
# Data
Build_From_Clean_DontIncludeRestore,13000
Build_No_Changes,2250
Build_CSharp_Change,3500
Build_AndroidResource_Change,2250
Build_AndroidAsset_Change,6500
Build_AndroidManifest_Change,4500
Build_JLO_Change,4500
Build_XAML_Change,3000
Install_CSharp_Change,4000
Install_XAML_Change,3750
Expand Down