public void RestoreTelemetryService_EmitRestoreEvent_IntervalsAreCaptured()
{
// Arrange
var first = "first";
var second = "second";
var telemetrySession = new Mock <ITelemetrySession>();
TelemetryEvent lastTelemetryEvent = null;
telemetrySession
.Setup(x => x.PostEvent(It.IsAny <TelemetryEvent>()))
.Callback <TelemetryEvent>(x => lastTelemetryEvent = x);
var tracker = new IntervalTracker();
tracker.StartIntervalMeasure();
tracker.EndIntervalMeasure(first);
tracker.StartIntervalMeasure();
tracker.EndIntervalMeasure(second);
var operationId = Guid.NewGuid().ToString();
var restoreTelemetryData = new RestoreTelemetryEvent(
operationId,
projectIds: new[] { Guid.NewGuid().ToString() },
source: RestoreOperationSource.OnBuild,
startTime: DateTimeOffset.Now.AddSeconds(-3),
status: NuGetOperationStatus.Succeeded,
packageCount: 1,
noOpProjectsCount: 0,
endTime: DateTimeOffset.Now,
duration: 2.10,
tracker
);
var service = new NuGetVSTelemetryService(telemetrySession.Object);
// Act
service.EmitTelemetryEvent(restoreTelemetryData);
// Assert
Assert.NotNull(lastTelemetryEvent);
Assert.Equal(RestoreTelemetryEvent.RestoreActionEventName, lastTelemetryEvent.Name);
Assert.Equal(12, lastTelemetryEvent.Count);
Assert.Equal(restoreTelemetryData.OperationSource.ToString(), lastTelemetryEvent["OperationSource"].ToString());
Assert.Equal(restoreTelemetryData.NoOpProjectsCount, (int)lastTelemetryEvent["NoOpProjectsCount"]);
Assert.Equal(restoreTelemetryData[first], lastTelemetryEvent[first]);
Assert.Equal(restoreTelemetryData[second], lastTelemetryEvent[second]);
}
public void GetIntervals_WhenStartIntervalIsNotCalled_IntervalsAreEmpty()
{
// Setup
var tracker = new IntervalTracker();
// Act - do nothing
tracker.EndIntervalMeasure("one");
tracker.EndIntervalMeasure("two");
// Assert
var allTimings = tracker.GetIntervals().ToList();
Assert.Equal(2, allTimings.Count);
Assert.True(allTimings.All(e => e.Item2.Equals(0)));
}
public void IntervalTracker_AllIntervalsAreCaptured()
{
// Setup
var tracker = new IntervalTracker();
// Act
tracker.StartIntervalMeasure();
tracker.EndIntervalMeasure("first");
tracker.StartIntervalMeasure();
tracker.EndIntervalMeasure("second");
tracker.StartIntervalMeasure();
tracker.EndIntervalMeasure("third");
// Assert
var allTimings = tracker.GetIntervals().ToList();
Assert.Equal(3, allTimings.Count);
Assert.True(allTimings.Any(e => e.Item1.Equals("first")));
Assert.True(allTimings.Any(e => e.Item1.Equals("second")));
Assert.True(allTimings.Any(e => e.Item1.Equals("third")));
}
private async Task RestorePackageSpecProjectsAsync(
List <IDependencyGraphProject> projects,
bool forceRestore,
bool isSolutionAvailable,
RestoreOperationSource restoreSource,
IntervalTracker intervalTracker,
CancellationToken token)
{
// Only continue if there are some build integrated type projects.
if (!(projects.Any(project => project is BuildIntegratedNuGetProject)))
{
return;
}
if (_packageRestoreConsent.IsGranted)
{
if (!isSolutionAvailable)
{
var globalPackagesFolder = SettingsUtility.GetGlobalPackagesFolder(_settings);
if (!Path.IsPathRooted(globalPackagesFolder))
{
var message = string.Format(
CultureInfo.CurrentCulture,
Resources.RelativeGlobalPackagesFolder,
globalPackagesFolder);
await _logger.WriteLineAsync(VerbosityLevel.Quiet, message);
// Cannot restore packages since globalPackagesFolder is a relative path
// and the solution is not available
return;
}
}
intervalTracker.StartIntervalMeasure();
// Cache p2ps discovered from DTE
var cacheContext = new DependencyGraphCacheContext(_logger, _settings);
var pathContext = NuGetPathContext.Create(_settings);
// Get full dg spec
var(dgSpec, additionalMessages) = await DependencyGraphRestoreUtility.GetSolutionRestoreSpecAndAdditionalMessages(_solutionManager, cacheContext);
intervalTracker.EndIntervalMeasure(RestoreTelemetryEvent.SolutionDependencyGraphSpecCreation);
intervalTracker.StartIntervalMeasure();
// Avoid restoring solutions with zero potential PackageReference projects.
if (DependencyGraphRestoreUtility.IsRestoreRequired(dgSpec))
{
// NOTE: During restore for build integrated projects,
// We might show the dialog even if there are no packages to restore
// When both currentStep and totalSteps are 0, we get a marquee on the dialog
await _logger.RunWithProgressAsync(
async (l, _, t) =>
{
// Display the restore opt out message if it has not been shown yet
await l.WriteHeaderAsync();
var sources = _sourceRepositoryProvider
.GetRepositories()
.ToList();
var providerCache = new RestoreCommandProvidersCache();
Action <SourceCacheContext> cacheModifier = (cache) => { };
var isRestoreOriginalAction = true;
var restoreSummaries = await DependencyGraphRestoreUtility.RestoreAsync(
_solutionManager,
dgSpec,
cacheContext,
providerCache,
cacheModifier,
sources,
_nuGetProjectContext.OperationId,
forceRestore,
isRestoreOriginalAction,
additionalMessages,
l,
t);
_packageCount += restoreSummaries.Select(summary => summary.InstallCount).Sum();
var isRestoreFailed = restoreSummaries.Any(summary => summary.Success == false);
_noOpProjectsCount = restoreSummaries.Where(summary => summary.NoOpRestore == true).Count();
if (isRestoreFailed)
{
_status = NuGetOperationStatus.Failed;
}
else if (_noOpProjectsCount < restoreSummaries.Count)
{
_status = NuGetOperationStatus.Succeeded;
}
},
token);
}
intervalTracker.EndIntervalMeasure(RestoreTelemetryEvent.PackageReferenceRestoreDuration);
}
else if (restoreSource == RestoreOperationSource.Explicit)
{
_logger.ShowError(Resources.PackageRefNotRestoredBecauseOfNoConsent);
}
}
private async Task RestoreAsync(bool forceRestore, RestoreOperationSource restoreSource, CancellationToken token)
{
var startTime = DateTimeOffset.Now;
_status = NuGetOperationStatus.NoOp;
// start timer for telemetry event
var stopWatch = Stopwatch.StartNew();
var intervalTracker = new IntervalTracker();
var projects = Enumerable.Empty <NuGetProject>();
_packageRestoreManager.PackageRestoredEvent += PackageRestoreManager_PackageRestored;
_packageRestoreManager.PackageRestoreFailedEvent += PackageRestoreManager_PackageRestoreFailedEvent;
var sources = _sourceRepositoryProvider.GetRepositories();
using (var packageSourceTelemetry = new PackageSourceTelemetry(sources, _nuGetProjectContext.OperationId, PackageSourceTelemetry.TelemetryAction.Restore))
{
try
{
intervalTracker.StartIntervalMeasure();
var solutionDirectory = _solutionManager.SolutionDirectory;
var isSolutionAvailable = await _solutionManager.IsSolutionAvailableAsync();
// Get the projects from the SolutionManager
// Note that projects that are not supported by NuGet, will not show up in this list
projects = (await _solutionManager.GetNuGetProjectsAsync()).ToList();
if (projects.Any() && solutionDirectory == null)
{
_status = NuGetOperationStatus.Failed;
_logger.ShowError(Resources.SolutionIsNotSaved);
await _logger.WriteLineAsync(VerbosityLevel.Minimal, Resources.SolutionIsNotSaved);
return;
}
intervalTracker.EndIntervalMeasure(RestoreTelemetryEvent.RestoreOperationChecks);
intervalTracker.StartIntervalMeasure();
// Check if there are any projects that are not INuGetIntegratedProject, that is,
// projects with packages.config. OR
// any of the deferred project is type of packages.config, If so, perform package restore on them
if (projects.Any(project => !(project is INuGetIntegratedProject)))
{
await RestorePackagesOrCheckForMissingPackagesAsync(
projects,
solutionDirectory,
isSolutionAvailable,
restoreSource,
token);
}
intervalTracker.EndIntervalMeasure(RestoreTelemetryEvent.PackagesConfigRestore);
var dependencyGraphProjects = projects
.OfType <IDependencyGraphProject>()
.ToList();
await RestorePackageSpecProjectsAsync(
dependencyGraphProjects,
forceRestore,
isSolutionAvailable,
restoreSource,
intervalTracker,
token);
// TODO: To limit risk, we only publish the event when there is a cross-platform PackageReference
// project in the solution. Extending this behavior to all solutions is tracked here:
// NuGet/Home#4478
if (projects.OfType <NetCorePackageReferenceProject>().Any())
{
_restoreEventsPublisher.OnSolutionRestoreCompleted(
new SolutionRestoredEventArgs(_status, solutionDirectory));
}
}
finally
{
_packageRestoreManager.PackageRestoredEvent -= PackageRestoreManager_PackageRestored;
_packageRestoreManager.PackageRestoreFailedEvent -= PackageRestoreManager_PackageRestoreFailedEvent;
await packageSourceTelemetry.SendTelemetryAsync();
stopWatch.Stop();
var duration = stopWatch.Elapsed;
// Do not log any restore message if user disabled restore.
if (_packageRestoreConsent.IsGranted)
{
await _logger.WriteSummaryAsync(_status, duration);
}
else
{
_logger.LogDebug(Resources.PackageRefNotRestoredBecauseOfNoConsent);
}
var protocolDiagnosticsTotals = packageSourceTelemetry.GetTotals();
// Emit telemetry event for restore operation
EmitRestoreTelemetryEvent(
projects,
restoreSource,
startTime,
duration.TotalSeconds,
protocolDiagnosticsTotals,
intervalTracker);
}
}
}