 On today's Visual Studio Toolbox, Karill is going to show us how to use a tool to get more information from your builds than just succeeded or failed. Hi, welcome to Visual Studio Toolbox. I'm your host, Robert Green, and joining me is Karill Ossinkoff. Hey, Karill. Hello, good to be here. Karill is a developer in Visual Studio Land and is coming back on the show. It's been, I looked this up five years since you're on the show last. Nice to be here again. Thanks for inviting me. It's way overdue to have you. You're going to tell us about some build tools you wrote, some ways we can find out more about what's going on with build. Right, exactly. So, a developer like me, obviously I know there's build in there, and I know to build my projects and solutions, and I know that there's a lot of information scrolling by, and occasionally I look at it, but mostly I care about two things. Build succeeded, build failed. Right? Right. So I miss build, build, right? Yeah. It's daunting. Like sometimes you feel this helplessness because there's a giant system in front of you, and it doesn't behave the way you expect. So either a file doesn't get copied or a different version of a DLL, or something is broken, you have no idea why, and you're in front of this black box system. And what do you do? What are the tools like to help you zoom in and understand the problems, see what's going on? Yeah. So basically, traditionally MS Build has a logging system, and they produce a large amount of logs, but mostly they are text logs, and for multi-prog builds, basically, imagine 10 people in the room chatting at the same time, different nodes logging different things, and so you see, well, this is doing this, but now I'm getting distracted by this node, but then I'm back here, but who started this, and I have no idea, and then there's this chunk of text that I don't need at all, right? So I want to collapse it, move it away, so there's no structure, there's no help, there's no, and so sometimes they would log too much, but at the same time, not the information that I want. Right. So something had to be done, and after some amount of misery, I said enough is enough, so let's build some tooling for it to make it better. Cool. So there's two things, the MS Build itself has a new log format called the binary log, short bin log, and it basically is a recording of exactly what happened during the build, very detailed, very rich, very organized and structured, and so it captures kind of like, here's what happened, you can play it back, you can play the log back, and then you'll see the same output that would happen during the regular build, right? And so it's a compressed, efficient binary format that is good, but now you need a viewer for it because it's not text anymore, right? And so I wrote a viewer, it's called the MS Build, binary and structured log viewer, but basically this is the bin log viewer, and it really gives you the insight on what's happened during that build, what files were involved, what were the environment variables, what were the properties. So in fact, a warning that we like to give people is that it contains your environment variables. So they have secrets, they have passwords, so treat those bin logs very carefully because they have some stuff in it. So but yeah, it's been very helpful, people use it, it's been real nice to see this. Let's see it in action. Yeah, so the first thing you do, you go to MSBuildLog.com, so website has everything you need to know about the logging, what it is, how to use it, how to obtain a bin log, how to play it back, how to view it, and so to download the viewer, just click the green button and the experience needs some improvement, but basically you download this file and then just click this button, run anyway, the viewer gets installed, and here there's also some documentation on how to use it on the command line. On the command line, you just type MSBuild, your solution, and then slash BL is the special magic switch that, after the build is done, you'll see a new file, bin log file here, and then you can double click on it to open in the viewer. And this is how the viewer looks like, so I'm gonna go here, and you have two choices here. You can either just build a new project or a solution, or you can open a recording, that bin log file that you have from somewhere else, so if it was built on CI or in some another machine, you're helping a friend. Is it any project, WinForms, UWP, Xamarin, web-based, anything you can build with MSBuild? Anything you can build with MSBuild, so you open a solution, you can select which MSBuild are you going to use to build it, and you can pass, for example, slash R here or additional parameters. For example, this is for multi-prog build, and this time I'm gonna do the rebuild target. And yeah, you can copy the command line to Clipboard, so you can just run it yourself. But you click a button, and now it just calls into MSBuild with that BL flag, and it's recording as you go. So there's some overhead in terms of performance, it's gonna make your build slightly slower, but just because it's capturing so much more useful information, so it's not a lot. And this is what you get when you open it up, and this is exactly the same what you see if you open a binlog file. So that's the binlog viewer here on the left, we have the pane where we can search for stuff. And so give us an overview of what we're looking at. Yes, so the main- Don't succeed it, that's good. Yeah, you see the green mark, don't succeed it. And then the tree, the main thing in here is the tree, it's a tree of the build, and now it's organized not in a single linear wall of text, a million lines of text. It's a tree, and you can see the most important thing is this solution is building. Here are the projects that we're building, and inside the project you will see targets running inside the targets. You see other targets. Let's see. There's tasks, and the tasks have parameters, and the folders, and output items, and so on. So now that you have all this rich goodness, you can search. So for example, if you want to see where the C-Sharp compiler ran, so you search for task, and then you narrow it down to CSE. And now you see, well, this is where the C-Sharp compiler was invoked. So there's parameters, here's what exactly what was passed to the compiler, here's the references, and you can click on the reference, you can copy, you can sort them. So it's easier to navigate, right? And here's all the metadata, here's all the sources. So pretty much it's exactly what happened during the build, but it's not text. So search is, I've built a few things here, so you can search for types of nodes that you care about. For example, you only want to look for errors. Here's, there's no errors in this build, right? Or warnings, or properties, or items. And then I've built some useful examples. For example, when you see, why did the file get copied, or why did it not get copied, right? So you search for copying file from. So you see this is where Ms. Build is copying files. So you can narrow it down to a DLL. And then you can further narrow it down to, you know, logger.dll. And so now you start narrowing it down to exactly what you want. And then the common problems that you see as resolve assembly references. So you see where things are resolved, where is it copied? Or there was a conflict. This is a common thing where you just have conflict. You don't know what to look for, right? In Cloud Third Con, why is this building again? I just built it. Nothing has changed. Why is it building again? Why is it doing work, right? So it's called building her mentality. And it is very useful to search for these exact strings to see how this is building completely, why? Because it says, well, this file that you expected does not exist. So you want to search for these things. Or for example, property reassignment. This is when a property had one value that was assigned a new value. So you know what changed it and who changed it and when. And so here in the tree, you see it's, and if it's too long, you can press space and it's gonna show exactly where this happened. So this is a powerful tool. You can see the source code for everything. It records the source code for all projects and all the imported files that were used during the build. And then you can go to the source code then. Yeah, so there's more, I mean. Yeah, so how would I, I mean, it's interesting to get a sense of what's going on in the build, but how would I use it for troubleshooting in general? And how much am I expected to know what's happening in the first place in order to be able to go drill into what might have happened? Right, well, for starters, if you have an error or something, you just have some text to search for. Just start, try searching for that text. Always a good first step. And then you do need to understand pretty much how MsBuild works. MsBuild is a generic system for interpreting a project. It can import other projects and then when it evaluates, it's done evaluating, then it constructed a target graph where targets need other targets to build. So targets, it's like functions call other functions. Targets can build other targets. And then inside the target, just like inside the function, you have statements, right? Inside the target, you have tasks. And the tasks is as a unit of actually doing work. Like, CSE is a task to run the C sharp compiler to convert the source code to a DLL file, right? So inside the tasks, you know, you pass them parameters and then you can drill deeper and deeper but pretty much once you understand this and then you have the initial understanding of what kind of problem are we facing, you'll be able to search. So if a build succeeded, would this help me find problems that were in there? Even though the build succeeded? Yes, so for example, I'll show you a problem right here with this very build at the very entity, double writes. A double write is when this file was written to from two different source locations. So first someone wrote this file from that location and then someone else randomly overwrote the file with something else. And depending on someone, you mean some process. Both of these, yeah, they were part of the build. So different parts of the build that racing are competing to see and depending on the order in multi-proc systems, then you can either get lucky or you will get unlucky. And so this shows you exactly what is a problem. It's a double write and then you can just search for, you can copy this and search for this exact file and see where it's being copied from. So you can go and search for copying file. So this is exactly the place where this one is getting copied, see? So it turns out the copy files marked as copy local taking it from NuGet. So you know what this is happening. And so you need to determine one of them shouldn't be doing that. Yeah. So then you resolve all your double writes. So this is an example of an analyzer, right? So now what would I do with that information? I'm finding that there's two different versions of that package and I want one versus the other. So usually I stop the one or. Right, so usually the next step is you look at the project. Here's you can view the source code. Here's the source code of the project. And you see here's the package reference. Here's this version. Okay. And there from here you can reason. And now one thing that there is a yellow text here that I wrote, people never read it, but I wrote it so that they read it. And once they read it, they'll learn that there's this very useful feature where you can click on a project and say preprocess. So what this does is it basically inlines all of the imported projects, importing other projects. There's giant graph, a tree of projects, and just it makes how MS build sees it. It's flattened. It's one giant XML file. This is exactly what MS build sees when it builds. And so you can search here for, for example, where did it run the AC sharp compiler? So for example, at this point that ran CSC at line 20,000. So, and then you can see the ordering of property assignment is important because sometimes you would set the property and wonder, well, why I'm sitting here, but nothing's happening. Turns out, someone else later is setting this to a different value. So you need to use search to figure out, well, who was the last person to set it? So, yeah, with you. Then you can't edit this file here to make things happen the way you want, can you? You can click open here. It'll open it in your favorite editor of your choice. And then you go there and you edit and then you kind of rebuild and see what's happening then. Okay, okay. So now one other big thing is that when you're inside of Visual Studio, you're building inside Visual Studio, you see the output window and you have, how do you investigate those? There is an extension called project system tools that you can install to Visual Studio 2019 and it will have a record button and it'll record these logs for design time build and regular builds and then you can just inspect them just like you do now. It's very convenient to understand. So it builds the same bin log and you look at it the exact same way. Because when you build in the IDE in Visual Studio, it's slightly different from building in the command line. Oh, okay. So in the command line you just pass slash BL and you obtain the bin log. When you're inside the Visual Studio, you need the Visual Studio extension project system tools which is probably a topic for a whole nother video like this. Okay. But people need to know that there are now tools to inspect both the command line builds and you can do it on CI and you can attach it as an artifact on the CI and then they inside the Visual Studio. And so common problems like you see incrementality where things are rebuilding when nothing has changed, double writes, non-deterministic builds, files getting copied to the output where you don't want them or vice versa, they aren't getting copied and you expect them. So all things like this. So you can use this then potentially as an opportunity to investigate why it builds and runs correctly on your machine but not potentially on someone else's or maybe not on a build server somewhere. Usually there's a dependency on environment on this particular machine. You take this environment variable or you end up resolving this DLL file from the gap or some other local location and things are not repeatable. So reproducible, repeatable builds are hermetic. They're isolated from the environment as much as possible and they bring everything they need with them. They bring in their SDK, they bring in the Nougat packages, they lay it all down exactly and then they build it and then you can reproduce byte by byte the same of builds on a different machine and then you'll never have this problem. So this is our, you know, the goal. Cool. Yeah, I guess just one quick maybe two or just one more minute of the features here. The here's all the files used during the build and you can search for example, you know, for here's the full text of this file, for example, and you can find the textual search, you can search in all these files. So here's for example, where C sharp compiler is called. Okay. And as I said, right-click menu. It's very important you can search in this subtree. You can view the subtree text. You can save the log as XML and then you can do further processing and if there's an API to read and write these ones. And you can like delete the stuff you don't care about. For example, I know this is just get it out of the way, right? And so there's various tricks and I encourage there's for example, the timeline view where you can see like what happened here. Like this only took like 271 milliseconds but this long thing took like nine seconds, right? Okay. And so at the very end, there's also the summary of like top 10 most expensive tasks so you can optimize your builds. Like I know the C sharp compiler here took the most. So I encourage people to like dig deeper and just try to, you know, explore. And this is a tool that basically opens up the MS build black box to kind of help you understand and solve the problems that I know people have problems. So it's good to learn. Cool. And thanks. Very cool. Okay. So we'll have links in the show notes on where to get it. Some documentation. And then there, I saw that the sources is up there. It's open source and get them. Yeah. Can look at. Well, the contributions and people send PRs and I'm very grateful for the help I get. Cool. Very cool. So hope you guys enjoyed that brief look at this. Play around with it and let us know what questions you have. We can think about what to do is maybe a follow up episode or something. So we can introduce it here and then dive in in the future. Thank you so much. All right. Hope you enjoyed that. We will see you next time on Visual Studio Toolbox.