Bug 58029 - With NDK r12b+ AOT is successfull but JIT still happens and app as slow as w/o AOT
Summary: With NDK r12b+ AOT is successfull but JIT still happens and app as slow as w/...
Status: RESOLVED FIXED
Alias: None
Product: Android
Classification: Xamarin
Component: MSBuild ()
Version: 7.3 (15.2)
Hardware: PC Windows
: --- normal
Target Milestone: 15.4
Assignee: dean.ellis
URL:
Depends on:
Blocks:
 
Reported: 2017-07-08 15:18 UTC by Vitaly Knyazev
Modified: 2017-09-11 16:42 UTC (History)
6 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 Vitaly Knyazev 2017-07-08 15:18:18 UTC
After AOT/LLVM with Android NDK r11c everything is fine: AOT gives startup boost from 17 to 8 seconds and all screens are much more responsive.

After AOT/LLVM with Android NDK r12b (or newer like r13b installed with VS2017 or latest r15b): AOT is ok, APK size is similar, but it looks like AOT generated native code is not used at all during runtime - startup takes 17+ seconds and all screens are sluggish, especially first time as if they still JIT-ed.
Comment 1 Vitaly Knyazev 2017-07-08 15:19:41 UTC
Using slow device like Alcatel POP4 to estimate performance.
Comment 2 Vitaly Knyazev 2017-07-08 15:27:32 UTC
Xamarin.Android: 7.3.1.2
Xamarin.Forms: 2.3.5.256-pre6
Android support libs: 25.3.1
Visual Studio 2017: 15.2 (26430.15)
Target framework: Android 7.1 (API 25)
Minimum Android version: API 22
Target Android version: Android 7.1 (API 25)
Android SDK Tools: 25.2.5
Android SKD Platform-tools: 26
Android SDK Build-tool: 25.0.3
SDK API levels installed: 22, 23, 24, 25
Windows 10 Pro: 15063.413
Comment 3 Vitaly Knyazev 2017-07-08 15:31:03 UTC
Platform: armeabi-v7a
Comment 4 Vitaly Knyazev 2017-07-08 15:35:16 UTC
<DebugType>pdbonly</DebugType>
<Optimize>true</Optimize>
<AndroidUseSharedRuntime>False</AndroidUseSharedRuntime>
<AndroidLinkMode>SdkOnly</AndroidLinkMode>
<EmbedAssembliesIntoApk>true</EmbedAssembliesIntoApk>
<BundleAssemblies>true</BundleAssemblies>
<AndroidCreatePackagePerAbi>true</AndroidCreatePackagePerAbi>
<Debugger>Xamarin</Debugger>
<AotAssemblies>true</AotAssemblies>
<EnableLLVM>true</EnableLLVM>
<AndroidEnableMultiDex>false</AndroidEnableMultiDex>
<EnableProguard>true</EnableProguard>
<DebugSymbols>False</DebugSymbols>
<AndroidEnableSGenConcurrent>true</AndroidEnableSGenConcurrent>
<AndroidSupportedAbis>armeabi-v7a</AndroidSupportedAbis>
<AndroidExplicitCrunch>true</AndroidExplicitCrunch>
Comment 5 Cody Beyer (MSFT) 2017-07-13 19:12:44 UTC
Does this occur on all apps, or only on certain apps? if this is only present on certain apps, are you able to attach a sample which demonstrates the issue?

Thanks!
Comment 6 Vitaly Knyazev 2017-07-13 23:42:23 UTC
Yes it happens even with fresh and empty project. 
Here is the sample app, it is basically standard "Master Details" template with latest support packages:
https://github.com/VitalyKnyazev/Xamarin_NDK_Issue

See also folder READY_APK for 3 precompiled packages:
- NO AOT (startup time ~7 seconds consistently)
- AOT with NDK r11c (startup time ~3.5 seconds consistently)
- AOT with NDK r15b (startup time ~7 seconds consistently)

Please note that you do need a slow device like Alcatel POP4 (TCL 5051X) or similar to see the slowness.
Comment 7 Vitaly Knyazev 2017-07-20 11:04:47 UTC
Up, as I am not sure how it works here...
Comment 8 Jon Douglas [MSFT] 2017-07-26 17:05:36 UTC
> Please note that you do need a slow device like Alcatel POP4 (TCL 5051X) or similar to see the slowness.

The problem here is that this device has 1GB of RAM. That is quite low for today's standard. Given a new Google Pixel which have 4x that amount at 4GB of RAM.

Google has a recommendation of testing on the following types of devices based on:

- Screen Size
- Processor
- Device Memory

So ensure you are testing on multiple "slower" phones and not just one. i.e. Devices with 1GB, 2GB, 3GB, 4GB RAM.

https://developer.android.com/distribute/best-practices/develop/test-your-app.html

As for your samples, can you please ensure to sign these with a proper certificate and reupload? I'm getting the following error:

[INSTALL_PARSE_FAILED_NO_CERTIFICATES]

Also on other devices I'm seeing:

[INSTALL_FAILED_OLDER_SDK]

Which is because the minSdkVersion is set to 22:

<uses-sdk android:minSdkVersion="22" />

Perhaps change the minSdkVersion to API 19 or even API 14? That way more devices can be tested without having to upgrade.

Once I can get properly signed APKs, I can test this on a few respective devices such as a Nexus 5, Nexus 6, Galaxy S5, and Google Pixel.

Thank you!
Comment 9 Vitaly Knyazev 2017-07-27 22:46:04 UTC
Hi Jon,

I have updated the packages as requested, now they are all signed and min API is 14.

The whole idea of this measurement on slow device is to highlight the issue which makes (paid) AOT feature not just totally useless but actually damaging - slower build, larger package, same or worse runtime performance. Of course it all will work better on latest and greatest devices but what is the point if one can get same if not better performance without AOT altogether, all due to a (potentially simple) bug.

Changed status to NEW.

Thanks

Vitaly
Comment 10 Vitaly Knyazev 2017-07-27 22:51:19 UTC
By some reason I believe this is somehow related: https://bugzilla.xamarin.com/show_bug.cgi?id=48678
Comment 11 Jon Douglas [MSFT] 2017-07-28 15:57:58 UTC
I am able to CONFIRM this issue with the updated APKs in https://bugzilla.xamarin.com/show_bug.cgi?id=58029#c6

There definitely seems to be something going on as the performance from 11->13b+ is significantly worse. Out of all of the three packages the order of performance I've seen best results are the following:

11
13b
NO AOT

This was tested on a few different devices varying of RAM (1gb, 2gb, 3gb). It seems that 13b is almost as performant as having NO AOT. Thus I am CONFIRMING this issue. In the meantime, I will be digging into this further to see if I can see anything that sticks out. Otherwise we'll have to wait for our AOT experts to chime in.
Comment 12 Jon Douglas [MSFT] 2017-07-28 17:22:39 UTC
**Correction on the previous comment, I meant to say 15b instead of 13b.**

NO AOT - 07-28 12:44:45.311: I/ActivityManager(769): Displayed com.companyname.App1/md58adf3f2592a7497b73592b5e766304c2.MainActivity: +3s820ms

NDK 11 - 07-28 12:48:38.356: I/ActivityManager(769): Displayed com.companyname.App1/md58adf3f2592a7497b73592b5e766304c2.MainActivity: +1s990ms

NDK 15b - 07-28 12:50:24.307: I/ActivityManager(769): Displayed com.companyname.App1/md58adf3f2592a7497b73592b5e766304c2.MainActivity: +3s866ms

So something seems fishy here. To do the next step of debugging, I need these APKs to be "Debuggable" meaning they have the `android:debuggable="true"` set in the Application. You can set this by changing your config to "Debug" or adding it in manually:

https://developer.android.com/guide/topics/manifest/application-element.html#debug

They also need to include the following environment variable:

debug.mono.log timing

https://developer.xamarin.com/guides/android/advanced_topics/environment/#debug.mono.log

You can see a document page on how to add an environment file and an example here:

https://developer.xamarin.com/guides/android/advanced_topics/environment/#Overview

https://developer.xamarin.com/guides/android/advanced_topics/environment/#Example

We will then be able to get the counters and methods to see the AOT behavior via:

$ adb shell run-as com.companyname.App1 cat files/.__override__/counters.txt > counters-FullAOT.txt

$ adb shell run-as com.companyname.App1 cat files/.__override__/methods.txt > methods-FullAOT.txt

If you can apply these two items to your project and provide the APKs again, we can further look into this. I will be creating an environment to do all of this work in the future to stop pestering you. I figured it's easier to ask this last time while I do so.
Comment 13 Vitaly Knyazev 2017-07-28 18:03:12 UTC
No problem, uploaded 3 debuggable APK:
https://github.com/VitalyKnyazev/Xamarin_NDK_Issue
Comment 14 Jon Douglas [MSFT] 2017-07-28 19:16:50 UTC
NDK 11:

Total time spent JITting (sec)      : 0.0669

JIT'd methods - 8565 total lines, ~4282.5 JITed method lines

NDK 15b:

Total time spent JITting (sec)      : 0.5901

JIT'd methods - 11225 total lines, ~5612.5 JITed method lines

NO AOT:

Total time spent JITting (sec)      : 0.6025

JIT'd methods - 11225 total lines, ~5612.5 JITed method lines

This is a little bit more confirmation that something is going on here.

The problem I'm seeing is that there are tons of `dlopen failed` logs for each AOT image with NDK 15b.

07-28 14:39:46.585: D/Mono(5686): Config attempting to parse: '/usr/local/etc/mono/assemblies/Xamarin.Android.Support.v4/Xamarin.Android.Support.v4.config'.
07-28 14:39:46.585: D/Mono(5686): Assembly Loader probing location: '/usr/local/lib/Xamarin.Android.Support.v7.AppCompat.dll'.
07-28 14:39:46.585: D/Mono(5686): Unloading image Xamarin.Android.Support.v7.AppCompat.dll [0xa0cb0100].
07-28 14:39:46.585: D/Mono(5686): Assembly Loader loaded assembly from bundle: 'Xamarin.Android.Support.v7.AppCompat.dll'.
07-28 14:39:46.587: W/linker(5686): /data/app/com.companyname.App1-1/lib/arm/libaot-Xamarin.Android.Support.v7.AppCompat.dll.so: is missing DT_SONAME will use basename as a replacement: "libaot-Xamarin.Android.Support.v7.AppCompat.dll.so"

07-28 14:39:46.590: D/Mono(5686): AOT: image 'Xamarin.Android.Support.v7.AppCompat.dll.so' not found: dlopen failed: cannot locate symbol "__aeabi_memset" referenced by "/data/app/com.companyname.App1-1/lib/arm/libaot-Xamarin.Android.Support.v7.AppCompat.dll.so"...
07-28 14:39:46.591: W/linker(5686): /data/app/com.companyname.App1-1/lib/arm/libaot-Xamarin.Android.Support.v7.AppCompat.dll.so: is missing DT_SONAME will use basename as a replacement: "libaot-Xamarin.Android.Support.v7.AppCompat.dll.so"
07-28 14:39:46.593: D/Mono(5686): AOT: image '/usr/local/lib/mono/aot-cache/arm/Xamarin.Android.Support.v7.AppCompat.dll.so' not found: dlopen failed: cannot locate symbol "__aeabi_memset" referenced by "/data/app/com.companyname.App1-1/lib/arm/libaot-Xamarin.Android.Support.v7.AppCompat.dll.so"...

In other words it's saying that "NO AOT FOR YOU". This versus the NDK 11:

07-28 14:57:21.627: D/Mono(8617): AOT: image 'Xamarin.Android.Support.v7.AppCompat.dll.so' found.

So although the .so files are making it to the device(installed and included in APK), it seems that they are failing to be used.
Comment 15 Vitaly Knyazev 2017-07-28 20:17:02 UTC
Thanks for confirming the issue, it means I am not just paranoid :)

Half a second difference for an empty app means at least 1.5 seconds for my app on the same device, quite noticeable delay... Plus further JIT delays for each view.

Hopefully it is easy to fix.
Comment 16 Jonathan Pryor 2017-08-28 16:31:04 UTC
This looks relevant: https://github.com/android-ndk/ndk/issues/126

TL;DR: `AndroidManifest.xml` has the concept of a `minSdkVersion` and `targetSdkVersion`:

https://developer.android.com/guide/topics/manifest/uses-sdk-element.html

The NDK builds uses these conceptual values, and requires that you use minSdkVersion to build native code.

Unfortunately, the `<Aot/>` task doesn't use `minSdkVersion` or `targetSdkVersion`; it uses `$(TargetFrameworkVersion)` (which is often `targetSdkVersion`, but need not be).

For example, Comment #2:

> Minimum Android version: API 22
> Target framework: Android 7.1 (API 25)

We will be passing API-25 to the `<Aot/>` toolchain, when we *need* to be passing API-22.

Context:

# androidLibPath -- which contains `libc.so` -- is based on `AndroidApiLevel`
https://github.com/xamarin/xamarin-android/blob/97f08f7/src/Xamarin.Android.Build.Tasks/Tasks/Aot.cs#L366

# $(_AndroidApiLevel) is used to set the Aot.AndroidApiLevel property:
https://github.com/xamarin/xamarin-android/blob/a06e0e3/src/Xamarin.Android.Build.Tasks/Xamarin.Android.Common.targets#L2153

# $(_AndroidApiLevel) comes from <ResolveSdks/>
https://github.com/xamarin/xamarinandroid/blob/a06e0e3/src/Xamarin.Android.Build.Tasks/Xamarin.Android.Common.targets#L617

# ResolveSdks.AndroidApiLevel comes from $(TargetFrameworkVersion)
https://github.com/xamarin/xamarin-android/blob/8942eca/src/Xamarin.Android.Build.Tasks/Tasks/ResolveSdksTask.cs#L379-L433

To fix this, we need to update the `<Aot/>` task to instead use `minSdkVersion` instead of `$(TargetFrameworkVersion)` to determine the appropriate NDK paths.
Comment 17 Jonathan Pryor 2017-08-30 21:03:55 UTC
PR: https://github.com/xamarin/xamarin-android/pull/795
Comment 18 Jonathan Pryor 2017-08-31 15:55:42 UTC
d15-4 PR: https://github.com/xamarin/xamarin-android/pull/805
Comment 19 Jonathan Pryor 2017-09-11 16:42:42 UTC
Fixed in:

https://github.com/xamarin/xamarin-android/commit/eca0e84ecbdbbfa85048f85c5a50317b5d67bf10
monodroid/d15-4/a54187cd

Fix should be available in Xamarin.Android 8.0.0.3 and later.