in Public/Src/Engine/Dll/Engine.cs [1740:2243]
private BuildXLEngineResult DoRun(LoggingContext loggingContext, EngineState engineState = null, bool disposeFrontEnd = true)
{
Contract.Requires(engineState == null || Configuration.Engine.ReuseEngineState);
if (m_distributionService != null && !m_distributionService.Initialize())
{
return BuildXLEngineResult.Failed(engineState);
}
if (Configuration.Experiment.ForceContractFailure)
{
Contract.Assert(false, "Assert induced by /exp:ForceContractFailure on command line.");
}
if (!OperatingSystemHelper.IsUnixOS)
{
if (TestHooks == null || TestHooks.DoWarnForVirusScan)
{
WarnForVirusScan(loggingContext, Configuration.Layout);
}
}
else
{
if (Configuration.Layout.EmitSpotlightIndexingWarning)
{
CheckArtifactFolersAndEmitNoIndexWarning(
Context.PathTable,
loggingContext,
Configuration.Layout.ObjectDirectory,
Configuration.Layout.CacheDirectory,
Configuration.Layout.FrontEndDirectory,
Configuration.Layout.EngineCacheDirectory);
}
// Make sure we are running on a case-insensitive file system in the macOS/Unix case for the time being
if (FileUtilities.IsFileSystemCaseSensitive())
{
// The Linux version is still experimental so we are willing to run on a case-sensitive filesystem;
// otherwise, be conservative and fail if the filesystem is case sensitive.
if (!OperatingSystemHelper.IsLinuxOS)
{
Logger.Log.ErrorCaseSensitiveFileSystemDetected(loggingContext);
return BuildXLEngineResult.Failed(engineState);
}
}
}
// Changing the min count of threads in the thread pool to speed-up CPU and IO intensive operations during front-end phase.
ThreadPoolHelper.ConfigureWorkerThreadPools(Configuration.Schedule.MaxProcesses, Configuration.FrontEnd.ThreadPoolMinThreadCountMultiplier());
ConfigureServicePointManager();
EngineState newEngineState = null;
bool success = true;
using (var pm = PerformanceMeasurement.StartWithoutStatistic(
loggingContext,
Logger.Log.StartEngineRun,
Logger.Log.EndEngineRun))
{
var engineLoggingContext = pm.LoggingContext;
bool directoryDeletionLockSuccess;
using (CreateOutputDirectories(Context.PathTable, engineLoggingContext, out directoryDeletionLockSuccess))
{
if (!directoryDeletionLockSuccess)
{
Contract.Assume(engineLoggingContext.ErrorWasLogged, "An error should have been logged during output directory creation.");
return BuildXLEngineResult.Failed(engineState);
}
// Once output directories including MoveDeleteTempDirectory have been created,
// create a TempCleaner for cleaning all temp directories
m_tempCleaner = new TempCleaner(engineLoggingContext, tempDirectory: m_moveDeleteTempDirectory);
using (
var objFolderLock = FolderLock.Take(
engineLoggingContext,
Configuration.Layout.ObjectDirectory.ToString(Context.PathTable),
Configuration.Engine.BuildLockPollingIntervalSec,
Configuration.Engine.BuildLockWaitTimeoutMins))
{
if (!objFolderLock.SuccessfullyCreatedLock)
{
Contract.Assume(engineLoggingContext.ErrorWasLogged, "An error should have been logged during folder lock acquisition.");
return BuildXLEngineResult.Failed(engineState);
}
using (
var engineCacheLock = FolderLock.Take(
engineLoggingContext,
Configuration.Layout.EngineCacheDirectory.ToString(Context.PathTable),
Configuration.Engine.BuildLockPollingIntervalSec,
Configuration.Engine.BuildLockWaitTimeoutMins))
{
if (!engineCacheLock.SuccessfullyCreatedLock)
{
Contract.Assume(engineLoggingContext.ErrorWasLogged, "An error should have been logged during folder lock acquisition.");
return BuildXLEngineResult.Failed(engineState);
}
if (!LogAndValidateConfiguration(engineLoggingContext))
{
Contract.Assume(engineLoggingContext.ErrorWasLogged, "An error should have been logged during configuration validation.");
return BuildXLEngineResult.Failed(engineState);
}
var recovery = FailureRecoveryFactory.Create(engineLoggingContext, Context.PathTable, Configuration);
bool recoveryStatus = recovery.TryRecoverIfNeeded();
var mountsTable = MountsTable.CreateAndRegister(loggingContext, Context, Configuration, m_initialCommandLineConfiguration.Startup.Properties);
var volumeMap = TryGetVolumeMapOfAllLocalVolumes(pm, mountsTable, loggingContext);
var journalState = GetJournalStateWithVolumeMap(volumeMap, loggingContext);
if (!OperatingSystemHelper.IsUnixOS)
{
if (volumeMap == null)
{
return BuildXLEngineResult.Failed(engineState);
}
}
m_fileContentTask = LoadFileContentTableAsync(engineState, engineLoggingContext);
EngineSchedule engineSchedule = null;
// Task representing the async initialization of this engine's cache.
// Cache initialization can be long-running, so we pass around this init task so that consumers can choose
// to wait on close to when it is actually needed.
CacheInitializationTask cacheInitializationTask = null;
ConstructScheduleResult constructScheduleResult = ConstructScheduleResult.None;
if (Configuration.Engine.TrackBuildsInUserFolder &&
!Configuration.InCloudBuild() &&
Configuration.Distribution.BuildRole == DistributedBuildRoles.None)
{
using (Context.EngineCounters.StartStopwatch(EngineCounter.RecordingBuildsInUserFolderDuration))
{
var primaryConfigFile = Configuration.Layout.PrimaryConfigFile.ToString(Context.PathTable);
var logsDirectory = Configuration.Logging.LogsDirectory.ToString(Context.PathTable);
var binDirectory = Configuration.Layout.BuildEngineDirectory.ToString(Context.PathTable);
if (m_translator != null)
{
primaryConfigFile = m_translator.Translate(primaryConfigFile);
logsDirectory = m_translator.Translate(logsDirectory);
binDirectory = m_translator.Translate(binDirectory);
}
new Invocations().RecordInvocation(
loggingContext,
new Invocations.Invocation(
loggingContext.Session.Id,
m_processStartTimeUtc,
primaryConfigFile,
logsDirectory,
m_buildVersion,
binDirectory,
m_commitId
));
if (Configuration.Viewer == ViewerMode.Show)
{
LaunchBuildExplorer(loggingContext, binDirectory);
}
}
}
try
{
if (Configuration.Distribution.BuildRole == DistributedBuildRoles.Worker)
{
if (!m_workerService.WaitForOrchestratorAttach())
{
// Worker timeout logs a warning but no error. It is not considered a failure wrt the worker
Contract.Assert(
engineLoggingContext.ErrorWasLogged,
"An error should have been logged during waiting for attaching to the orchestrator.");
return BuildXLEngineResult.Failed(engineState);
}
}
cacheInitializationTask = CacheInitializer.GetCacheInitializationTask(
loggingContext,
Context.PathTable,
Configuration.Layout.CacheDirectory.ToString(Context.PathTable),
Configuration.Cache,
rootTranslator: m_rootTranslator,
recoveryStatus: recoveryStatus,
cancellationToken: Context.CancellationToken,
testHookCacheFactory: TestHooks?.CacheFactory);
// When distribution is on, we have to finish initializing the EngineCache right away.
// (rather than trying to defer waiting as much as possible).
// Ensure the EngineCache initialized correctly if this is a distributed build
if (Configuration.Distribution.BuildRole != DistributedBuildRoles.None)
{
Possible<CacheInitializer> possibleCacheInitializerForDistribution =
cacheInitializationTask.GetAwaiter().GetResult();
if (!possibleCacheInitializerForDistribution.Succeeded)
{
// StorageCacheStartupError has been logged by CacheInitializer
Logger.Log.ErrorCacheDisabledDistributedBuild(engineLoggingContext);
return BuildXLEngineResult.Failed(engineState);
}
}
RootFilter rootFilter;
constructScheduleResult = ConstructSchedule(
loggingContext,
Configuration.FrontEnd.MaxFrontEndConcurrency(),
cacheInitializationTask,
journalState,
engineState,
out engineSchedule,
out rootFilter);
success &= constructScheduleResult != ConstructScheduleResult.Failure;
bool exitOnNewGraph = constructScheduleResult == ConstructScheduleResult.ExitOnNewGraph;
if (exitOnNewGraph)
{
Context.EngineCounters.AddToCounter(EngineCounter.ExitOnNewGraph, 1);
}
ValidateSuccessMatches(success, engineLoggingContext);
var phase = Configuration.Engine.Phase;
if (success && phase.HasFlag(EnginePhases.Schedule) && Configuration.Ide.IsEnabled)
{
Contract.Assert(engineSchedule != null);
if (Configuration.Ide.IsNewEnabled)
{
IdeGenerator.Generate(
engineSchedule.Context,
engineSchedule.Scheduler.PipGraph,
engineSchedule.Scheduler.ScheduledGraph,
m_initialCommandLineConfiguration.Startup.ConfigFile,
Configuration.Ide);
}
else
{
BuildXL.Ide.Generator.Old.IdeGenerator.Generate(
engineSchedule.Context,
engineSchedule.Scheduler.PipGraph,
engineSchedule.Scheduler.ScheduledGraph,
m_initialCommandLineConfiguration.Startup.ConfigFile,
Configuration.Ide);
}
}
// Front end is no longer needed and can be clean-up before moving to a next phase.
// It make no sense to check for error case.
// If there is an error, the process will be closed any way.
if (disposeFrontEnd)
{
CleanUpFrontEndOnSuccess(success, constructScheduleResult);
}
// Build workers don't allow CleanOnly builds since the orchestrator selects which pips they run
if (success && Configuration.Engine.CleanOnly && Configuration.Distribution.BuildRole != DistributedBuildRoles.Worker)
{
Contract.Assert(
!phase.HasFlag(EnginePhases.Execute),
"CleanOnly in conjunction with executing pips doesn't make sense since output file cleaning happens again before each pip run.");
Contract.Assert(rootFilter != null);
Func<DirectoryArtifact, bool> isOutputDir = artifact =>
{
NodeId node = engineSchedule.Scheduler.PipGraph.GetSealedDirectoryNode(artifact);
SealDirectoryKind sealDirectoryKind = engineSchedule.Scheduler.PipGraph.PipTable.GetSealDirectoryKind(node.ToPipId());
return sealDirectoryKind == SealDirectoryKind.Opaque || sealDirectoryKind == SealDirectoryKind.SharedOpaque;
};
success &= OutputCleaner.DeleteOutputs(
engineLoggingContext,
isOutputDir,
engineSchedule.Scheduler.PipGraph.FilterOutputsForClean(
rootFilter).ToArray(),
Context.PathTable,
m_tempCleaner);
ValidateSuccessMatches(success, engineLoggingContext);
}
// Keep this as close to the Execute phase as possible
if (phase.HasFlag(EnginePhases.Schedule) && !exitOnNewGraph && Configuration.Engine.LogStatistics)
{
BuildXL.Tracing.Logger.Log.Statistic(
engineLoggingContext,
new BuildXL.Tracing.Statistic
{
Name = Statistics.TimeToFirstPipSyntheticMs,
Value = (int)(DateTime.UtcNow - m_processStartTimeUtc).TotalMilliseconds,
});
}
ThreadPoolHelper.ConfigureWorkerThreadPools(Configuration.Schedule.MaxProcesses);
if (success && !exitOnNewGraph && phase.HasFlag(EnginePhases.Execute))
{
Contract.Assert(
phase.HasFlag(EnginePhases.Schedule),
"Must have already scheduled the values. It should be impossible to Execute without scheduling.");
Contract.Assert(engineSchedule != null, "Scheduler is non-null when we are at least in the Schedule phase.");
WorkerService workerservice = null;
if (Configuration.Distribution.BuildRole == DistributedBuildRoles.Worker)
{
workerservice = m_workerService;
}
var stats = default(ExecuteStatistics);
using (var executePhase = StartPhase(
loggingContext,
EnginePhases.Execute,
Logger.Log.ExecutePhaseStart,
(context, executeStats) =>
{
m_enginePerformanceInfo.LimitingResourcePercentages = engineSchedule.Scheduler.ExecutionSampler.GetLimitingResourcePercentages();
Logger.Log.ExecutePhaseComplete(
context,
executeStats,
m_enginePerformanceInfo.LimitingResourcePercentages);
m_enginePerformanceInfo.ExecutePhaseDurationMs = executeStats.ElapsedMilliseconds;
},
() => stats))
{
var executePhaseLoggingContext = executePhase.LoggingContext;
Contract.Assert(
executePhaseLoggingContext.GetRootContext() == loggingContext.GetRootContext(),
"PhaseLoggingContext's root context doesn't match AppLoggingContext's root.");
Contract.Assert(
executePhaseLoggingContext.GetRootContext() == engineLoggingContext.GetRootContext(),
"PhaseLoggingContext's root context doesn't match pm's root.");
success &= engineSchedule.ExecuteScheduledPips(
executePhaseLoggingContext,
workerservice);
ValidateSuccessMatches(success, engineLoggingContext);
}
}
Task<bool> postExecutionTasks = Task.FromResult(true);
// Post execution tasks are only performed on orchestrator.
if (Configuration.Distribution.BuildRole != DistributedBuildRoles.Worker && engineSchedule != null)
{
// Even if the execution phase failed or was skipped, we want to persist / finish persisting some structures like the exported pip graph.
// TODO: Should this also happen in the event we have a fully constructed engine schedule, but e.g. evaluation failures?
// Need to quantify how successful schedule construction was, and branch in ProcessEndOfBuild accordingly.
postExecutionTasks = engineSchedule.ProcessPostExecutionTasksAsync(
loggingContext,
Context,
Configuration,
phase);
}
if (TestHooks == null && !string.IsNullOrEmpty(PipEnvironment.RestrictedTemp))
{
m_tempCleaner.RegisterDirectoryToDelete(PipEnvironment.RestrictedTemp, false);
}
// The file content table should now contain all of the hashes needed for this build.
// At this point we may have failed (but have not exploded), so it is safe to write it out. Note that we might want to write it
// out even if we did not run the execution phase at all, due to file content table usage before then (e.g. cached graph reloading).
var savingFileContentTableTask = FileContentTable.IsStub
? Task.FromResult(true)
: TrySaveFileContentTable(loggingContext);
// Saving file content table and post execution tasks are happening in parallel.
success &= postExecutionTasks.GetAwaiter().GetResult();
success &= savingFileContentTableTask.GetAwaiter().GetResult();
ValidateSuccessMatches(success, engineLoggingContext);
if (!savingFileContentTableTask.Result)
{
Contract.Assert(
engineLoggingContext.ErrorWasLogged,
"An error should have been logged during saving file content table.");
return BuildXLEngineResult.Failed(engineState);
}
}
finally
{
// Ensure the task that saves the graph to the content cache has finished
try
{
m_graphCacheContentCachePut?.GetAwaiter().GetResult();
}
catch (Exception e)
{
BuildXL.Tracing.UnexpectedCondition.Log(loggingContext, e.ToString());
}
// Ensure the execution log supporting graph files have finished copying to the logs directory
m_executionLogGraphCopy?.GetAwaiter().GetResult();
m_previousInputFilesCopy?.GetAwaiter().GetResult();
LogStats(loggingContext, engineSchedule, cacheInitializationTask, constructScheduleResult);
Context.EngineCounters.MeasuredDispose(m_orchestratorService, EngineCounter.OrchestratorServiceDisposeDuration);
Context.EngineCounters.MeasuredDispose(m_workerService, EngineCounter.WorkerServiceDisposeDuration);
if (Configuration.Engine.ReuseEngineState)
{
// There are three places where EngineState get disposed:
// (1) When a new engine schedule is constructed from scratch, we dispose the existing engine state.
// (2) When the graph cache is a hit and BuildXL tries to reload the graph from the engine state, the engine state gets disposed if the engine state and engine cache dir are out-of-sync.
// this happens when the engine cache dir is manually edited externally or another BuildXL build (non-server) changed the engine cache dir during the lifetime of the engine state.
// EngineState.Version property and EngineState file in the engineCache dir allow us to understand whether they are in-sync.
// (3) On creating failed BuildXLEngineResult.
if (engineSchedule != null)
{
// If the build graph is successfully created, then we create one or reuse based on EngineSchedule
newEngineState = engineSchedule.GetOrCreateNewEngineState(engineState);
}
else
{
// If the build is unsuccessful, i.e., engineSchedule is null, and engine state is not disposed,
// then reuse the existing engine, updating the file content table
newEngineState = !EngineState.IsUsable(engineState)
? null
: engineState.WithFileContentTable(FileContentTable);
}
Contract.Assert(newEngineState == null || ReferenceEquals(FileContentTable, newEngineState.FileContentTable), "The file content table wasn't correctly updated");
Contract.Assume(EngineState.CorrectEngineStateTransition(engineState, newEngineState, out var incorrectMessage), incorrectMessage);
}
if (engineSchedule != null)
{
// We cannot dispose the PipTable in the EngineSchedule if TestHooks or Visualization is enabled.
// We transfer PipTable ownership to TestHooks or EngineLiveVisualizationInformation if at least one of them are enabled.
if (TestHooks?.Scheduler != null)
{
var isTransferred = engineSchedule.TransferPipTableOwnership(TestHooks.Scheduler.Value.PipGraph.PipTable);
Contract.Assume(isTransferred);
}
// Dispose engineSchedule before disposing EngineCache
// Do not move this statement after engineCacheInitialization.GetAwaiter().GetResult() below
engineSchedule.Dispose();
}
using (Context.EngineCounters.StartStopwatch(EngineCounter.EngineCacheInitDisposeDuration))
{
// ReSharper disable once ReturnValueOfPureMethodIsNotUsed
cacheInitializationTask?.GetAwaiter().GetResult().Then(
cacheInitializer =>
{
// Check for successful cache session close, otherwise fail the build
Possible<string, Failure> cacheCloseResult = cacheInitializer.Close();
if (!cacheCloseResult.Succeeded)
{
Logger.Log.CacheSessionCloseFailed(
loggingContext,
cacheCloseResult.Failure.DescribeIncludingInnerFailures());
success = false;
}
Context.EngineCounters.MeasuredDispose(cacheInitializer, EngineCounter.EngineCacheDisposeDuration);
return Unit.Void;
});
}
cacheInitializationTask?.Dispose();
if (m_snapshotCollector != null)
{
using (Context.EngineCounters.StartStopwatch(EngineCounter.SnapshotCollectorPersistDuration))
{
success &= m_snapshotCollector.Persist(Configuration, Context.PathTable, Context.CancellationToken);
ValidateSuccessMatches(success, engineLoggingContext);
}
}
if (Configuration.Engine.LogStatistics)
{
Context.EngineCounters.LogAsStatistics("Engine", loggingContext);
}
}
} // End of EngineCache mutex lock
} // End of object directory mutex Lock
} // End of output directory deletion lock
} // End of perf measurement
if (ShouldUpgradeFileAccessWarningsToHighLevelError(Configuration) &&
m_trackingEventListener != null &&
((m_trackingEventListener.CountsPerEventId((int)BuildXL.Scheduler.Tracing.LogEventId.FileMonitoringWarning) != 0) ||
(m_trackingEventListener.CountsPerEventId((int)BuildXL.Processes.Tracing.LogEventId.PipProcessDisallowedNtCreateFileAccessWarning) != 0)))
{
Logger.Log.FileAccessErrorsExist(loggingContext);
success = false;
}
ValidateSuccessMatches(success, loggingContext);
return BuildXLEngineResult.Create(
success,
m_enginePerformanceInfo,
previousState: engineState,
newState: newEngineState,
shouldDisposePreviousEngineState: false /* Engine state can still be usable. */);
}