Sdk: build.cmd should have it's verbosity turned down

Created on 2 Aug 2017  路  16Comments  路  Source: dotnet/sdk

The output of build.cmd is very, very large and spewing out lots of text that is going too fast to be useful. Perhaps turn down the verbosity?

Most helpful comment

This is very helpful in CI

Then enable it specifically in CI. The majority use case is by humans and the current default is unusable. A build is just needlessly scrolling my console without any benefit.

All 16 comments

I actually like having complete output. In a CI scenario or even just doing a plain build, I can get everything I need to debug a problem without having to fiddle with flags or looking for log files.

That said, I have only used build.sh and cant say if build.cmd is more or less verbose.

This is very helpful in CI, you can search the output message easily after CI failed without look into any artifact. By default, msbuild.log has the same messages, and you can search here if the buffer is overflowed.
_./build.cmd /bl_ is also good for dev cycle, you can open binary log with https://github.com/KirillOsenkov/MSBuildStructuredLog

Msbuild param can pass though as well _.build.cmd /v:q_

Is build.cmd just for CI scenarios?

@davkean no, but CI is a major use case of this script and it should has less extra config as possible.

Lots of other repos pass extra arguments for CI vs dev builds. On Windows, the output is effectively useless because it blows easily through the command-line buffer.

This is very helpful in CI

Then enable it specifically in CI. The majority use case is by humans and the current default is unusable. A build is just needlessly scrolling my console without any benefit.

When I last grabbed this repo the first thing I did was run build.bat, the second was editing run-build.ps1 to make it usable. I concur with the above: if it's for CI then do it for CI, have an extra param sent or infer from a variable. The current approach makes the very first interaction anti-user and that's a bad first experience.

I agree that the command line experience should be cleaned up. We should have an optional parameter that enables the verbose console log, and add that to the CI configuration.

@jaredpar

Then enable it specifically in CI. The majority use case is by humans and the current default is unusable. A build is just needlessly scrolling my console without any benefit.

Consider the scenario of build broke and people needs to investigate why, at this point, it's better to have detail as much as possible.

@dsplaisted

I agree that the command line experience should be cleaned up. We should have an optional parameter that enables the verbose console log, and add that to the CI configuration.

I prefer CI config to be simple (we already had a lot). The root problem is we have a complex build that requires log to debug, hide it from the developer will not help. However, if we think we don't need verbose log level(I actually think so), we should tune it down everywhere

Consider the scenario of build broke and people needs to investigate why, at this point, it's better to have detail as much as possible.

Sure. That is why in CI you have a more detailed output and / or write to a log file. This is what we do in virtually every other repo and it works great while also having a great experience for developers in the repo.

The build output as is, writes 23,000+ lines to my screen. That easily overflows the console buffer and hence really doesn't benefit developers at all. Also I don't really agree with the premise that I need the full log to understand the error. The vast majority of the time it's a simple compilation bug, MSBuild error, etc ... and the summary line is more than enough information to fix the bug.

However, if we think we don't need verbose log level(I actually think so), we should tune it down everywhere

The build output on average is adding 18 lines per second to the developer console. That's counting unwrapped lines. The console output wraps frequently so the real line count is significantly higher.

No human is processing that information in real time. It can only be processed as an after the fact investigation. That is why log files are the way to go here. Or at least keeping the output to CI only.

The build output as is, writes 23,000+ lines to my screen. That easily overflows the console buffer

I think that's the key point here - you can't use this data to investigate build logs because you can't go back and look at it on Windows.

You should optimize for the common case - ie I've introduced a compiler error or a test failed, in other repo's we always write a log so you can go back and investigate it if needed.

One more thing, the CLI build is one of the slowest builds I've seen in open source (slower than Roslyn which has 3 times as many projects), I wouldn't be surprised if writing to the console is contributing to that.

One more thing, the CLI build is one of the slowest builds I've seen in open source (slower than Roslyn which has 3 times as many projects), I wouldn't be surprised if writing to the console is contributing to that.

Took some measurements on this recently on my dev box:

  • Roslyn: 4.5 million lines of code and build time is 2-3 minutes
  • CLI: 50,000 lines of code and build.cmd takes 21+ minutes

The results are slightly off because in Roslyn build.cmd just builds. While in CLI build.cmd restores, builds and run tests. Hence the type of work is different. But even if you add restore and test to the Roslyn measurements it still comes in at ~19 minutes.

I agree with turning down the verbosity. Strongly!

Some things contributing to slow builds:

  1. CLI build runs on .NET core and compiler and other tools have worse startup time on .NET Core due to not having server support
  2. CLI builds its own satellite assemblies so we start up csc 14x per assembly (compounding 1)
  3. CLI build runs crossgen on the whole tooling stack (can be disabled via DISABLE_CROSSGEN and I think we should turn it off for developer builds. I always do.
  4. Lots of CLI tests are integration tests: they execute verbs end-to-end which spin up msbuild processes, cause nuget to hit the network, etc.
  5. CLI build forces nuget cache to repo-local location (to keep my packages around, I do git clean src -fdx && git clean test -fdx && rd /s /q artifacts instead of straight up git clean -fdx

I think all of these are much more impactful than writing to the console, and all have the characteristic that they aren't really correlated to lines of code for the CLI logic itself.

But even if perf win is zero, I want to get rid of the clutter and turn down the verbosity.

@nguerrera we have done a bunch of improvements in our builds by now, with more already slotted to go (repo-refactoring). Do we still need this issue active?

We should end up with the same verbosity in CLI as all the other repo toolset repos when that lands, so I guess we can close this.

Was this page helpful?
0 / 5 - 0 ratings