Improve debugging experience: add global switch MSBuildDebugEngine; Inject binary logger from BuildManager; print static graph as .dot file #6639

cdmihai · 2021-06-29T21:25:13Z

Context

There's still a bit of friction when debugging MSBuild, especially under VS. You have to set multiple env vars, or search through temp, find all the obscure env var names, etc

Changes Made

add one env var, MSBuildDebugEngine to turn everything on and also automatically pick ./MSBuild_Logs as the debug log path for everything that spews out log files.
in addition, when MSBuildDebugEngine:
- inject a binary logger directly from the build manager. This is super useful when running MSBuild in VS, as the build logging that VS gives is kind of lacking
- dump a .dot representation of the static graph, when one is available

This is how MSBuild_Logs looks like after doing a build (both VS and cmdline should produce this):

Forgind

I think this looks good and helpful 🙂

Forgind · 2021-07-05T18:01:48Z

src/Build/BackEnd/BuildManager/BuildManager.cs

@@ -486,7 +488,7 @@ public void BeginBuild(BuildParameters parameters)
            ILoggingService InitializeLoggingService()
            {
                ILoggingService loggingService = CreateLoggingService(
-                    _buildParameters.Loggers,
+                    (_buildParameters.Loggers ?? Enumerable.Empty<ILogger>()).Concat(GetDebuggingLoggers()),


Why do you need to concat something to empty as opposed to just taking GetDebuggingLoggers()?

If buildParam.Loggers is not null, then I need to concat with the method. If it is null, I need to take just the method. This was the shortest way I found to express it.

This is very concise but since it's just for us, I'd rather see something like

Suggested change

(_buildParameters.Loggers ?? Enumerable.Empty<ILogger>()).Concat(GetDebuggingLoggers()),

AppendDebuggingLoggers(_buildParameters.Loggers),

so we have neither linq nor the empty enumerables in the main path.

Forgind · 2021-07-05T18:03:11Z

src/Build/BackEnd/BuildManager/BuildManager.cs

+            // VS builds discard many msbuild events so attach a binlogger to capture them all.
+            IEnumerable<ILogger> GetDebuggingLoggers()
+            {
+                if (CurrentProcessMatchesDebugName() is false ||


Why do you need to say is false? Aren't there non-nullable bools?

Just style preference, has nothing to do with nullability.

I prefer !CurrentProcessMatchesDebugName, but that's fine. This is probably more readable, to be honest.

src/Build/BackEnd/BuildManager/BuildManager.cs

src/Shared/Traits.cs

Forgind · 2021-07-05T18:22:53Z

src/Shared/Debugging/DebugUtils.cs

+            }
+        });
+
+        public static string ProcessInfoString


Does this have to be => rather than =? I don't see the difference here.

Good point, everything in the expression should be constant throughout process lifetime.

src/Shared/Traits.cs

src/Build/BackEnd/Components/Scheduler/Scheduler.cs

cdmihai · 2021-07-13T18:54:08Z

src/Shared/ExceptionHandling.cs

@@ -41,7 +45,15 @@ static ExceptionHandling()
        /// <returns></returns>
        private static string GetDebugDumpPath()
        {
-            string debugPath = Environment.GetEnvironmentVariable("MSBUILDDEBUGPATH");
+            string debugPath =
+#if CLR2COMPATIBILITY || MICROSOFT_BUILD_ENGINE_OM_UNITTESTS


@Forgind
Made this change after you signed off. ChangeWaves are not visible to the MICROSOFT_BUILD_ENGINE_OM_UNITTESTS assembly so I had to ifdef it out. The alternative is to move ChangeWaves from Microsoft.Build.Framework into shared sources, but that seems like a bigger change than this one (and it's probably good to refrain from increasing shared sources).

Maybe move the test to Engine.UnitTests? It kinda makes sense that Engine.OM.UnitTests wouldn't be able to see Framework, but I'm not a huge fan of ifdef'ing based on being in a test—to me, it feels like making tests not actually test code, just test similar code. I'll let @benvillalobos opine on the right way to handle ChangeWaves visibility, though.

The entire test assembly ends up depending on ChangeWaves, not just a few tests, so it's not feasible to move tests. Only other solution that I see is to move ChangeWaves into the shared sources directory.

I remember having issues in trying to make changewaves shared. Lots of "This type exists multiple times" issues. If you can move it with no issues then by all means. It's unrelated to what this PR is doing so I'd say make an issue for it but don't let it block.

Add a comment and this is fine by me.

benvillalobos · 2021-07-14T19:40:19Z

Can you add this PR to the changewaves doc?

src/Shared/Debugging/DebugUtils.cs

rainersigwald · 2021-07-14T20:11:32Z

src/Build/BackEnd/BuildManager/BuildManager.cs

@@ -486,7 +488,7 @@ public void BeginBuild(BuildParameters parameters)
            ILoggingService InitializeLoggingService()
            {
                ILoggingService loggingService = CreateLoggingService(
-                    _buildParameters.Loggers,
+                    (_buildParameters.Loggers ?? Enumerable.Empty<ILogger>()).Concat(GetDebuggingLoggers()),


This is very concise but since it's just for us, I'd rather see something like

Suggested change

(_buildParameters.Loggers ?? Enumerable.Empty<ILogger>()).Concat(GetDebuggingLoggers()),

AppendDebuggingLoggers(_buildParameters.Loggers),

so we have neither linq nor the empty enumerables in the main path.

rainersigwald · 2021-07-14T20:12:42Z

src/Build/BackEnd/BuildManager/BuildManager.cs

+            // VS builds discard many msbuild events so attach a binlogger to capture them all.
+            IEnumerable<ILogger> GetDebuggingLoggers()


cc @drewnoakes on this since it interacts with project-system-tools

@rainersigwald do you have any expectation of consequence here, or is this just an FYI?

Just an FYI. We should happily handle having multiple loggers attached and everything should continue working as it is, but these logs might be helpful in some cases.

src/Build/BackEnd/BuildManager/BuildManager.cs

rainersigwald · 2021-07-14T20:17:57Z

src/Shared/ExceptionHandling.cs

@@ -41,7 +45,15 @@ static ExceptionHandling()
        /// <returns></returns>
        private static string GetDebugDumpPath()
        {
-            string debugPath = Environment.GetEnvironmentVariable("MSBUILDDEBUGPATH");
+            string debugPath =
+#if CLR2COMPATIBILITY || MICROSOFT_BUILD_ENGINE_OM_UNITTESTS


Add a comment and this is fine by me.

shyamnamboodiripad · 2021-08-19T06:58:31Z

src/Shared/Debugging/DebugUtils.cs

+        static DebugUtils()
+        {
+            string environmentDebugPath = Environment.GetEnvironmentVariable("MSBUILDDEBUGPATH");
+            var debugDirectory = environmentDebugPath ?? Path.Combine(Directory.GetCurrentDirectory(), "MSBuild_Logs");


@rainersigwald @cdmihai I encountered the following unhandled exception when this code was executed from within our service hub process where we invoke MSBulild programmatically -

I had set the MSBuildDebugEngine environment variable (and we have our own BinaryLogger specified programmatically. But I had not set MSBuildDebugPath.

System.UnauthorizedAccessException: Access to the path 'C:\Program Files\Microsoft Visual Studio\2022\Main\Common7\ServiceHub\Hosts\ServiceHub.Host.CLR.AnyCPU\MSBuild_Logs' is denied. HResult='-2147024891' at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath) at System.IO.Directory.InternalCreateDirectory(String fullPath, String path, Object dirSecurityObj, Boolean checkHost) at System.IO.Directory.InternalCreateDirectoryHelper(String path, Boolean checkHost) at Microsoft.Build.Shared.FileUtilities.EnsureDirectoryExists(String directoryPath) at Microsoft.Build.Shared.Debugging.DebugUtils..cctor() --- System.TypeInitializationException: The type initializer for 'Microsoft.Build.Shared.Debugging.DebugUtils' threw an exception. HResult='-2146233036' at Microsoft.Build.Internal.CommunicationsUtilities.GetEnvironmentVariables() at Microsoft.Build.Internal.Utilities.GetEnvironmentProperties() at Microsoft.Build.Evaluation.ProjectCollection.get_EnvironmentProperties() at Microsoft.Build.Evaluation.ProjectCollection.InitializeToolsetCollection(ToolsetRegistryReader registryReader, ToolsetConfigurationReader configReader) at Microsoft.Build.Evaluation.ProjectCollection..ctor(IDictionary`2 globalProperties, IEnumerable`1 loggers, IEnumerable`1 remoteLoggers, ToolsetDefinitionLocations toolsetDefinitionLocations, Int32 maxNodeCount, Boolean onlyLogCriticalEvents, Boolean loadProjectsReadOnly) at Microsoft.Build.Evaluation.ProjectCollection.get_GlobalProjectCollection()

Not a huge issue but now that I know about MSBuildDebugPath :) But have you considered moving the default location to something like %temp% at least for programmatic invocations so that it is harder to run into problems like above?

Temp dir makes it a worse experience when debugging, as we're usually cd-ed into some repo directory when setting MSBuildDebugEngine and it's nice to just get all the logs there. Rather than forcing everybody to look into tmp, or forcing everybody to set MSBuildDebugPath, maybe the option that maximizes global experience is to only have users that do not propagate the user's CWD set MSBuildDebugPath.

That being said, wouldn't it be "more correct" to propagate the user's CWD to the service hub process?

davkean · 2021-08-26T08:39:25Z

@cdmihai This appears to have regressed VS: https://devdiv.visualstudio.com/DevDiv/_workitems/edit/1386501

rainersigwald · 2021-08-26T14:14:10Z

Let's go ahead and revert this until we can chase the problems down. I think the only thing that really needs to change is the moved default emergency-stack-dump-text-file location.

…ngine; Inject binary logger from BuildManager; print static graph as .dot file (dotnet#6639)" This reverts commit cdb5077. Conflicts: documentation/wiki/ChangeWaves.md src/Build/BackEnd/Components/Scheduler/Scheduler.cs src/Shared/Traits.cs

In #6639 I thought it would be a good idea to always expose exceptions by always setting msbuild's debug path, fallbacking to the current working directory. But that's a breaking change. Also, some processes (like VS helpers) do not propagate the user's CWD and thus end up writing under Program Files which fails with permission exceptions. So only set the debug path to the current working directory when `MSBuildDebugEngine` is set.

cdmihai changed the title ~~Debugging improvements~~ Improve debugging experience Jun 29, 2021

cdmihai force-pushed the improveDebugging branch from ed05a8b to 45f2eb3 Compare June 30, 2021 01:09

Forgind approved these changes Jul 5, 2021

View reviewed changes

Forgind approved these changes Jul 13, 2021

View reviewed changes

cdmihai force-pushed the improveDebugging branch from f406bb4 to fe59e40 Compare July 13, 2021 18:51

cdmihai commented Jul 13, 2021

View reviewed changes

rainersigwald approved these changes Jul 14, 2021

View reviewed changes

Extract out useful DebugUtils

65b4817

cdmihai changed the title ~~Improve debugging experience~~ Improve debugging experience: add global switch MSBuildDebugEngine; Inject binary logger from BuildManager; print static graph as .dot file Jul 23, 2021

cdmihai force-pushed the improveDebugging branch from 915f4b3 to 4e39ec5 Compare July 23, 2021 17:19

cdmihai added 18 commits July 23, 2021 20:59

Extract engine debug flags

b1f0007

Improve VS debugging by injecting binlogger in build manager

b2fa640

Dump project graph

ad490eb

Make access to debug flags uniform and under change wave

93228cc

Fix failing test

503fb17

use field TestEnvironment in XMake_Tests

ddc3fee

Remove redundant type specifier

84908ae

Inline out var declarations

4edc6aa

use type keyword

d518245

Remove redundant code

7277582

Misc cleanup

ed4aab3

update change waves

77fee95

Fix appending to file name

0a120a4

Remove Linq from non-debugging path

732c92b

Cache check whether to debug current process

f4611b0

Document ifdef

d0f2981

Propagate debug path to out of proc nodes

bb65c38

Remove unused fields

aa5d749

cdmihai force-pushed the improveDebugging branch from 4e39ec5 to aa5d749 Compare July 24, 2021 03:59

Forgind added the merge-when-branch-open PRs that are approved, except that there is a problem that means we are not merging stuff right now. label Jul 26, 2021

ladipro merged commit cdb5077 into dotnet:main Jul 26, 2021

ManickaP mentioned this pull request Aug 18, 2021

MSBuild_Logs directories created in source tree under normal operations #6772

Closed

shyamnamboodiripad reviewed Aug 19, 2021

View reviewed changes

cdmihai deleted the improveDebugging branch August 19, 2021 17:39

rainersigwald mentioned this pull request Aug 26, 2021

Revert MSBuildDebugEngine #6787

Closed

cdmihai mentioned this pull request Aug 28, 2021

Only set debug path when MSBuildDebugEngine is set #6792

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Improve debugging experience: add global switch MSBuildDebugEngine; Inject binary logger from BuildManager; print static graph as .dot file #6639

Improve debugging experience: add global switch MSBuildDebugEngine; Inject binary logger from BuildManager; print static graph as .dot file #6639

cdmihai commented Jun 29, 2021 •

edited

Loading

Forgind left a comment

Forgind Jul 5, 2021

cdmihai Jul 13, 2021

rainersigwald Jul 14, 2021

Forgind Jul 5, 2021

cdmihai Jul 13, 2021

Forgind Jul 13, 2021

Forgind Jul 5, 2021

cdmihai Jul 13, 2021

cdmihai Jul 13, 2021 •

edited

Loading

Forgind Jul 13, 2021

cdmihai Jul 14, 2021 •

edited

Loading

benvillalobos Jul 14, 2021

rainersigwald Jul 14, 2021

benvillalobos commented Jul 14, 2021

rainersigwald Jul 14, 2021

rainersigwald Jul 14, 2021

drewnoakes Jul 15, 2021

rainersigwald Jul 15, 2021

rainersigwald Jul 14, 2021

shyamnamboodiripad Aug 19, 2021

cdmihai Aug 19, 2021

davkean commented Aug 26, 2021

rainersigwald commented Aug 26, 2021

	(_buildParameters.Loggers ?? Enumerable.Empty<ILogger>()).Concat(GetDebuggingLoggers()),
	AppendDebuggingLoggers(_buildParameters.Loggers),

		// VS builds discard many msbuild events so attach a binlogger to capture them all.
		IEnumerable<ILogger> GetDebuggingLoggers()

Improve debugging experience: add global switch MSBuildDebugEngine; Inject binary logger from BuildManager; print static graph as .dot file #6639

Improve debugging experience: add global switch MSBuildDebugEngine; Inject binary logger from BuildManager; print static graph as .dot file #6639

Conversation

cdmihai commented Jun 29, 2021 • edited Loading

Context

Changes Made

Forgind left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cdmihai Jul 13, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cdmihai Jul 14, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

benvillalobos commented Jul 14, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

davkean commented Aug 26, 2021

rainersigwald commented Aug 26, 2021

cdmihai commented Jun 29, 2021 •

edited

Loading

cdmihai Jul 13, 2021 •

edited

Loading

cdmihai Jul 14, 2021 •

edited

Loading