Bug 10840 - Fast deployment option makes deployment slow...
Summary: Fast deployment option makes deployment slow...
Status: RESOLVED FIXED
Alias: None
Product: Android
Classification: Xamarin
Component: General ()
Version: 4.6.x
Hardware: Macintosh Mac OS
: --- normal
Target Milestone: ---
Assignee: Bugzilla
URL:
Depends on:
Blocks:
 
Reported: 2013-03-02 03:59 UTC by NeoDarque
Modified: 2013-05-03 13:23 UTC (History)
5 users (show)

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

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:
RESOLVED FIXED

Description NeoDarque 2013-03-02 03:59:54 UTC
In a Xamarin.Android project using Xamarin.Studio 4.0, if I enable the "Fast deployment" option for a project the deploy gets reaaaally slow instead of faster, takes about a minute instead of the few seconds when it's off (both to emulator and real device).
But if I disable "fast deployment" none of my breakpoints will ever be hit, so I have to enable the "fast deployment" option... which is a terrible deployment experience.
Comment 1 Mikayla Hutchinson [MSFT] 2013-03-02 17:06:03 UTC
What stage of the "fast" deploy is slow?
Comment 2 NeoDarque 2013-03-02 17:15:13 UTC
Xamarin Studio says in the little status area up top "Deployment completed" pretty quickly. But then it just hangs there for another 30 seconds or so.

Looking in the Application output area it hangs after "Detecting existing process".
And when it comes back to life again and actually starts the app it spits out the following:

"Terminated existing processMonoDroid-Handshake"
"Error opening trace file: No such file och directory (2)"
Comment 3 Jonathan Pryor 2013-03-31 22:32:07 UTC
The purpose behind Fast Deployment is to speed up turnaround by _avoiding_ rebuilding and reinstalling the .apk, and instead "only" deploying the assemblies that have changed. This isn't always possible, e.g. when a new Java.Lang.Object subclass is added or a new Java virtual method is overridden, but it is frequently possible.

Steps to reproduce:

1. Create a new project with the default template.

2. time xbuild /t:Install *.csproj /v:diag > build1.txt

real	0m17.543s
user	0m8.995s
sys	0m0.703s

3. Ideal case: no changes at all!

$ time xbuild /t:Install *.csproj /v:diag > build2.txt

real	0m3.268s
user	0m1.136s
sys	0m0.105s

OK, not "blazing fast", but much faster than the initial build.

4. No changes, but updated filetime:

$ touch *.cs
$ time xbuild /t:Install *.csproj /v:diag > build3.txt

real	0m10.212s
user	0m8.807s
sys	0m0.476s

Now the pain starts.

Why is (4) so slow? From `build3.txt`:

> Target _BuildApkFastDev needs to be built as input file 'obj/Debug/android/bin/classes.dex' is newer than output file 'obj/Debug/android/bin/resources_and_assemblies'
...
> 	Target _Upload:
> 	Task "InstallPackageAssemblies"
...
> 		DEBUG: RunShellCommand:R32CA05X6KN pm uninstall -k "Scratch.HelloXamarin20"
> 		TASK: Push bin/Debug/Scratch.HelloXamarin20-Signed.apk : /data/local/tmp/Scratch.HelloXamarin20-Signed.apk completed?:587664
> 		DEBUG: RunShellCommand:R32CA05X6KN pm install "/data/local/tmp/Scratch.HelloXamarin20-Signed.apk"
...

In short, it's slow because we rebuild the .apk, uninstall the existing app, reinstall it, then re-sync all the assemblies.

Ouch.
Comment 4 Jonathan Pryor 2013-03-31 22:33:57 UTC
This regression was probably introduced when fixing Bug #4642.
Comment 5 Jonathan Pryor 2013-04-03 21:57:15 UTC
Confirmed; the fix for Bug #4642 created this regression.
Comment 6 Jonathan Pryor 2013-04-04 12:38:10 UTC
Fixed in monodroid/2a082c6c.

For those currently hitting this, I'm sorry. You can fix this locally by making the following two changes to Xamarin.Android.Common.targets:

1. In the _GenerateJavaStubs target, remove this line:

        <Touch Files="$(IntermediateOutputPath)android\AndroidManifest.xml;$(_AcwMapFile)" />

2. In the _GeneratePackageManagerJava target, remove this line:

        <Touch Files="$(IntermediateOutputPath)android\src\mono\MonoPackageManager.java" />

Rebuilds should then be faster.
Comment 7 Jonathan Pryor 2013-04-08 11:15:50 UTC
Backported to the 4.6.x branch as monodroid/c6a5183c.
Comment 8 JLee 2013-04-15 08:00:44 UTC
This bug is reported to be fixed with release 4.6.3.
I can't confirm this. I checked with release 4.6.3 and 4.6.4. and the problem still persists.
My build takes over 2 minutes if I change a .cs codefile.
Packaging is perfomed with every build, even if no .cs codefile has been changed (takes over 70 seconds).

My mono-debug-setting are:
linking = none
use shared runtime = yes
fast deployment = yes

In 4.6.2 the above-mentioned workaround from Jon doesn't work for me, also.
Comment 9 Jonathan Pryor 2013-04-15 08:13:56 UTC
@JLee: Can you provide your diagnostic build output?

Does it improve if you remove your bin and obj directories and rebuild entirely?

Does your project have any pre-build or post-build steps?

The point to Fast Deployment is that rebuilding and reinstalling the .apk can be skipped if the .apk hasn't changed (e.g. no new Android resources, no AndroidManifest.xml changes, no new Java.Lang.Object subclassses or new Java virtual method overrides).

> My build takes over 2 minutes if I change a .cs codefile.

What kind of change?

> Packaging is perfomed with every build, even if no .cs codefile has been
> changed (takes over 70 seconds).

That is deeply worrying. Are you on OS X or Windows?

My current shot-in-the-dark guess is that you're on OSX with some pre-build or post-build steps. Pre/post build steps require running md-tool on OSX, which will slow down the build, and if said steps alter file times on the "wrong" files, a ful rebuild may be forced.

Diagnostic build output will help in tracking this down.

Finally, please try command-line based deployment:

http://docs.xamarin.com/guides/android/advanced_topics/build_process#Build_Targets

    > MSBuild /t:Install App.csproj /v:diag > build-1.txt
    > MSBuild /t:Install App.csproj /v:diag > build-2.txt

(This is primarily to see install-related messages as well; otherwise you'd have to hunt down Xamarin Studio's AndroidTools log file or Visual Studio's monodroid.log file...)
Comment 10 JLee 2013-04-15 10:07:42 UTC
@Jon

I have sent the two build-outputs to hello@xamarin.com as a zipfile.

> What kind of change?

e.g. adding string test = "hello world"; to a random .cs file triggers the full compilation-time.

> Does it improve if you remove your bin and obj directories and rebuild
entirely?

after installing 4.6.3 and 4.6.4 I wiped the obj and bin folders completely - so no

> Are you on OS X or Windows?
I'm on Win7 32bit, VS2010

> My current shot-in-the-dark guess is that you're on OSX with some pre-build or
post-build steps.

I think, I haven't any pre/post-buildoptions. I always worked with mono as it came "out of the box". How can I check?

additional info:
I work with two .net 3rd party libraries (ICSharpCode.SharpZipLib and Ionic.Zip.Reduced for zipping) and an Android-Binding-Library with an embedded jar file for printing on a fujitsu-printer.
Comment 11 Jonathan Pryor 2013-04-23 15:27:01 UTC
Thank you for providing the build output.

Careful (translated) review of the build output suggests that the problem is the _AddTrialSplashScreenResources. This was confirmed by the QA team which also sees no speedup in step (4) when a Trial license is being used.

Are you using a Trial license?
Comment 12 Jonathan Pryor 2013-04-23 16:13:43 UTC
Discussion of Fast deployment on Trial editions (Comment #8 through Comment #11) has been moved to Bug #11918.
Comment 13 JLee 2013-04-29 06:56:36 UTC
Ok, then tell me please, where I can check, if my system wronly! runs in Trial Mode.
My License (professesional) is from 06/2012. Under 4.6.4 I was successfully logged in into my account (in VS2012) and my workstation is registerd in the account. When my system runs on trial, it's another bug in mono and no user-error.
Comment 14 JLee 2013-04-29 08:03:58 UTC
I mean VS2010 not VS2012.
Comment 15 Jonathan Pryor 2013-04-29 20:51:30 UTC
> tell me please, where I can check, if my system wronly! runs in Trial Mode.

Open CMD.EXE and enter:

    "%ProgramFiles(x86)%\MSBuild\Xamarin\Android\mandroid.exe" --version > %TMP%\o.txt
    notepad %TMP%\o.txt

%TMP%\o.txt will contain Trial if you have Trial mode enabled.
Comment 16 Jonathan Pryor 2013-05-03 13:23:44 UTC
@JLee: Re-reading the build output provided on April 15. (Which means everything I'm about to ask is out of date, but c'est la vie).

It occurred to me to search for "neuer als", which finds these interesting hits in build-2.txt:

> Die Eingabedatei "C:\Users\User\Documents\Entwicklung\OwiGo_Smart\src\Android\obj\Debug\res\layout\picker_parkzeit.xml" ist neuer als die Ausgabedatei "obj\Debug\R.cs.flag".

Since picker_parkzeit.xml is newer than R.cs.flag, ~everything needs to be rebuilt: `aapt` needs to be re-run, which means a new .apk needs to be generated, which means the previous app needs to be uninstalled and the new .apk installed.

What is the timestamp on `obj\Debug\res\layout\picker_parkzeit.xml` vs. `obj\Debug\R.cs.flag` and `obj\Debug\android\bin\packaged_resources`?


Meanwhile, this following hit should be ignorable:

> Die Eingabedatei "C:\Users\User\Documents\Entwicklung\OwiGo_Smart\src\Android\bin\Debug\OwiGo_Smart_Android.dll" ist neuer als die Ausgabedatei "obj\Debug\android\src\mono\MonoPackageManager.java".

That should "just" result in re-running <GeneratePackageManagerJava/>, which will create ACWs, but if the ACWs haven't changed then it shouldn't, in itself, cause a .apk rebuild+reinstall.

All remaining matches for "neuer als" are because `res\layout\picker_parkzeit.xml` is newer, necessitating cascading rebuilds:

> Die Eingabedatei "C:\Users\User\Documents\Entwicklung\OwiGo_Smart\src\Android\obj\Debug\res\layout\picker_parkzeit.xml" ist neuer als die Ausgabedatei "obj\Debug\android\bin\packaged_resources".
> Die Eingabedatei "obj\Debug\android\bin\packaged_resources" ist neuer als die Ausgabedatei "obj\Debug\android\bin\resources_and_assemblies".
> Die Eingabedatei "obj\Debug\android\bin\resources_and_assemblies" ist neuer als die Ausgabedatei "bin\Debug\de.owigo.smart.apk".
> Die Eingabedatei "obj\Debug\android\bin\de.owigo.smart.apk" ist neuer als die Ausgabedatei "bin\Debug\de.owigo.smart-Signed.apk".

These cascading rebuilds are death; it's why things are so slow.

---

So let's further investigate `obj\Debug\res\layout\picker_parkzeit.xml`, which appears to be the root cause here. It's timestamp is set in the `_GenerateAndroidResourceDir` target with the `<Touch/>` task:

> <Target Name="_GenerateAndroidResourceDir"
> 	Inputs="$(MSBuildAllProjects);@(AndroidResource)"
> 	Outputs="@(_AndroidResourceDest)">
> 	<Copy SourceFiles="@(AndroidResource)" DestinationFiles="@(_AndroidResourceDest)" SkipUnchangedFiles="true" />
> 	<RemoveUnknownFiles Files="@(_AndroidResourceDest)" Directory="$(MonoAndroidResDirIntermediate)" RemoveDirectories="true" />
> 	<Touch Files="@(_AndroidResourceDest)" />
> </Target>

According to the build output, _GenerateAndroidResourceDir isn't executed:

> Das Ziel "_GenerateAndroidResourceDir" wird bersprungen, da alle Ausgabedateien hinsichtlich der Eingabedateien aktuell sind.

R.cs.flag, meanwhile, is created by the `_UpdateAndroidResgen` task:

> <Target Name="_UpdateAndroidResgen"
> 	Inputs="$(MSBuildAllProjects);@(ResolvedLibraryOutputs);@(_AndroidResourceDest)"
> 	Outputs="$(_AndroidResgenFlagFile)"
> 	Condition="'$(AndroidResgenFile)' != ''"
> 	DependsOnTargets="_CheckForDeletedResourceFile;_ValidateAndroidPackageProperties;_ResolveMonoAndroidSdks;_GetLibraryImports;_CheckDuplicateJavaLibraries;_AddTrialSplashScreenResources">

Looking at this now, the interesting bit is that _GenerateAndroidResourceDir creates/update obj\Debug\res\*, while _UpdateAndroidResgen processes those files to create R.cs.flag, yet there's no explicit dependency between those targets.

There is an implicit one:

> <Target Name="UpdateAndroidResources"
> 	DependsOnTargets="_CheckForDeletedResourceFile;_ComputeAndroidResourcePaths;_GenerateAndroidResourceDir;_UpdateAndroidResgen;_AddLibraryProjectsEmbeddedResourceToProject" />

How is DependsOnTargets evaluated? http://msdn.microsoft.com/en-us/library/vstudio/t50z2hka.aspx

> The MSBuild engine executes dependencies in the order in which they appear in the DependsOnTargets attribute, from left to right. For more information, see MSBuild Targets.

So _GenerateAndroidResourceDir should be executed before _UpdateAndroidResgen, which is correct.

Furthermore, reviewing build-2.txt I see that _GenerateAndroidResourceDir is executed before _UpdateAndroidResgen.

So it makes no sense at all to me that R.cs.flag would be older than obj\Debug\res\layout\picker_parkzeit.xml.

What are the timestamps of obj\Debug\R.cs.flag and obj\Debug\res\layout\picker_parkzeit.xml? How is it that picker_parkzeit.xml has a newer timestamp?