on today's visual studio toolbox Kirill
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 Greene and joining me is Kirill
Austin cough hey Kirill hello good to be
here Corel is a developer and visual
studio land and is coming back on the
show it's been I've looked this up five
years Wow
since you're on the show last nice to be
here again thanks for my overdue to have
you and you're gonna tell us about some
build tools you wrote some some ways we
can find out more about what's going on
with build right thanks Lee so you know
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 a mis build builds 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 in 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 problem to
you what's going on yeah
so basically traditionally msbuild has a
logging system and they produce a large
amount of logs but mostly there takes
logs and for multi product builds
basically imagine ten people in the room
chatting at the same time different
nodes login 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
lock too much at the same time not the
information that I want right so
something had to be done uh-huh and
after all you know some amount of misery
I said enough is enough
so let's build some tooling for it yeah
better cool so there's two things the
msbuild itself has a new log format
called the binary log a short bin log
and it basically is a reporting 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 there
a viewer called AM is built binary in
structured love viewer but basically
this is the bin log viewer okay 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 these have
secrets they have passwords so treat
those bin logs very carefully okay
because they have some stuff in it so
but yeah it's been very helpful people
use it and it's been real nice to let's
see this let's see in action yeah so the
first thing you do you go to M is built
log comm this website has everything you
need to know about you know the logging
and 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 click this button run anyway if
your 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 M is build your solution
and then /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
like so I'm gonna go here and you have
two choices here you can either just
build and you a project or solution or
you can open their recording that bin
log file that you have from somewhere
else so if it was built on Cir and some
another machine you're helping in France
is it any project where are DWP xamarin
anything we must move bill okay anything
you can build with them as build so you
open a solution you can select which
amis build are you going to use to build
it and you can pass for example slash
are here or additional parameters for
example this is for multi proc 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 that's you click a button and
now it just calls into Miss build with
that BL flag and it's recording as you
go okay
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 their AB in log file so that's
the bin log 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 they may exceed it that's good yeah
you see the green our build succeeded
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 that single
linear you know 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 you know
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
ok so now that you have all this rich
goodness you can search so for example
if you want to see where this is sharp
compiler ran so you search for task and
then you narrow it down to CSC and now
you see well this is where the easysharp
compiler was invoked
okay 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 some years oldi metadata
here's all the sources so pretty much
it's exactly what happened during the
build but it's not text so searches I've
built a few things here so you can
search for you know types of nodes that
you care about for example you only want
to look for errors here's there's no
errors in this bill 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 hopping file from so you see
this is where I must build this copying
file so you can narrow it down to a dll
and then can further narrow it down to
you know logger dll and so now you 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 copy where there
was a conflict this is a common thing
where you just have fun think you don't
know what to look for
right right encountered can't why 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 aha
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 she would
change it and who change 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 built and then you
can go to the source go then
yeah so there's more I mean yeah so how
would I I mean it's interesting to to
get a better sense of what's going on in
the bill 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 right 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 it's always a
good first step and then you do need to
understand very much how this build
works and this build is a generic system
for interpreting a project it can import
other projects and then when it
evaluates is done evaluating then it's
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 a unit of actually doing work
like CSC 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 some parameters an ink and
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 succeeded yes so for
example I'll show you a problem right
here with us very build at the very
entity double writes a double write is
when this file was written two from two
different source location so first
someone wrote this file from that
location and then someone else randomly
overrode the file with something else
and depending on someone you mean some
process both of these yeah they were
part of the build
okay so different parts of the build are
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 right 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
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 nougat so you know what
this is happening so you need to
determine one of them shouldn't be doing
that yeah so then you resolve all your
double R 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 you want one versus the other so
your stop the one or all right so
usually the next step is you look at the
project here's you can view the source
code to use the source code of the
project and see here's the package
reference here's this version ok results
and they're from here you can reason and
now one thing that there is a yellow
text here mm-hmm that I wrote people
never read it but I wrote it so that
they read it then once they read it they
learn that there's this a very useful
feature where you can click on the
project and say pre-process 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 and makes how I'm is
built sees it it's flattened it's one
giant cement found this is exactly what
them is built sees when it builds ok and
so you can search here for for example
where did it run the c-sharp compiler so
for example at this point that ran CSC
at line 20000 so okay and then you can
see the ordering of the property
assignment is important because
sometimes you would set the property in
wonder well why I'm sitting in 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 what then
you can't edit this file here to make
things happen the way you want can you
uh 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 ok ok so now one other
big thing is that when you're inside of
Visual Studio you're building side
Visual Studio see the output window and
you have how do you investigate those
right there is the 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 it builds the same bin log
yes exact same way because when you
build in the IDE in Visual Studio it's
slightly different from building in the
command line okay so in the command line
you just pass /bl and you obtain a bin
lock 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 where nothing has changed
double writes non-deterministic builds
you know files getting copied to the
output where you don't want them or
vice-versa they aren't getting copied
then you expect them so all things like
this you use this then potentially is an
opportunity to investigate why it builds
and runs correctly in your machine but
not potentially on someone else's or
maybe not on a build server somewhere
usually if there's a dependency on the
environment on the 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 built or
hermetic they're isolated from the
environment as much as possible and they
bring everything they need with them
they bring in their as decay they bring
in the nougat packages they lay it all
down exactly and then they build it and
then you can reproduce bite by bite the
same builds on a different machine and
then you'll never have this problem so
this is our you know they go cool yeah I
guess
just one quick na tour just one minute
of the features here the gears are 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 do 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 in it 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 then so
there's various tricks and I incurred
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 bills like I know this
is sharp compiling 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 msbuild 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
ok 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 on github you
can can look at yeah we welcome on
tribution and people send fee ours and
I'm very grateful for the help I got
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
alright hope you enjoyed that we will
see you next time on visual studio
toolbox
[Music]