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.

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

BuildManager instances acquire its own BuildTelemetry instance (#8444) #8552

Merged
merged 4 commits into from
Mar 11, 2023
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
4 changes: 4 additions & 0 deletions eng/Build.props
Original file line number Diff line number Diff line change
Expand Up @@ -2,9 +2,13 @@
<!-- Copyright (c) .NET Foundation and contributors. All rights reserved. Licensed under the MIT license. See License.txt in the project root for full license information. -->
<Project>

<!-- Commented out as a temporary fix for the msbuild CI.
Waiting for https://github.com/NuGet/NuGet.Client/pull/5010 fix to flow to CI machines. -->
<!--
<PropertyGroup>
<RestoreUseStaticGraphEvaluation Condition="'$(DotNetBuildFromSource)' != 'true'">true</RestoreUseStaticGraphEvaluation>
</PropertyGroup>
-->

<ItemGroup>
<!-- Remove all sln files globbed by arcade so far and add only MSBuild.sln to the build.
Expand Down
2 changes: 1 addition & 1 deletion eng/Versions.props
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@
<!-- Copyright (c) .NET Foundation and contributors. All rights reserved. Licensed under the MIT license. See License.txt in the project root for full license information. -->
<Project>
<PropertyGroup>
<VersionPrefix>17.5.0</VersionPrefix><DotNetFinalVersionKind>release</DotNetFinalVersionKind>
<VersionPrefix>17.5.1</VersionPrefix><DotNetFinalVersionKind>release</DotNetFinalVersionKind>
<PackageValidationBaselineVersion>17.4.0</PackageValidationBaselineVersion>
<AssemblyVersion>15.1.0.0</AssemblyVersion>
<PreReleaseVersionLabel>preview</PreReleaseVersionLabel>
Expand Down
10 changes: 5 additions & 5 deletions src/Build.UnitTests/BackEnd/KnownTelemetry_Tests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -15,19 +15,19 @@ public class KnownTelemetry_Tests
[Fact]
public void BuildTelemetryCanBeSetToNull()
{
KnownTelemetry.BuildTelemetry = new BuildTelemetry();
KnownTelemetry.BuildTelemetry = null;
KnownTelemetry.PartialBuildTelemetry = new BuildTelemetry();
KnownTelemetry.PartialBuildTelemetry = null;

KnownTelemetry.BuildTelemetry.ShouldBeNull();
KnownTelemetry.PartialBuildTelemetry.ShouldBeNull();
}

[Fact]
public void BuildTelemetryCanBeSet()
{
BuildTelemetry buildTelemetry = new BuildTelemetry();
KnownTelemetry.BuildTelemetry = buildTelemetry;
KnownTelemetry.PartialBuildTelemetry = buildTelemetry;

KnownTelemetry.BuildTelemetry.ShouldBeSameAs(buildTelemetry);
KnownTelemetry.PartialBuildTelemetry.ShouldBeSameAs(buildTelemetry);
}

[Fact]
Expand Down
57 changes: 37 additions & 20 deletions src/Build/BackEnd/BuildManager/BuildManager.cs
Original file line number Diff line number Diff line change
Expand Up @@ -256,6 +256,12 @@ public class BuildManager : INodePacketHandler, IBuildComponentHost, IDisposable
/// </summary>
private IEnumerable<DeferredBuildMessage> _deferredBuildMessages;

/// <summary>
/// Build telemetry to be send when this build ends.
/// <remarks>Could be null</remarks>
/// </summary>
private BuildTelemetry _buildTelemetry;

private ProjectCacheService _projectCacheService;

private bool _hasProjectCacheServiceInitializedVsScenario;
Expand Down Expand Up @@ -504,11 +510,22 @@ public void BeginBuild(BuildParameters parameters)

// Initiate build telemetry data
DateTime now = DateTime.UtcNow;
KnownTelemetry.BuildTelemetry ??= new()

// Acquire it from static variable so we can apply data collected up to this moment
_buildTelemetry = KnownTelemetry.PartialBuildTelemetry;
if (_buildTelemetry != null)
{
KnownTelemetry.PartialBuildTelemetry = null;
}
else
{
StartAt = now,
};
KnownTelemetry.BuildTelemetry.InnerStartAt = now;
_buildTelemetry = new()
{
StartAt = now,
};
}

_buildTelemetry.InnerStartAt = now;

if (BuildParameters.DumpOpportunisticInternStats)
{
Expand Down Expand Up @@ -819,10 +836,10 @@ public BuildSubmission PendBuildRequest(BuildRequestData requestData)

var newSubmission = new BuildSubmission(this, GetNextSubmissionId(), requestData, _buildParameters.LegacyThreadingSemantics);

if (KnownTelemetry.BuildTelemetry != null)
if (_buildTelemetry != null)
{
KnownTelemetry.BuildTelemetry.Project ??= requestData.ProjectFullPath;
KnownTelemetry.BuildTelemetry.Target ??= string.Join(",", requestData.TargetNames);
_buildTelemetry.Project ??= requestData.ProjectFullPath;
_buildTelemetry.Target ??= string.Join(",", requestData.TargetNames);
}

_buildSubmissions.Add(newSubmission.SubmissionId, newSubmission);
Expand All @@ -847,12 +864,12 @@ public GraphBuildSubmission PendBuildRequest(GraphBuildRequestData requestData)

var newSubmission = new GraphBuildSubmission(this, GetNextSubmissionId(), requestData);

if (KnownTelemetry.BuildTelemetry != null)
if (_buildTelemetry != null)
{
// Project graph can have multiple entry points, for purposes of identifying event for same build project,
// we believe that including only one entry point will provide enough precision.
KnownTelemetry.BuildTelemetry.Project ??= requestData.ProjectGraphEntryPoints?.FirstOrDefault().ProjectFile;
KnownTelemetry.BuildTelemetry.Target ??= string.Join(",", requestData.TargetNames);
_buildTelemetry.Project ??= requestData.ProjectGraphEntryPoints?.FirstOrDefault().ProjectFile;
_buildTelemetry.Target ??= string.Join(",", requestData.TargetNames);
}

_graphBuildSubmissions.Add(newSubmission.SubmissionId, newSubmission);
Expand Down Expand Up @@ -998,13 +1015,13 @@ public void EndBuild()

loggingService.LogBuildFinished(_overallBuildSuccess);

if (KnownTelemetry.BuildTelemetry != null)
if (_buildTelemetry != null)
{
KnownTelemetry.BuildTelemetry.FinishedAt = DateTime.UtcNow;
KnownTelemetry.BuildTelemetry.Success = _overallBuildSuccess;
KnownTelemetry.BuildTelemetry.Version = ProjectCollection.Version;
KnownTelemetry.BuildTelemetry.DisplayVersion = ProjectCollection.DisplayVersion;
KnownTelemetry.BuildTelemetry.FrameworkName = NativeMethodsShared.FrameworkName;
_buildTelemetry.FinishedAt = DateTime.UtcNow;
_buildTelemetry.Success = _overallBuildSuccess;
_buildTelemetry.Version = ProjectCollection.Version;
_buildTelemetry.DisplayVersion = ProjectCollection.DisplayVersion;
_buildTelemetry.FrameworkName = NativeMethodsShared.FrameworkName;

string host = null;
if (BuildEnvironmentState.s_runningInVisualStudio)
Expand All @@ -1019,12 +1036,12 @@ public void EndBuild()
{
host = "VSCode";
}
KnownTelemetry.BuildTelemetry.Host = host;
_buildTelemetry.Host = host;

KnownTelemetry.BuildTelemetry.UpdateEventProperties();
loggingService.LogTelemetry(buildEventContext: null, KnownTelemetry.BuildTelemetry.EventName, KnownTelemetry.BuildTelemetry.Properties);
_buildTelemetry.UpdateEventProperties();
loggingService.LogTelemetry(buildEventContext: null, _buildTelemetry.EventName, _buildTelemetry.Properties);
// Clean telemetry to make it ready for next build submission.
KnownTelemetry.BuildTelemetry = null;
_buildTelemetry = null;
}
}

Expand Down
14 changes: 7 additions & 7 deletions src/Build/BackEnd/Client/MSBuildClient.cs
Original file line number Diff line number Diff line change
Expand Up @@ -168,9 +168,9 @@ public MSBuildClientExitResult Execute(CancellationToken cancellationToken)
try
{
bool serverIsAlreadyRunning = ServerIsRunning();
if (KnownTelemetry.BuildTelemetry != null)
if (KnownTelemetry.PartialBuildTelemetry != null)
{
KnownTelemetry.BuildTelemetry.InitialServerState = serverIsAlreadyRunning ? "hot" : "cold";
KnownTelemetry.PartialBuildTelemetry.InitialServerState = serverIsAlreadyRunning ? "hot" : "cold";
}
if (!serverIsAlreadyRunning)
{
Expand Down Expand Up @@ -546,14 +546,14 @@ private ServerNodeBuildCommand GetServerNodeBuildCommand()
// We remove env variable used to invoke MSBuild server as that might be equal to 1, so we do not get an infinite recursion here.
envVars.Remove(Traits.UseMSBuildServerEnvVarName);

Debug.Assert(KnownTelemetry.BuildTelemetry == null || KnownTelemetry.BuildTelemetry.StartAt.HasValue, "BuildTelemetry.StartAt was not initialized!");
Debug.Assert(KnownTelemetry.PartialBuildTelemetry == null || KnownTelemetry.PartialBuildTelemetry.StartAt.HasValue, "BuildTelemetry.StartAt was not initialized!");

PartialBuildTelemetry? partialBuildTelemetry = KnownTelemetry.BuildTelemetry == null
PartialBuildTelemetry? partialBuildTelemetry = KnownTelemetry.PartialBuildTelemetry == null
? null
: new PartialBuildTelemetry(
startedAt: KnownTelemetry.BuildTelemetry.StartAt.GetValueOrDefault(),
initialServerState: KnownTelemetry.BuildTelemetry.InitialServerState,
serverFallbackReason: KnownTelemetry.BuildTelemetry.ServerFallbackReason);
startedAt: KnownTelemetry.PartialBuildTelemetry.StartAt.GetValueOrDefault(),
initialServerState: KnownTelemetry.PartialBuildTelemetry.InitialServerState,
serverFallbackReason: KnownTelemetry.PartialBuildTelemetry.ServerFallbackReason);

return new ServerNodeBuildCommand(
_commandLine,
Expand Down
12 changes: 5 additions & 7 deletions src/Build/BackEnd/Node/OutOfProcServerNode.cs
Original file line number Diff line number Diff line change
Expand Up @@ -369,15 +369,13 @@ private void HandleServerNodeBuildCommand(ServerNodeBuildCommand command)
ConsoleConfiguration.Provider = command.ConsoleConfiguration;

// Initiate build telemetry
if (KnownTelemetry.BuildTelemetry == null)
{
KnownTelemetry.BuildTelemetry = new BuildTelemetry();
}
if (command.PartialBuildTelemetry != null)
{
KnownTelemetry.BuildTelemetry.StartAt = command.PartialBuildTelemetry.StartedAt;
KnownTelemetry.BuildTelemetry.InitialServerState = command.PartialBuildTelemetry.InitialServerState;
KnownTelemetry.BuildTelemetry.ServerFallbackReason = command.PartialBuildTelemetry.ServerFallbackReason;
BuildTelemetry buildTelemetry = KnownTelemetry.PartialBuildTelemetry ??= new BuildTelemetry();

buildTelemetry.StartAt = command.PartialBuildTelemetry.StartedAt;
buildTelemetry.InitialServerState = command.PartialBuildTelemetry.InitialServerState;
buildTelemetry.ServerFallbackReason = command.PartialBuildTelemetry.ServerFallbackReason;
}

// Also try our best to increase chance custom Loggers which use Console static members will work as expected.
Expand Down
9 changes: 5 additions & 4 deletions src/Framework/Telemetry/KnownTelemetry.cs
Original file line number Diff line number Diff line change
Expand Up @@ -9,9 +9,10 @@ namespace Microsoft.Build.Framework.Telemetry;
internal static class KnownTelemetry
{
/// <summary>
/// Telemetry for build.
/// If null Telemetry is not supposed to be emitted.
/// After telemetry is emitted, sender shall null it.
/// Partial Telemetry for build.
/// This could be optionally initialized with some values from early in call stack, for example in Main method.
/// After this instance is acquired by a particular build, this is set to null.
/// Null means there are no prior collected build telemetry data, new clean instance shall be created for particular build.
/// </summary>
public static BuildTelemetry? BuildTelemetry { get; set; }
public static BuildTelemetry? PartialBuildTelemetry { get; set; }
}
4 changes: 2 additions & 2 deletions src/MSBuild/MSBuildClientApp.cs
Original file line number Diff line number Diff line change
Expand Up @@ -79,9 +79,9 @@ CancellationToken cancellationToken
exitResult.MSBuildClientExitType == MSBuildClientExitType.UnknownServerState ||
exitResult.MSBuildClientExitType == MSBuildClientExitType.LaunchError)
{
if (KnownTelemetry.BuildTelemetry != null)
if (KnownTelemetry.PartialBuildTelemetry != null)
{
KnownTelemetry.BuildTelemetry.ServerFallbackReason = exitResult.MSBuildClientExitType.ToString();
KnownTelemetry.PartialBuildTelemetry.ServerFallbackReason = exitResult.MSBuildClientExitType.ToString();
}

// Server is busy, fallback to old behavior.
Expand Down
12 changes: 6 additions & 6 deletions src/MSBuild/XMake.cs
Original file line number Diff line number Diff line change
Expand Up @@ -222,7 +222,7 @@ string[] args
DebuggerLaunchCheck();

// Initialize new build telemetry and record start of this build.
KnownTelemetry.BuildTelemetry = new BuildTelemetry { StartAt = DateTime.UtcNow };
KnownTelemetry.PartialBuildTelemetry = new BuildTelemetry { StartAt = DateTime.UtcNow };

using PerformanceLogEventListener eventListener = PerformanceLogEventListener.Create();

Expand Down Expand Up @@ -310,18 +310,18 @@ string[] commandLine
IsInteractiveBuild(commandLineSwitches))
{
canRunServer = false;
if (KnownTelemetry.BuildTelemetry != null)
if (KnownTelemetry.PartialBuildTelemetry != null)
{
KnownTelemetry.BuildTelemetry.ServerFallbackReason = "Arguments";
KnownTelemetry.PartialBuildTelemetry.ServerFallbackReason = "Arguments";
}
}
}
catch (Exception ex)
{
CommunicationsUtilities.Trace("Unexpected exception during command line parsing. Can not determine if it is allowed to use Server. Fall back to old behavior. Exception: {0}", ex);
if (KnownTelemetry.BuildTelemetry != null)
if (KnownTelemetry.PartialBuildTelemetry != null)
{
KnownTelemetry.BuildTelemetry.ServerFallbackReason = "ErrorParsingCommandLine";
KnownTelemetry.PartialBuildTelemetry.ServerFallbackReason = "ErrorParsingCommandLine";
}
canRunServer = false;
}
Expand Down Expand Up @@ -633,7 +633,7 @@ string[] commandLine
DebuggerLaunchCheck();

// Initialize new build telemetry and record start of this build, if not initialized already
KnownTelemetry.BuildTelemetry ??= new BuildTelemetry { StartAt = DateTime.UtcNow };
KnownTelemetry.PartialBuildTelemetry ??= new BuildTelemetry { StartAt = DateTime.UtcNow };

// Indicate to the engine that it can toss extraneous file content
// when it loads microsoft.*.targets. We can't do this in the general case,
Expand Down