Needs new debugger ... or something

SamB commented 9 years ago

So, um, right now, debugging complex build processes is harder than it has to be:

The (formerly?) experimental MSBUILDDEBUGGING approach is extremely slow, seems brittle, has an unfortunate dependence on Just My Code, and for some scenarios requires running Visual Studio under the debugger. (It's very easy to lose control of the target build process.) However, if you can manage to get to point in the build that you are interested in, it can provide some quite useful information about the state of things at that time.
Log output seems to provide more-or-less enough information, but finding the relevant portions for a complex build, especially one with many recursive invocations, is fairly painful.

So, we could really use a better approach to debugging. Perhaps something based on stepping back and forth through some kind machine-readable of log file?

aolszowka commented 9 years ago

I'm not sure if you're referring to the undocumented/unsupported Registry Key (DebuggerEnabled) discussed here: http://blogs.msdn.com/b/visualstudio/archive/2010/07/06/debugging-msbuild-script-with-visual-studio.aspx

While I agree that debugger is less than ideal, in most cases it seems to meet any needs I've ever run into (even in extremely complex build script scenarios). Is there a particular scenario you're running into that you could describe in better detail?

rainersigwald commented 9 years ago

@aolszowka Can you elaborate on cases where you've found the debugger useful? Since it's never been "officially supported" and since no one on the MSBuild team ever used it to debug build problems and we couldn't find an advocate for it, we're currently planning to remove it entirely from future releases (see for example #144).

SamB commented 9 years ago

@aolszowka: I was referring to that functionality, yes, though it seems to be a lot simpler to just set MSBUILDDEBUGGING=1 in the environment manually rather than mucking about with those registry keys, what with the version-dependence and WoW64 redirection and all that, just to persuade MSBuild to set the very same environment variable.

I've tried it on a few different things, mostly using VS's MSBuild 14.0 release binaries, and kept seeming to lose control of the target; "step over" and "step out" seemed the worst, but on at least one occasion I had "step in" more-or-less hang both the target process and the IDE instance I was running the debugger in (though for some reason they did not use much CPU, and the debugger stopped acting hung once I killed the target).

In one of my earlier attempts to use the feature, I tried it using a self-built copy of MSBuild, and I discovered that it really doesn't work very well when MSBuild is considered "My Code". (Or when "Just My Code" is off.)

It's also quite tricky to figure out which elements could possibly have breakpoints set on them, and I really can't see any way around this that doesn't involve knowing the future (though it would help if there were indicators in the margin for each possible breakpoint in already-loaded code ...)

In conclusion, it seems to me that the main thing that wouldn't be easier and more efficient to implement in a trace-replay-based debugger is to step through Task code, but given the reliance on "Just My Code" that's kind of limited in applicability, too. The other thing is that you don't get UI "for free", and have to either write IDE/editor-specific code or a freestanding tool, but given the quality of the "free" UI, this would probably be more-or-less necessary anyway.

But I'd already seen someone mention removal of this feature as if it were all-but-inevitable, so I didn't think it was really necessary to go into so much detail (if you can call it detail).

MarkStega commented 8 years ago

@rainersigwald @SamB Looking at the various issues it does seem inevitable that the current "experimental" debugger is going away. I want to enforce SamB's comments that some form of debugging beyond trace logging is very desirable. As a relatively new customizer of MSBuild scripts I am finding it exceedingly difficult to follow just how my script it executing. I am having the same 14.0 release issues described above. I know the comment was made the the MSBuild team members don't use the debugger, but that is a select group of MSBuild script experts so it isn't really a valid sample of those who write MSBuild scripts.

drvink commented 8 years ago

It would be nice if this feature were improved rather than dropped, if only for its enormous value in aiding comprehension of the stock MSBuild targets files.

danmoseley commented 7 years ago

OK, I'm going to try to focus this discussion around a proposal. Thoughts?

Motivation

I believe it is time to give debugging another attempt, from a different angle.

Although I have a soft spot in my heart for the VS based debugger, it was finicky and heavyweight. In innumerable hours debugging build process I never used my own debugger. I relied on logs and dumping values with the <Warning> tag. It is slow work and not much has improved since then.

Most of the time I have simple questions:

What is setting this property/adding this item?
What is the value of this property/item list at this point?
Why is this condition true/false?

There are other questions I ask but what I'm proposing could be extended to cover most of them.

Usage

We can get elaborate, but to start simple we need 6 commands and 1 parameter to msbuild.exe

msbuild my.csproj /break:<symbol>

This breaks when a property, item type, metadata type, task or target name, warning or error code, or file location are encountered that match the parameter.

Examples:

msbuild my.csproj /break:OverwriteOnUpload

Also possible:

msbuild my.csproj /break:cloudtest.targets(59)

This would build and break into the console:

Break at cloudtest.targets(59)
>

Get help:

>?
where, show, set, step, break, breaks, go, ??

?? would show descriptions of all the commands - the debugger is completely self documenting.

Get context:

>where
          cloudtest.targets(59): <OverwriteOnUpload Condition="'$(OverwriteOnUpload)' == ''">false</OverwriteOnUpload>

Display property values matching pattern:

>show TestILCZipFileName
default.zip

Items:

>show Reference
System.dll
mscorlib.dll

If it forms a valid condition we show the expansion and evaluation:

>show '$(OverwriteOnUpload)' == ''"
'true' == ''
false

Issued without parameters it would be reasonable for show to operate on any condition on the current tag, and also on the body of it.

>show
'true' == ''
false
false

Set properties:

>set OverwriteOnUpload=

Single step:

>step

>where
cloudtest.targets(60):     <TimeoutInSeconds Condition="'$(TimeoutInSeconds)' == ''">600</TimeoutInSeconds>

List breakpoints:

>breaks
OutputPath
CloudTest.targets(60)

Clear breakpoint (nb: could use a more discoverable syntax)

>break -OutputPath

>breaks
CloudTest.targets(60)

Continue

>go

Normal console logging would interspersed with the debugger commands. (It could be redirected to a file if that was confusing.)

Limitations

These limitations come naturally but allow us to hit the 80% case with something simple and quick to use.

msbuild.exe only. Almost always, a build issue reproduces at the console and it's easier to work there.
single processor only. Race bugs are better diagnosed by another means such as using this logger -- that's something to discuss separately.
line-based. You don't see the full source context as you would in an IDE. I can imagine ways it could be extended in that direction this turns out to be important.
no attach
no stepping into managed code. Instead attach a managed code debugger and set a breakpoint in the managed code

Implementation

This ought to take significantly less time to implement than the VS debugger because it's less ambitious. It should not need pervasive changes - the most tricky thing would be to figure out how to sychronize the console with the build, as they're async. The console logger is also async and ideally we would flush it before emitting debugging text. By wrapping relevant code inside if (debugging){ } there should be no impact to non-debugging scenarios.

Future

Going forward we would add commands based on real world need to keep the set focused and productive. The goal is not to become gdb or ntsd but to be a quick and easy to understand way to jump to the problem in real-world situations.

Other possible commands

tracepoint: breakpoint that logs the break and continues - possibly could dump some value
callstack to show you the current target and, which targets invoked it (whether it was an AfterTargets, DependsOnTargets, BeforeTargets, or CallTarget)

drvink commented 7 years ago

This sounds good overall, but why only a single active breakpoint?

danmoseley commented 7 years ago

@drvink No reason, just keeping it simple.

drvink commented 7 years ago

@danmosemsft Having multiple breakpoints (and the ability to enable/disable them) would be nice so that the user need not juggle them manually. Also, given that msbuild already knows how to evaluate conditions, why not allow for conditional breakpoints?

I appreciate wanting to limit the scope of the feature so as to make easy implementation possible, but part of the value of any interactive debugging facility is not just the ability to examine data, but also to control execution. :)

danmoseley commented 7 years ago

I've updated to allow multiple breakpoints.

@chcosta @joperezr @ericstj would something like this be useful in the majority of the situations you find yourself debugging MSBuild script?

joperezr commented 7 years ago

would something like this be useful in the majority of the situations you find yourself debugging MSBuild script?

This would be super useful! I have more <Message Text='**DEBUGGING MESSAGE=$(SomeProperty)' Importance="High" /> than I can count to check state of properties/items, evaluate conditions, and to tell how many times I enter a target, and when I enter it. One more feature I would love in this debugger would be a callstack-like command. This would show you the current target and, which targets invoked it (whether it was an AfterTargets, DependsOnTargets, BeforeTargets, or CallTarget)

danmoseley commented 7 years ago

For <Message> -- perhaps that needs a tracepoint, ie., when hitting a breakpoint, dump something, and continue.

callstack is clearly interesting, I've recorded above as P2 because it's likely significantly more work.

ericstj commented 7 years ago

I like it. I'd definitely use it. The main reason I never used the VS debugger was that it always took too long to set it up and get everything working. So I usually resort to diag logs and pp files. A self-contained debugger is definitely attractive if it is essentially free to use. In addition to properties, it'd be nice to have a Break task, a Break API, and a Break property function to make it easy to modify various points of code without having to figure out the commandline parameters.

I do think conditional breakpoints are a necessity. A lot of times you have a problem that only reproduces when doing a full stack build. If you set a breakpoint globally it'd be too noisy (for the same reason things are too noisy when looking at the full-stack diag log). You'd want to condition the breakpoint on perhaps project or some other derived property that would only be true in some cases to catch the interesting portion of the build.

Not sure how I feel about limiting it to single-proc. I've hit plenty of multi-proc issues other than the race conditions.

chcosta commented 7 years ago

I've written a few tools to help me investigate logs and essentially parse out a single proc which I care about from the inter-leaved multi-proc logs. So, the interesting thing to me isn't usually multi-proc debugging, but having some mechanism to scope the multi-proc build to a single build thread I care about and determining how I got there. I'm not sure if I'm actually making an argument for multi-proc or single-proc. I am saying that I often have to debug a multi-proc build, but only care about what is happening in one of the procs. I suppose that the way to handle this would be a conditional breakpoint. break at CloudTest.targets(39) if '$(MSBuildProjectName)'=='blah.proj'

Regarding...

1. What is setting this property/adding this item?
2. What is the value of this property/item list at this point?
3. Why is this condition true/false?

I completely agree, but it's often interesting to know, not just who set a property last or to a specific value, but each instance of when a property was set, changed, skipped, etc up to a particular point. Perhaps that's the kind of information you mean by 1. This is even interesting in the initial property context though, not just dynamic evaluation.

I often debug tasks, but it requires me to recompile the source code to launch a debugger or wait indefinitely for me to attach. Stepping directly from a target, into the task would be tremendously useful.

danmoseley commented 7 years ago

@chcosta if you want to log one file per proc, you should be able to simply add /distributedFileLogger. It hasn't historically got much use but IIRC that's what it's for.

weshaggard commented 7 years ago

This definitely sounds interesting and I'd use it. +1 from me

commonsensesoftware commented 7 years ago

This all seems to be in the right direction. At least in my experience, most of my debugging has involved the where and when something changed.

Two interesting variants that I think would go a long way are:

Support a -WhatIf switch similar to PowerShell that can evaluate a build script with a no-op on tasks or at least allow tasks to opt into a what if behavior.
Enable a visualization for the build log that can show the traceability of properties, items, and so on changed during the build; a poor man's IntelliTrace for MSBuild if you will.

Understanding when, where, and why something changed in a build is very useful for troubleshooting IMHO. While a debugger is nifty and useful in some situations, the ability to have a comprehensive visualization of what will happen or what did happen is more effective in tracking down issues. You might liken this approach as something akin to SQL Server's Estimated Query Plan and Actual Query Plan.

My typical investigation into these type of issues today usually involves changing the log level to Detailed or Diagnostic and then spelunking the log file with a text editor.

clairernovotny commented 7 years ago

I'd use this...debugging Targets can be really challenging today when things go wrong or don't do things as expected.

jeffkl commented 6 years ago

I'm wondering if the latest features in http://msbuildlog.com/ address the needs here. /binarylogger is now built into MSBuild.exe so its easier than ever to capture a diagnostic log and the full import graph.

Nirmal4G commented 6 years ago

With the introduction of SDK concept, we need something like this to debug the MSBuild props/targets. #1493

commonsensesoftware commented 6 years ago

@jeffkl is right. Most, but arguably not all, of the requests here are addressed by the MSBuild Structured Binary Log and it's various viewer/analyzer tools. I've personally be using them and find them to be unbelievably valuable. We needed it 10 years ago!

While incredible powerful and easy to search, things can sometimes still be difficult to spelunk. The *.binglog format can be used to replay a build. Something that would be nice in a tool would be to visually replay the evaluation. This might be analogous to formula tracing in Excel. You want to visually trace through the log to follow the flow and changes. There's already a timeline and ordered execution tree. If we had a way to set a breakpoint or step through the log visually, I think we'd have everything that has been asked for.

I'm not sure that interactive debugging is all that useful. Interactively traversing a log would be more useful IMO. Furthermore, that would help diagnose scenarios where you can't interactively debug a build, such as on a build server. However, you'd now be able to interactively walk through a replay. This concept has already proven to be effective with IntelliTrace and historical debugging.

BenNesson commented 6 years ago

I will say I'm sorry to see the old VS debugging approach go. I once used it as part of a truly ludicrous MSBuild code coverage collection tool.

TaskStartedEventArgs only provides the Name and File of the Task being started, which isn't enough to specifically identify which task is running. So the coverage logger attached to msbuild as a debugger and set a breakpoint on each Task, marking it as covered when the breakpoint was hit.

It worked pretty well, except there was a bug that any Tasks that directly used certain stuff from (I think it was) Microsoft.Build.Evaluation themselves would crash if you were running with debugging enabled.

KirillOsenkov commented 4 years ago

Given the progress with binlogs and http://msbuildlog.com in the past few years I'm curious whether there's still a niche for an actual debugger like described above.

In any case I'd be curious if the binlog viewer is missing any scenarios. Feel free to file issues over at https://github.com/KirillOsenkov/MSBuildStructuredLog.

joperezr commented 4 years ago

I've used binlogs to debug countless build issues and it is definitely a super powerful tool, thank you so much for all the amazing work @KirillOsenkov! One scenario where I think that a msbuild debugger would still be great would be in order to be able to break in some stage of the build, to analyze files/tempfiles/variables/properties and then to be able to run target by target. I might be wrong but I don't believe that this is something you can use the binlog for and in some advanced diagnostic scenarios it might be super useful.

KirillOsenkov commented 4 years ago

I agree, but then aren't you better off just debugging the real thing at that point though?

michael-hawker commented 1 year ago

We have a fairly complex build with many props file shared across various projects. It's hard to understand sometimes if we have the right configuration setup for conditions, so debugging and seeing the exact evaluation in reference to our props files would be helpful. Was hopeful the old debugger article I found would still work on the core version, but alas.

Binlog is helpful to a point, but on a complex build it's harder to understand why something didn't happen. Like I think I'm including a reference but it's not built... with a debugger I could see if I actually hit that line in my props file where it's defined and at least eliminate or know if that's the issue or not.

ChristopherHaws commented 1 year ago

The vscode extension MSBuild Project Tools improves the experience while editing props, targets, sln and csproj files in vscode. It isnt perfect, but its way better than what Visual Studio Enterprise provides. The "above the fold" description of this extension on the marketplace page does not do it justice! I highly recommend giving it a try.

The creator is working on publishing the language service and I was going to attempt to get it working with Visual Studio.

This seemed relevant to this thread. It doesn't have debugger support, but it is free and open source 😃:

KirillOsenkov commented 1 year ago

Check out https://github.com/mhutch/MonoDevelop.MSBuildEditor by @mhutch

dotnet / msbuild