Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[build] Normal & Diagnostic Log Verbosity, at once! #1808

Merged
merged 1 commit into from
Jun 14, 2018

Conversation

jonpryor
Copy link
Member

Fixes: #1792

We have a bit of a conundrum: when things break, the diagnostic build
logs are essential to tracking down why something broke.

However, the sheer verbosity of those diagnostic logs makes it
difficult to determine what broke; it's very easy to get lost.
Additionally, the gigantic log files make the Console Output
Jenkins link nearly useless, as most web browsers will cease up when
attempting to download ~1GB log files.

Split the difference: introduce a new $(call MSBUILD_BINLOG) syntax
which creates an MSBuild binary log file, which is like
diagnostic output but even moreso, while also overriding the
console logging to /v:normal.

This should allow the Console Output link to be a bit more
reasoanble, and if something goes wrong we can download the separate
*.binlog files for further analysis.

MSBuild binary log files can be read with MSBuild itself:

msbuild /v:diag bin/BuildDebug/msbuild-*.binlog

Note: above command will actually fail; you can only print one log
file at a time with that syntax.

The created log files follow the pattern msbuild-EPOCH-NAME, where
EPOCH is the time_t/Unix epoch value at the time the command was
executed
. This should allow filenames to be non-colliding, and allow
plausibly sane sorting behavior. (Maybe.)

Fixes: dotnet#1792

We have a bit of a conundrum: when things break, the diagnostic build
logs are *essential* to tracking down *why* something broke.

However, the sheer *verbosity* of those diagnostic logs makes it
difficult to determine *what* broke; it's very easy to get lost.
Additionally, the gigantic log files make the **Console Output**
Jenkins link nearly useless, as most web browsers will cease up when
attempting to download ~1GB log files.

Split the difference: introduce a new `$(call MSBUILD_BINLOG)` syntax
which creates an [MSBuild binary log][0] file, which is like
diagnostic output *but even moreso*, while *also* overriding the
console logging to `/v:normal`.

[0]: https://github.com/Microsoft/msbuild/wiki/Binary-Log

This should allow the **Console Output** link to be a bit more
reasoanble, and if something goes wrong we can download the separate
`*.binlog` files for further analysis.

MSBuild binary log files can be read with MSBuild itself:

	msbuild /v:diag bin/BuildDebug/msbuild-*.binlog

Note: above command will actually fail; you can only print one log
file at a time with that syntax.

The created log files follow the pattern `msbuild-EPOCH-NAME`, where
EPOCH is the `time_t`/Unix epoch value *at the time the command was
executed*.  This should allow filenames to be non-colliding, and allow
plausibly sane sorting behavior.  (Maybe.)
@jonpryor jonpryor requested review from grendello and atsushieno June 12, 2018 01:39
@atsushieno
Copy link
Contributor

This PR/commit does not fix #1792 by itself. What is important there is to get CI build results readable.

What is more important and kindful for developers is that there is a solid and supported way to run individual tests to diagnose the issues. If each contributor is asked to run "hacky" way to run individual tests and be blamed if they get false results by adding hacks, then those contributors are pissed off.

It does not have to be done within this PR, but if it's not achieved then we'll have to keep the issue open.

@atsushieno
Copy link
Contributor

Build is failing and because of the exact issue on the context I cannot see why it's failing :(

@jonpryor
Copy link
Member Author

Your concern was strictly that the build log was too big:

You are asking me to read 2M lines of log file after downloading 60MB+ gzipped content.
I stopped trying to investigate the log file, it is simply not readable.

The log file is now smaller; the build log for this PR is ~95MB. The previous build log size when a non-full mono rebuild was involved was 206MB; we're less than half the size, and much of that output is the mono build. As such, I'm now able to click the Console Output link and view it within 20 seconds. (Yay?)

I cannot see why it's failing

You still need to read the log output: line 979566 -- 310 lines from the end of the file -- contains the error:

error MSB4018: The "ResolveSdks" task failed unexpectedly. [/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/tests/CodeBehind/BuildTests/CodeBehindBuildTests.csproj]
error MSB4018: System.NullReferenceException: Object reference not set to an instance of an object [/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/tests/CodeBehind/BuildTests/CodeBehindBuildTests.csproj]
error MSB4018:   at Xamarin.Android.Tasks.ResolveSdks.GetMaxStableApiLevel () [0x0000b] in <7bedfdca2f8e43fdbf86a8b4b8c2bcc7>:0  [/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/tests/CodeBehind/BuildTests/CodeBehindBuildTests.csproj]
error MSB4018:   at Xamarin.Android.Tasks.ResolveSdks.ValidateApiLevels () [0x00051] in <7bedfdca2f8e43fdbf86a8b4b8c2bcc7>:0  [/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/tests/CodeBehind/BuildTests/CodeBehindBuildTests.csproj]
error MSB4018:   at Xamarin.Android.Tasks.ResolveSdks.RunTask () [0x007f7] in <7bedfdca2f8e43fdbf86a8b4b8c2bcc7>:0  [/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/tests/CodeBehind/BuildTests/CodeBehindBuildTests.csproj]
error MSB4018:   at Xamarin.Android.Tasks.ResolveSdks.Execute () [0x00002] in <7bedfdca2f8e43fdbf86a8b4b8c2bcc7>:0  [/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/tests/CodeBehind/BuildTests/CodeBehindBuildTests.csproj]
error MSB4018:   at Microsoft.Build.BackEnd.TaskExecutionHost.Microsoft.Build.BackEnd.ITaskExecutionHost.Execute () [0x00023] in <24bc6288c5b04a3da2a58b4fda160e2d>:0  [/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/tests/CodeBehind/BuildTests/CodeBehindBuildTests.csproj]
error MSB4018:   at Microsoft.Build.BackEnd.TaskBuilder+<ExecuteInstantiatedTask>d__26.MoveNext () [0x00212] in <24bc6288c5b04a3da2a58b4fda160e2d>:0  [/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/tests/CodeBehind/BuildTests/CodeBehindBuildTests.csproj]

Is it too much to go to the end of the file and search backwards for error ?

As for why <ResolveSdks/> is throwing a NullReferenceException, that's addressed in PR #1809.

@jonpryor
Copy link
Member Author

What is more important and kindful for developers is that there is a solid and supported way to run individual tests to diagnose the issues

That wasn't mentioned in Issue #1792, and we do have documentation on running individual tests, though apparently we need to document running a single MSBuild unit test.

@dellis1972: would you be able to update the docs to include running a single MSBuild unit test fixture and/or method?

@dellis1972
Copy link
Contributor

@jonpryor I will

@atsushieno
Copy link
Contributor

I mean, build individual tests and get separate test results on the CI builds, instead of forcing contributors read all those annoyingly irrelevant build logs.

@jonpryor
Copy link
Member Author

get separate test results on the CI builds

You mean like the Test Result link on Jenkins? If a unit test fails, you don't need to read Console Output to determine the error. For example:

https://jenkins.mono-project.com/job/xamarin-android-pr-builder/3315/ >
https://jenkins.mono-project.com/job/xamarin-android-pr-builder/3315/testReport/junit/Xamarin.Android.Build.Tests.AndroidUpdateResourcesTest/CheckAaptErrorRaisedForInvalidFileName/Xamarin_Android_Build_Tests_AndroidUpdateResourcesTest_CheckAaptErrorRaisedForInvalidFileName_True____Debug/

Additionally, the Console Output link won't even show the build log for that failing test; you'd have to use test-errors.zip to get the build logs.

@jonpryor
Copy link
Member Author

That aside, this PR appears to be incomplete: some portions of the output are not "normal" verbosity, but "diagnostic" verbosity:

Using "ResolveSdks" task from assembly "/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/bin/Debug/lib/xamarin.android/xbuild/Xamarin/Android/Xamarin.Android.Build.Tasks.dll".
Task "ResolveSdks" (TaskId:2281)
  Task Parameter:AndroidSdkBuildToolsVersion=27.0.3 (TaskId:2281)
  Task Parameter:AndroidSdkPath=/Users/builder/android-toolchain/sdk (TaskId:2281)
  Task Parameter:AndroidNdkPath=/Users/builder/android-toolchain/ndk (TaskId:2281)
  Task Parameter:AndroidUseAapt2=False (TaskId:2281)
  Task Parameter:AotAssemblies=False (TaskId:2281)
  Task Parameter:SequencePointsMode=None (TaskId:2281)
  Task Parameter:ProjectFilePath=/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/tests/CodeBehind/CommonSampleLibrary/CommonSampleLibrary.csproj (TaskId:2281)
  Task Parameter:ReferenceAssemblyPaths=/Users/builder/jenkins/workspace/xamarin-android-pr-builder/xamarin-android/bin/Debug/lib/xamarin.android/xbuild-frameworks/MonoAndroid/v1.0/ (TaskId:2281)
  Task Parameter:TargetFrameworkVersion=v8.1 (TaskId:2281)
  Task Parameter:UseLatestAndroidPlatformSdk=True (TaskId:2281)
  Task Parameter:LatestSupportedJavaVersion=1.8.0 (TaskId:2281)
  Task Parameter:MinimumSupportedJavaVersion=1.6.0 (TaskId:2281)
  ResolveSdksTask: (TaskId:2281)
    AndroidApiLevel:  (TaskId:2281)
...

None of that should appear in "normal" verbosity. Looks like there are some additional spots to fix, e.g.: https://github.com/xamarin/xamarin-android/blob/391970420f92df5923bd92118ca1d78e228303bf/build-tools/scripts/RunTests.targets#L84

@atsushieno
Copy link
Contributor

Where can I find such a "Test Result link" on https://jenkins.mono-project.com/job/xamarin-anroid-linux-pr-builder/2993/ ? (it is the context of the issue #1792 I reported)

(Although let's make sure that separate build logs don't have to be part of this PR.)

@jonpryor
Copy link
Member Author

Where can I find such a "Test Result link" on https://jenkins.mono-project.com/job/xamarin-anroid-linux-pr-builder/2993/

There isn't one.

Our builds have three possible states:

  • Green/Stable: repo was built, tests were built, tests were executed, all tests pass.
  • Orange/Unstable: Repo was built, tests were built, tests were executed, some tests fail.
  • Red/Failed: Repo or tests did not build.

The build you linked to is Red. Something failed to build. Consequently, no tests were run. As such, there is not a "test result link," nor can there be one.

Reviewing the log for that build, I see:

The "ResolveSdks" task failed unexpectedly.
System.ArgumentNullException: Value cannot be null.
Parameter name: element
  at System.Xml.Linq.XElement.op_Explicit (System.Xml.Linq.XElement element)
  at Xamarin.Android.Tools.AndroidVersion.Load (System.Xml.Linq.XDocument doc)
  at Xamarin.Android.Tools.AndroidVersion.Load (System.String uri)
  at Xamarin.Android.Tools.AndroidVersions+<>c.<.ctor>b__16_1 (System.String file)
  at System.Linq.Enumerable+SelectEnumerableIterator`2[TSource,TResult].MoveNext ()
  at Xamarin.Android.Tools.AndroidVersions.LoadVersions (System.Collections.Generic.IEnumerable`1[T] versions)
  at Xamarin.Android.Tools.AndroidVersions..ctor (System.Collections.Generic.IEnumerable`1[T] frameworkDirectories)
  at Xamarin.Android.Tasks.MonoAndroidHelper.RefreshSupportedVersions (System.String[] referenceAssemblyPaths)
  at Xamarin.Android.Tasks.ResolveSdks.RunTask ()
  at Xamarin.Android.Tasks.ResolveSdks.Execute ()
  at Microsoft.Build.BackEnd.TaskExecutionHost.Microsoft.Build.BackEnd.ITaskExecutionHost.Execute ()

It's 51 lines from the end of the file; it is not hard to find this error message. (It is also repeated 5 times for various assemblies.)

The cause for the ArgumentNullException has already been determined and fixed.

@atsushieno
Copy link
Contributor

build

@atsushieno atsushieno merged commit 987a05f into dotnet:master Jun 14, 2018
@github-actions github-actions bot locked and limited conversation to collaborators Feb 2, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants