Skip to content
New issue

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

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

Already on GitHub? # to your account

[Xamarin.Android.Build.Tasks] not so many log messages! #2952

Merged
merged 1 commit into from
Apr 10, 2019

Conversation

jonathanpeppers
Copy link
Member

We used to have the pattern of including log messages at the beginning
of Execute() in MSBuild tasks:

Log.LogDebugMessage ("MyMSBuildTask Task");
Log.LogDebugMessage ("  FooProperty: {0}", FooProperty);
Log.LogDebugTaskItems ("  BarItems: ", BarItems);

This was mostly here to improve diagnostic log output from XBuild,
which we no longer support.

MSBuild properly logs any input properties on MSBuild tasks, so we can
remove a lot of code!

There were a couple places I could go a step further:

  • <AndroidCreateDebugKey/> and <AndroidZipAlign/> I could remove
    the entire Execute() method.
  • <JavaCompileToolTask/> had an OnLogStarted method I could
    remove. <Javac/> also was overriding this method.

I thought this might have some impact on build times, since logging
and string.Format takes some time (it's not free!).

A build of the Xamarin.Forms app in this repo:

# Before
Time Elapsed 00:00:25.66
Time Elapsed 00:00:25.36
Time Elapsed 00:00:25.67
# After
Time Elapsed 00:00:24.58
Time Elapsed 00:00:23.98
Time Elapsed 00:00:24.98

The overall build times vary quite a bit. So if I took a conservative
estimate it seems the initial build is 500ms better?

A more revealing difference, I think, is the size of these binlog
files:

# fresh build
746947 before.first.binlog
740797 after.first.binlog
# build with no changes
827913 before.second.binlog
825665 after.second.binlog
# build with xaml change
848821 before.third.binlog
844365 after.third.binlog

These files are compressed, so if they are 2K-6K smaller that was a
lot of log messages...

We used to have the pattern of including log messages at the beginning
of `Execute()` in MSBuild tasks:

    Log.LogDebugMessage ("MyMSBuildTask Task");
    Log.LogDebugMessage ("  FooProperty: {0}", FooProperty);
    Log.LogDebugTaskItems ("  BarItems: ", BarItems);

This was mostly here to improve diagnostic log output from XBuild,
which we no longer support.

MSBuild properly logs any input properties on MSBuild tasks, so we can
remove a lot of code!

There were a couple places I could go a step further:

* `<AndroidCreateDebugKey/>` and `<AndroidZipAlign/>` I could remove
  the entire `Execute()` method.
* `<JavaCompileToolTask/>` had an `OnLogStarted` method I could
  remove. `<Javac/>` also was overriding this method.

I thought this might have *some* impact on build times, since logging
and `string.Format` takes some time (it's not free!).

A build of the Xamarin.Forms app in this repo:

    # Before
    Time Elapsed 00:00:25.66
    Time Elapsed 00:00:25.36
    Time Elapsed 00:00:25.67
    # After
    Time Elapsed 00:00:24.58
    Time Elapsed 00:00:23.98
    Time Elapsed 00:00:24.98

The overall build times vary quite a bit. So if I took a conservative
estimate it seems the initial build is 500ms better?

A more revealing difference, I think, is the size of these binlog
files:

    # fresh build
    746947 before.first.binlog
    740797 after.first.binlog
    # build with no changes
    827913 before.second.binlog
    825665 after.second.binlog
    # build with xaml change
    848821 before.third.binlog
    844365 after.third.binlog

These files are compressed, so if they are 2K-6K smaller that was a
lot of log messages...
@jonpryor
Copy link
Member

Perusing the test failures, our network is bad and makes me feel bad (ALWAYS NETWORK FAILURES), Java.Interop-PerformanceTests.Possible Crash / Release is not that uncommon and is ignorable, but Mono.Android_TestsMultiDex.Possible Crash / Release is worrying:

XA/RuntimeTest: FAILURE: JNIEnv* wasn't changed!

This means that the condition the test was checking for isn't happening, which...could make some sense (that behavior was from a very old Android version, though the assertion has succeeded until now!), except we haven't touched the emulator or anything which would introduce such a change.

Fascinating.

I'm restarting the build.

@jonpryor jonpryor merged commit 28e1f93 into dotnet:master Apr 10, 2019
@github-actions github-actions bot locked and limited conversation to collaborators Jan 31, 2024
# for free to subscribe to this conversation on GitHub. Already have an account? #.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants