Skip to content

Commit

Permalink
Merge pull request #3027 from natidea/nominateLogging
Browse files Browse the repository at this point in the history
Add logging for NuGetRestorer
  • Loading branch information
natidea authored Dec 7, 2017
2 parents 6316e99 + d7db794 commit 6d0159e
Showing 1 changed file with 94 additions and 1 deletion.
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
using System.Threading.Tasks;
using System.Threading.Tasks.Dataflow;
using Microsoft.Internal.Performance;
using Microsoft.VisualStudio.ProjectSystem.Logging;
using Microsoft.VisualStudio.ProjectSystem.Properties;
using Microsoft.VisualStudio.ProjectSystem.Utilities;
using NuGet.SolutionRestoreManager;
Expand All @@ -23,6 +24,7 @@ internal class NuGetRestorer : OnceInitializedOnceDisposedAsync
private readonly IActiveConfiguredProjectsProvider _activeConfiguredProjectsProvider;
private readonly IActiveConfiguredProjectSubscriptionService _activeConfiguredProjectSubscriptionService;
private readonly IActiveProjectConfigurationRefreshService _activeProjectConfigurationRefreshService;
private readonly IProjectLogger _logger;
private IDisposable _targetFrameworkSubscriptionLink;
private DisposableBag _designTimeBuildSubscriptionLink;

Expand All @@ -46,14 +48,16 @@ public NuGetRestorer(
IVsSolutionRestoreService solutionRestoreService,
IActiveConfiguredProjectSubscriptionService activeConfiguredProjectSubscriptionService,
IActiveProjectConfigurationRefreshService activeProjectConfigurationRefreshService,
IActiveConfiguredProjectsProvider activeConfiguredProjectsProvider)
IActiveConfiguredProjectsProvider activeConfiguredProjectsProvider,
IProjectLogger logger)
: base(projectVsServices.ThreadingService.JoinableTaskContext)
{
_projectVsServices = projectVsServices;
_solutionRestoreService = solutionRestoreService;
_activeConfiguredProjectSubscriptionService = activeConfiguredProjectSubscriptionService;
_activeProjectConfigurationRefreshService = activeProjectConfigurationRefreshService;
_activeConfiguredProjectsProvider = activeConfiguredProjectsProvider;
_logger = logger;
}

[ProjectAutoLoad(startAfter: ProjectLoadCheckpoint.ProjectFactoryCompleted)]
Expand Down Expand Up @@ -166,13 +170,16 @@ private Task ProjectPropertyChangedAsync(Tuple<ImmutableList<IProjectValueVersio
_projectVsServices.Project.Services.ProjectAsynchronousTasks
.RegisterAsyncTask(JoinableFactory.RunAsync(async () =>
{
LogProjectRestoreInfo(_projectVsServices.Project.FullPath, projectRestoreInfo);

await _solutionRestoreService
.NominateProjectAsync(_projectVsServices.Project.FullPath, projectRestoreInfo,
_projectVsServices.Project.Services.ProjectAsynchronousTasks.UnloadCancellationToken)
.ConfigureAwait(false);

CodeMarkers.Instance.CodeMarker(CodeMarkerTimerId.PerfPackageRestoreEnd);

CompleteLogProjectRestoreInfo(_projectVsServices.Project.FullPath);
}),
ProjectCriticalOperation.Build | ProjectCriticalOperation.Unload | ProjectCriticalOperation.Rename,
registerFaultHandler: true);
Expand All @@ -192,5 +199,91 @@ private static bool HasTargetFrameworkChanged(IProjectVersionedValue<IProjectSub
}
return false;
}

#region ProjectRestoreInfo Logging

private void LogProjectRestoreInfo(string fullPath, IVsProjectRestoreInfo projectRestoreInfo)
{
if (_logger.IsEnabled)
{
using (IProjectLoggerBatch logger = _logger.BeginBatch())
{
logger.WriteLine();
logger.WriteLine("------------------------------------------");
logger.WriteLine($"BEGIN Nominate Restore for {fullPath}");
logger.IndentLevel++;

logger.WriteLine($"BaseIntermediatePath: {projectRestoreInfo.BaseIntermediatePath}");
logger.WriteLine($"OriginalTargetFrameworks: {projectRestoreInfo.OriginalTargetFrameworks}");
LogTargetFrameworks(logger, projectRestoreInfo.TargetFrameworks as TargetFrameworks);
LogReferenceItems(logger, "Tool References", projectRestoreInfo.ToolReferences as ReferenceItems);

logger.IndentLevel--;
logger.WriteLine();
}
}
}

private void CompleteLogProjectRestoreInfo(string fullPath)
{
if (_logger.IsEnabled)
{
using (IProjectLoggerBatch logger = _logger.BeginBatch())
{
logger.WriteLine();
logger.WriteLine("------------------------------------------");
logger.WriteLine($"COMPLETED Nominate Restore for {fullPath}");
logger.WriteLine();
}
}
}

private void LogTargetFrameworks(IProjectLoggerBatch logger, TargetFrameworks targetFrameworks)
{
logger.WriteLine($"Target Frameworks ({targetFrameworks.Count})");
logger.IndentLevel++;

foreach (var tf in targetFrameworks)
{
LogTargetFramework(logger, tf as TargetFrameworkInfo);
}
logger.IndentLevel--;
}

private void LogTargetFramework(IProjectLoggerBatch logger, TargetFrameworkInfo targetFrameworkInfo)
{
logger.WriteLine(targetFrameworkInfo.TargetFrameworkMoniker);
logger.IndentLevel++;

LogReferenceItems(logger, "Project References", targetFrameworkInfo.ProjectReferences as ReferenceItems);
LogReferenceItems(logger, "Package References", targetFrameworkInfo.PackageReferences as ReferenceItems);
LogProperties(logger, "Target Framework Properties", targetFrameworkInfo.Properties as ProjectProperties);

logger.IndentLevel--;
}

private void LogProperties(IProjectLoggerBatch logger, string heading, ProjectProperties projectProperties)
{
var properties = projectProperties.Cast<ProjectProperty>()
.Select(prop => $"{prop.Name}:{prop.Value}");
logger.WriteLine($"{heading} -- ({string.Join(" | ", properties)})");
}

private void LogReferenceItems(IProjectLoggerBatch logger, string heading, ReferenceItems references)
{
logger.WriteLine(heading);
logger.IndentLevel++;

foreach (var reference in references)
{
var properties = reference.Properties.Cast<ReferenceProperty>()
.Select(prop => $"{prop.Name}:{prop.Value}");
logger.WriteLine($"{reference.Name} -- ({string.Join(" | ", properties)})");
}

logger.IndentLevel--;
}

#endregion
}
}

0 comments on commit 6d0159e

Please sign in to comment.