Bug 58169 - _UpdateAndroidResgen constantly being called
Summary: _UpdateAndroidResgen constantly being called
Status: VERIFIED FIXED
Alias: None
Product: Android
Classification: Xamarin
Component: MSBuild ()
Version: 7.3 (15.2)
Hardware: Macintosh Mac OS
: Normal normal
Target Milestone: 15.4
Assignee: dean.ellis
URL:
Depends on:
Blocks:
 
Reported: 2017-07-14 17:44 UTC by Jake Louw
Modified: 2017-10-13 20:05 UTC (History)
5 users (show)

Tags: 15.5
Is this bug a regression?: ---
Last known good build:


Attachments
project + msbuild outputs (1.56 MB, application/zip)
2017-07-14 17:44 UTC, Jake Louw
Details


Notice (2018-05-24): bugzilla.xamarin.com is now in read-only mode.

Please join us on Visual Studio Developer Community and in the Xamarin and Mono organizations on GitHub to continue tracking issues. Bugzilla will remain available for reference in read-only mode. We will continue to work on open Bugzilla bugs, copy them to the new locations as needed for follow-up, and add the new items under Related Links.

Our sincere thanks to everyone who has contributed on this bug tracker over the years. Thanks also for your understanding as we make these adjustments and improvements for the future.


Please create a new report on Developer Community or GitHub with your current version information, steps to reproduce, and relevant error messages or log files if you are hitting an issue that looks similar to this resolved bug and you do not yet see a matching new report.

Related Links:
Status:
VERIFIED FIXED

Description Jake Louw 2017-07-14 17:44:17 UTC
Created attachment 23570 [details]
project + msbuild outputs

Hi Xamarin,

I'm trying to optimize the build speed of our Android application. I've noticed through diagnostic outputs of MSBuild that aapt is constantly being run when C# code changes are made in referencing assemblies (i.e. not touching any of the Android resources). It's worth mentioning that _UpdateAndroidResgen on our production applications takes around 20 seconds to run on my mid-2010 MBP. As of such, deployment times are brutally slow and frustrating.

Let's walk through the sample build project attached:

In MainActivity.cs in ResGenBug, I refactor the count field to 'countz'. I then deploy to my emulator. As seen in ResGenBugCountRefactor (contained in the zip file attached), _UpdateAndroidResgen is not called. Worth noting that the same behaviour exists for both fields and properties. Awesome!

In Test.cs in ResGenLibrary, I refactor the Bug property to 'Bugz'. I then deploy to my emulator. As seen in ResGenLibraryBugRefactor (contained in the zip file attached), _UpdateAndroidResgen is called and aapt is run. However, no resources were changed. It's also worth noting that ResGenLibrary can also be a .NET Standard library (not a Android library as presented in the attachment), and the same pattern emerges.

Please advise,
Jake.
Comment 1 Jon Douglas [MSFT] 2017-07-14 18:36:36 UTC
The ResGenLibraryBugRefactor logs show a few large build items based on the MSBuild summary:

      578 ms  _BuildAdditionalResourcesCache             1 calls
      858 ms  _UpdateAndroidResgen                       1 calls
     1248 ms  CoreCompile                                1 calls
...
      577 ms  GetAdditionalResourcesFromAssemblies       1 calls
     1207 ms  Aapt                                       2 calls
     1246 ms  Csc                                        1 calls


So we see a few culprits: _UpdateAndroidResgen at .8s, GetAdditionalResourcesFromAssemblies at .5s and Aapt at 1.2s. In total give or take 2.5 extra seconds of build time.

Let's take an example from my point of view loading this project initially:

2>      687 ms  LinkAssemblies                             1 calls
2>      752 ms  GenerateJavaStubs                          1 calls
2>      766 ms  CreateAdditionalLibraryResourceCache       1 calls
2>     1341 ms  Aapt                                       3 calls
2>     1587 ms  Javac                                      1 calls
2>     3995 ms  CompileToDalvik                            1 calls

This is a full build of both projects just to test this behavior out. This is typically expected as this project was never built on this machine until now.

A) Refactor the count field inside MainActivity.cs

1>       67 ms  _UpdateAndroidResgen                       1 calls
...
2>      517 ms  CreateAdditionalLibraryResourceCache       1 calls
2>      806 ms  GenerateJavaStubs                          1 calls
2>      967 ms  Javac                                      1 calls
2>     1042 ms  Aapt                                       3 calls
2>     3234 ms  CompileToDalvik                            1 calls

B) Refactor the Bugs field inside Test.cs

1>       50 ms  _UpdateAndroidResgen                       1 calls
...
2>      564 ms  CreateAdditionalLibraryResourceCache       1 calls
2>      930 ms  Javac                                      1 calls
2>     1128 ms  Aapt                                       3 calls
2>     3159 ms  CompileToDalvik                            1 calls

However I did not touch any resources, I only touched C# code in both an Android project and an Android Library project.

So it seems that Aapt is called regardless. Let's look into MSBuild Structured Log Viewer for more details:

We can see that the Aapt Task is called in the following Targets:

_UpdateAndroidResgen
_GenerateJavaDesignerForComponent
_CreateBaseApk

However let's just dig into _UpdateAndroidResgen for now

We can see it depends on the following targets:

_CheckForDeletedResourceFile
_ResolveMonoAndroidSdks
_ValidateAndroidPackageProperties
_GetLibraryImports
_CheckDuplicateJavaLibraries
_GetAdditionalResourcesFromAssemblies
_CreateAdditionalResourceCache
_GenerateAndroidResourceDir
_DefineBuildTargetAbis

https://github.com/xamarin/xamarin-android/blob/a35e52abed7468e359918f913270fafc8f5a1cfc/src/Xamarin.Android.Build.Tasks/Xamarin.Android.Common.targets#L1231-L1240

So it seems this is executed every build regardless. Even in your build logs prior we see _UpdateAndroidResgen is fired off:

4 ms  _UpdateAndroidResgen                       1 calls

However...

Skipping target "_UpdateAndroidResgen" because all output files are up-to-date with respect to the input files.

For the troublesome refactor logs, we see that Target is actually being fired off.

Building target "_UpdateAndroidResgen" completely.

Which is where we see the .8s:

858 ms  _UpdateAndroidResgen                       1 calls

Thus this Bug should be confirmed as it seems like there are excess calls to Aapt via the _UpdateAndroidResgen target when it should be skipped if Resources have not been modified in some way.
Comment 2 dean.ellis 2017-07-17 09:56:25 UTC
Jake

Thanks for the bug report and the repo project. Its nice to have :) 
I will take a look at this , hopefully we will be able to get that issue resolved.

Dean
Comment 3 dean.ellis 2017-07-17 10:15:31 UTC
Jake

Just some information for you. There is a reason why the '_UpdateAndroidResgen' is run when a library project changes. 
As part of the build process for a library project we have to embed the resources into the assembly. This is because msbuild does not allow you to access files outside of the current project directory. So we embed them and extract those resources into the app's obj/Debug/library_projects directory for processing.

So when you update the code in the library project we end up repackaging the resources into the .dll. 

The _UpdateAndroidResgen target as one of its inputs uses the @(ReferencePath) or @(ReferenceDependencyPaths) to figure out if it needs to run [1]. This is so we can extract the resources from the updated assemblies.

So if the .dll gets updated then we end up running _UpdateAndroidResgen. This will be the reason why that target is running when you touch a .cs file. 

Now what we might be able to do is optimise things a bit more and only run that main target if the resources have been updated in the library. I will start looking at that as soon as I can. 

I the mean time I thought it might be helpful to have an explanation as to what is happening currently :).


[1] https://github.com/xamarin/xamarin-android/blob/master/src/Xamarin.Android.Build.Tasks/Xamarin.Android.Common.targets#L1244
Comment 4 Jake Louw 2017-07-17 16:06:08 UTC
Thanks Dean for the explanation.

We have temporarily moved all working-code into our main project as a temporary solution to fix our slow deploy times.

Would definitely like to see this issue resolved soon though - one of our developers is now working on quite a hacked-up branch.

Here's an x-ref to the same issue started by Jonathan Pryor (the first issue):
https://bugzilla.xamarin.com/show_bug.cgi?id=57018

Cheers,
Jake.
Comment 5 dean.ellis 2017-07-26 10:14:23 UTC
PR is now up for this issue https://github.com/xamarin/xamarin-android/pull/702

It reworks the way we deal with resources on incremental builds. The theory being that if you only update C# code we use the zip from the previous build with no changes. This new system should stop the `_UpdateAndroidResgen` target constantly being called.
Comment 6 dean.ellis 2017-08-01 11:52:52 UTC
Fixed in xamarin-android/master/86888322
Comment 7 Jake Louw 2017-08-08 15:37:47 UTC
Thanks Dean for the quick fix!

Looking forward to this fix appearing in the alpha channel.

Cheers,
Jake.
Comment 8 Peter Collins 2017-08-17 21:48:09 UTC
@Jake this fix will be included in our next Alpha update, which should be available early next week.

I've tested this change against a couple of projects (including the one attached) and can confirm that _UpdateAndroidResgen is being skipped after editing a .cs file in a library project. Comparison testing was done against d15-3 stable and d15-4/14c1494d (7.5.0.13).

Details for the attached project can be found below. Timings are for an `Install` call _after_ modifying the 'Bugs' field inside Test.cs.

MSBuild target performance summary for 15.3:

>  432 ms  _CreateBaseApk                             1 calls
>  615 ms  _UpdateAndroidResgen                       2 calls
> 1182 ms  _BuildApkFastDev                           1 calls
> 1396 ms  ResolveProjectReferences                   2 calls
> 1507 ms  _Sign                                      1 calls
> 1531 ms  CoreCompile                                2 calls
> 4522 ms  _Upload     
MSBuild target performance summary for 15.4:
        
>    1 ms  _CreateBaseApk                             1 calls
>    3 ms  _UpdateAndroidResgen                       2 calls
>    2 ms  _BuildApkFastDev                           1 calls
> 1470 ms  ResolveProjectReferences                   2 calls
>    1 ms  _Sign                                      1 calls
> 1532 ms  CoreCompile                                2 calls
> 1567 ms  _Upload                                    1 calls
Comment 9 Jake Louw 2017-10-13 20:05:17 UTC
Confirmed fixed in our app. Thanks guys!