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.

Sign up for GitHub

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

Add logging for NuGetRestorer #3027

Merged
merged 1 commit into from
Dec 7, 2017
Merged

Add logging for NuGetRestorer #3027

Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
95 changes: 94 additions & 1 deletion src/Microsoft.VisualStudio.ProjectSystem.Managed.VS/ProjectSystem/VS/NuGet/NuGetRestorer.cs
View file
Open in desktop
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
}
}