Skip to content

Commit

Permalink
[monodroid] Runtime startup performance improvements (#2515)
Browse files Browse the repository at this point in the history 
Fixes: #1443
Context: https://jenkins.mono-project.com/view/Xamarin.Android/job/xamarin-android/plot/Tests%20times/

A frequent complaint with Xamarin.Android is that application startup
times can be slower than desired.  For example, see the
[Xamarin.Forms app startup data][xf-startup], in particular the
**init-Release** column (times in milliseconds), which is the time
at which the `Runtime.init: end native-to-managed transition` message
is printed when `timing` messages are enabled.

As of Jenkins build 1359, the **init-Release** value is 518ms.

(Note that the times in that table are not necessarily useful, nor
are they future proof: they come from the emulator that the Jenkins
build machine uses, and that emulator *has* changed and *will* change
in the future.  Additionally, because it's an x86-accelerated
emulator, times are not meaningful to Android hardware devices.  The
values also fluctuate a lot.  Better than nothing? ¯\_(ツ)_/¯)

Optimize some startup operations to reduce the **init-Release** value:

  * JNI Handling Improvements:
      * Reduce Java class lookup.
      * Don't lookup `android.os.Build.VERSION.SDK_INT` via JNI.
      * `jstring` handling improvements.
  * Review logging messages.
  * Improve package name hash generation.
  * Improve environment variable processing.
  * Mono Handling Improvements
      * Stop preloading all assemblies.
      * Avoid using "system properties" to control Mono features.
  * Desktop version is now a compile-time build option, not runtime.
  * Initialize `xamarin_getifaddrs()` on-demand, not at startup.

[xf-startup]: https://jenkins.mono-project.com/view/Xamarin.Android/job/xamarin-android/plot/Tests%20times/#plot-8694435842335223270.csv

~~ JNI Handling Improvements ~~

Previously, JNI was used to lookup the
`android.os.Build.VERSION.SDK_INT` value.  We now pass
`Build.VERSION.SDK_INT` into `Runtime.init()`, avoiding the JNI calls.

Previously, `JNIEnv::FindClass()` was used during process startup in
order to lookup multiple types which are required for operation.
These types are now fields on the `mono.android.Runtime` type, and
`JNIEnv::GetStaticObjectField()` is used to obtain the `jclass`.

Additionally, a handful of class field/method lookups were moved out
of the init code so that the code that doesn't use them doesn't have
to pay the tax.

`jstring` and `jobjectArray`-of-`jstring` values are now handled by
the new `jstring_wrapper` and `jstring_array_wrapper` types, which
take care of efficiently caching the retrieved strings as well as of
correctly deleting local references to the obtained objects.
Both classes are optimized so that they compile into the equivalent
of the current, hand-written, code.  They also take care to make the
minimum necessary number of calls in order to access the strings,
both standalone and from arrays, as well as to release the resources.
The string and array wrapper instances are passed around as
references, thus using the minimum amount of memory.


~~ Log Messages ~~

Previously whenever any of the `log_{info,debug}()` functions were
called we'd spend time preparing all the parameters to pass to the
function, sometimes involving memory allocation, function calls, etc.,
only to discard all of that work **inside** the `log_*` call because
the logging category used in that call was disabled.

Now we check whether the category is enabled before we set out to
construct the parameters.


~~ Environment Processing ~~

Since [2012-Aug-16][env-support], `@(AndroidEnvironment)` has worked
by creating a file named `environment` within the `.apk` -- which is
stored uncompressed within the `.apk` -- and the file is then
processed, calling **setenv**(3) to store the recorded values.

There's a fair bit of potentially hairy string manipulation here,
from ***C***, which is not entirely ideal or performant.

To speed the process up, this commit replaces the `environment` file
with a Java class generated during application build which contains
an array of `"name", "value"` pairs.  The class is passed to
`Java_mono_android_Runtime_init()` and its elements are used to
create the requested environment variables.

Some of these variables are special-cased; instead of using them for
**setenv**(3), they control flags in the `AndroidSystem` class

  * `mono.aot`: The `$(AndroidAotMode)` value; which *kind* of AOT
    mono should support at runtime.
  * `mono.llvm`: The `$(EnableLLVM)` value; whether LLVM-generated
    AOT files should be used.
  * `__XA_DSO_IN_APK`: Support in-place reading of `.so` files;
    See commit 95ca102.

[env-support]: xamarin/monodroid@dbd73ec


~~ Mono Handling Improvements ~~

During process startup startup, *every* assembly within the `.apk`
would be loaded so that a `Java.Interop.__TypeRegistrations` type
could be probed, and if it existed, the
`__TypeRegistrations.RegisterPackages()` method would be invoked.

This was done in order to [better support "type mappings"][typemaps]
between Java names and C# names (and vice versa).

However, this support hasn't been required since the introduction
of the [`typemap.jm` and `typemap.mj` files][typemap-files]; we just
hadn't gotten around to removing the
`__TypeRegistrations.RegisterPackages()` invocation.

*Not* loading every assembly on startup allows assemblies to be
loaded on-demand, and improves startup times.

[typemaps]: #1443 (comment)
[typemap-files]: xamarin/monodroid@e69b76e


~~ Startup Time Summary ~~

Startup times for `tests/Xamarin.Forms-Performance-Integration`,
average of 50 iterations of (uninstall app, install app, launch app):

  * Debug configuration:

        Old: 1s 440ms
        New: 1s 100ms

  * Release configuration:

        Old: 650ms
        New: 270ms
  • Loading branch information
@grendello @jonpryor
grendello authored and jonpryor committed Jan 4, 2019
1 parent a422d5d commit b90d3ab
Show file tree
Hide file tree
Showing 35 changed files with 1,053 additions and 678 deletions.
2 changes: 1 addition & 1 deletion build-tools/scripts/cmake-common.props
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,6 @@
<Project ToolsVersion="4.0" xmlns="http://schemas.microsoft.com/developer/msbuild/2003">
<PropertyGroup>
<_CmakeCommonFlags>-GNinja -DCMAKE_MAKE_PROGRAM=$(NinjaPath)</_CmakeCommonFlags>
<_CmakeAndroidFlags>$(_CmakeCommonFlags) -DANDROID_TOOLCHAIN=clang -DANDROID_NATIVE_API_LEVEL=$(AndroidNdkApiLevel) -DANDROID_PLATFORM=android-$(AndroidNdkApiLevel) -DCMAKE_TOOLCHAIN_FILE=$(AndroidNdkDirectory)\build\cmake\android.toolchain.cmake -DANDROID_NDK=$(AndroidNdkDirectory)</_CmakeAndroidFlags>
<_CmakeAndroidFlags>$(_CmakeCommonFlags) -DANDROID_STL="system" -DANDROID_CPP_FEATURES="" -DANDROID_TOOLCHAIN=clang -DANDROID_NATIVE_API_LEVEL=$(AndroidNdkApiLevel) -DANDROID_PLATFORM=android-$(AndroidNdkApiLevel) -DCMAKE_TOOLCHAIN_FILE=$(AndroidNdkDirectory)\build\cmake\android.toolchain.cmake -DANDROID_NDK=$(AndroidNdkDirectory)</_CmakeAndroidFlags>
</PropertyGroup>
</Project>
41 changes: 20 additions & 21 deletions src/Mono.Android/Android.Runtime/JNIEnv.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -152,15 +152,16 @@ internal static unsafe void Initialize (JnienvInitializeArgs* args)
{
Logger.Categories = (LogCategories) args->logCategories;

var __start = new DateTime ();
Stopwatch stopper = null;
long elapsed, totalElapsed = 0;
if (Logger.LogTiming) {
__start = DateTime.UtcNow;
Logger.Log (LogLevel.Info,
"monodroid-timing",
"JNIEnv.Initialize start: " + (__start - new DateTime (1970, 1, 1)).TotalMilliseconds);
Logger.Log (LogLevel.Info,
"monodroid-timing",
"JNIEnv.Initialize: Logger JIT/etc. time: " + (DateTime.UtcNow - new DateTime (1970, 1, 1)).TotalMilliseconds + " [elapsed: " + (DateTime.UtcNow - __start).TotalMilliseconds + " ms]");
stopper = new Stopwatch ();
stopper.Start ();
Logger.Log (LogLevel.Info, "monodroid-timing", "JNIEnv.Initialize start");
elapsed = stopper.ElapsedMilliseconds;
totalElapsed += elapsed;
Logger.Log (LogLevel.Info, "monodroid-timing", $"JNIEnv.Initialize: Logger JIT/etc. time: elapsed {elapsed} ms]");
stopper.Restart ();
}

gref_gc_threshold = args->grefGcThreshold;
Expand Down Expand Up @@ -195,16 +196,14 @@ internal static unsafe void Initialize (JnienvInitializeArgs* args)
#endif // JAVA_INTEROP

if (Logger.LogTiming) {
var __end = DateTime.UtcNow;
Logger.Log (LogLevel.Info,
"monodroid-timing",
"JNIEnv.Initialize: time: " + (__end - new DateTime (1970, 1, 1)).TotalMilliseconds + " [elapsed: " + (__end - __start).TotalMilliseconds + " ms]");
__start = DateTime.UtcNow;
elapsed = stopper.ElapsedMilliseconds;
totalElapsed += elapsed;
Logger.Log (LogLevel.Info, "monodroid-timing", $"JNIEnv.Initialize: managed runtime init time: elapsed {elapsed} ms]");
stopper.Restart ();
var _ = Java.Interop.TypeManager.jniToManaged;
__end = DateTime.UtcNow;
Logger.Log (LogLevel.Info,
"monodroid-timing",
"JNIEnv.Initialize: TypeManager init time: " + (__end - new DateTime (1970, 1, 1)).TotalMilliseconds + " [elapsed: " + (__end - __start).TotalMilliseconds + " ms]");
elapsed = stopper.ElapsedMilliseconds;
totalElapsed += elapsed;
Logger.Log (LogLevel.Info, "monodroid-timing", $"JNIEnv.Initialize: TypeManager init time: elapsed {elapsed} ms]");
}

AllocObjectSupported = androidSdkVersion > 10;
Expand Down Expand Up @@ -238,10 +237,10 @@ internal static unsafe void Initialize (JnienvInitializeArgs* args)
Java.Lang.Thread.DefaultUncaughtExceptionHandler = defaultUncaughtExceptionHandler;
}

if (Logger.LogTiming)
Logger.Log (LogLevel.Info,
"monodroid-timing",
"JNIEnv.Initialize end: " + (DateTime.UtcNow - new DateTime (1970, 1, 1)).TotalMilliseconds);
if (Logger.LogTiming) {
totalElapsed += stopper.ElapsedMilliseconds;
Logger.Log (LogLevel.Info, "monodroid-timing", $"JNIEnv.Initialize end: elapsed {totalElapsed} ms");
}
}

internal static void Exit ()
Expand Down
7 changes: 6 additions & 1 deletion src/Mono.Android/java/mono/android/Runtime.java
View file
Original file line number Diff line number Diff line change
@@ -1,12 +1,17 @@
package mono.android;

public class Runtime {
static java.lang.Class java_lang_Class = java.lang.Class.class;;
static java.lang.Class java_lang_System = java.lang.System.class;
static java.lang.Class java_util_TimeZone = java.util.TimeZone.class;
static java.lang.Class mono_android_IGCUserPeer = mono.android.IGCUserPeer.class;
static java.lang.Class mono_android_GCUserPeer = mono.android.GCUserPeer.class;

private Runtime ()
{
}

public static native void init (String lang, String[] runtimeApks, String runtimeDataDir, String[] appDirs, ClassLoader loader, String[] externalStorageDirs, String[] assemblies, String packageName);
public static native void init (String lang, String[] runtimeApks, String runtimeDataDir, String[] appDirs, ClassLoader loader, String[] externalStorageDirs, String[] assemblies, String packageName, int apiLevel, String[] environmentVariables);
public static native void register (String managedType, java.lang.Class nativeClass, String methods);
public static native void notifyTimeZoneChanged ();
public static native int createNewContext (String[] runtimeApks, String[] assemblies, ClassLoader loader);
Expand Down
4 changes: 3 additions & 1 deletion src/Xamarin.Android.Build.Tasks/Resources/MonoPackageManager.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,9 @@ public static void LoadApplication (Context context, ApplicationInfo runtimePack
externalLegacyDir
},
MonoPackageManager_Resources.Assemblies,
context.getPackageName ());
context.getPackageName (),
android.os.Build.VERSION.SDK_INT,
mono.android.app.XamarinAndroidEnvironmentVariables.Variables);

mono.android.app.ApplicationRegistration.registerApplications ();

Expand Down
9 changes: 9 additions & 0 deletions src/Xamarin.Android.Build.Tasks/Resources/XamarinAndroidEnvironmentVariables.java
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,9 @@
package mono.android.app;

public class XamarinAndroidEnvironmentVariables
{
// Variables are specified the in "name", "value" pairs
public static final String[] Variables = new String[] {
//@ENVVARS@
};
}
101 changes: 0 additions & 101 deletions src/Xamarin.Android.Build.Tasks/Tasks/BuildApk.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -45,8 +45,6 @@ public class BuildApk : Task

public ITaskItem[] BundleNativeLibraries { get; set; }

public ITaskItem[] Environments { get; set; }

public ITaskItem[] TypeMappings { get; set; }

[Required]
Expand Down Expand Up @@ -74,37 +72,24 @@ public class BuildApk : Task

public bool PreferNativeLibrariesWithDebugSymbols { get; set; }

public string AndroidAotMode { get; set; }

public string AndroidSequencePointsMode { get; set; }

public bool EnableLLVM { get; set; }

public bool EnableSGenConcurrent { get; set; }

public string AndroidEmbedProfilers { get; set; }
public string HttpClientHandlerType { get; set; }
public string TlsProvider { get; set; }
public string UncompressedFileExtensions { get; set; }


static readonly string MSBuildXamarinAndroidDirectory = Path.GetDirectoryName (typeof (BuildApk).Assembly.Location);

[Output]
public ITaskItem[] OutputFiles { get; set; }

[Output]
public string BuildId { get; set; }

bool _Debug {
get {
return string.Equals (Debug, "true", StringComparison.OrdinalIgnoreCase);
}
}

SequencePointsMode sequencePointsMode = SequencePointsMode.None;

Guid buildId = Guid.NewGuid ();

public ITaskItem[] LibraryProjectJars { get; set; }
string [] uncompressedFileExtensions;
Expand All @@ -125,7 +110,6 @@ void ExecuteWithAbi (string supportedAbis, string apkInputPath, string apkOutput
if (EmbedAssemblies && !BundleAssemblies)
AddAssemblies (apk);

AddEnvironment (apk);
AddRuntimeLibraries (apk, supportedAbis);
apk.Flush();
AddNativeLibraries (files, supportedAbis);
Expand Down Expand Up @@ -206,11 +190,9 @@ public override bool Execute ()
Log.LogDebugMessage (" Debug: {0}", Debug ?? "no");
Log.LogDebugMessage (" PreferNativeLibrariesWithDebugSymbols: {0}", PreferNativeLibrariesWithDebugSymbols);
Log.LogDebugMessage (" EmbedAssemblies: {0}", EmbedAssemblies);
Log.LogDebugMessage (" AndroidAotMode: {0}", AndroidAotMode);
Log.LogDebugMessage (" AndroidSequencePointsMode: {0}", AndroidSequencePointsMode);
Log.LogDebugMessage (" CreatePackagePerAbi: {0}", CreatePackagePerAbi);
Log.LogDebugMessage (" UncompressedFileExtensions: {0}", UncompressedFileExtensions);
Log.LogDebugTaskItems (" Environments:", Environments);
Log.LogDebugTaskItems (" ResolvedUserAssemblies:", ResolvedUserAssemblies);
Log.LogDebugTaskItems (" ResolvedFrameworkAssemblies:", ResolvedFrameworkAssemblies);
Log.LogDebugTaskItems (" NativeLibraries:", NativeLibraries);
Expand All @@ -220,8 +202,6 @@ public override bool Execute ()
Log.LogDebugTaskItems (" JavaLibraries:", JavaLibraries);
Log.LogDebugTaskItems (" LibraryProjectJars:", LibraryProjectJars);
Log.LogDebugTaskItems (" AdditionalNativeLibraryReferences:", AdditionalNativeLibraryReferences);
Log.LogDebugTaskItems (" HttpClientHandlerType:", HttpClientHandlerType);
Log.LogDebugMessage (" TlsProvider: {0}", TlsProvider);

Aot.TryGetSequencePointsMode (AndroidSequencePointsMode, out sequencePointsMode);

Expand All @@ -246,10 +226,6 @@ public override bool Execute ()
}
}

BuildId = buildId.ToString ();

Log.LogDebugMessage (" [Output] BuildId: {0}", BuildId);

OutputFiles = outputFiles.Select (a => new TaskItem (a)).ToArray ();

Log.LogDebugTaskItems (" [Output] OutputFiles :", OutputFiles);
Expand Down Expand Up @@ -349,83 +325,6 @@ static string GetTargetDirectory (string path)
return "assemblies";
}

void AddEnvironment (ZipArchiveEx apk)
{
var environment = new StringWriter () {
NewLine = "\n",
};

if (EnableLLVM) {
environment.WriteLine ("mono.llvm=true");
}

AotMode aotMode;
if (AndroidAotMode != null && Aot.GetAndroidAotMode(AndroidAotMode, out aotMode)) {
environment.WriteLine ("mono.aot={0}", aotMode.ToString().ToLowerInvariant());
}

const string defaultLogLevel = "MONO_LOG_LEVEL=info";
const string defaultMonoDebug = "MONO_DEBUG=gen-compact-seq-points";
const string defaultHttpMessageHandler = "XA_HTTP_CLIENT_HANDLER_TYPE=System.Net.Http.HttpClientHandler, System.Net.Http";
const string defaultTlsProvider = "XA_TLS_PROVIDER=btls";
string xamarinBuildId = string.Format ("XAMARIN_BUILD_ID={0}", buildId);

bool haveLogLevel = false;
bool haveMonoDebug = false;
bool havebuildId = false;
bool haveHttpMessageHandler = false;
bool haveTlsProvider = false;
bool haveMonoGCParams = false;

foreach (ITaskItem env in Environments ?? new TaskItem[0]) {
environment.WriteLine ("## Source File: {0}", env.ItemSpec);
foreach (string line in File.ReadLines (env.ItemSpec)) {
var lineToWrite = line;
if (lineToWrite.StartsWith ("MONO_LOG_LEVEL=", StringComparison.Ordinal))
haveLogLevel = true;
if (lineToWrite.StartsWith ("MONO_GC_PARAMS=", StringComparison.Ordinal))
haveMonoGCParams = true;
if (lineToWrite.StartsWith ("XAMARIN_BUILD_ID=", StringComparison.Ordinal))
havebuildId = true;
if (lineToWrite.StartsWith ("MONO_DEBUG=", StringComparison.Ordinal)) {
haveMonoDebug = true;
if (sequencePointsMode != SequencePointsMode.None && !lineToWrite.Contains ("gen-compact-seq-points"))
lineToWrite = line + ",gen-compact-seq-points";
}
if (lineToWrite.StartsWith ("XA_HTTP_CLIENT_HANDLER_TYPE=", StringComparison.Ordinal))
haveHttpMessageHandler = true;
if (lineToWrite.StartsWith ("XA_TLS_PROVIDER=", StringComparison.Ordinal))
haveTlsProvider = true;
environment.WriteLine (lineToWrite);
}
}

if (_Debug && !haveLogLevel) {
environment.WriteLine (defaultLogLevel);
}

if (sequencePointsMode != SequencePointsMode.None && !haveMonoDebug) {
environment.WriteLine (defaultMonoDebug);
}

if (!havebuildId)
environment.WriteLine (xamarinBuildId);

if (!haveHttpMessageHandler)
environment.WriteLine (HttpClientHandlerType == null ? defaultHttpMessageHandler : $"XA_HTTP_CLIENT_HANDLER_TYPE={HttpClientHandlerType.Trim ()}");
if (!haveTlsProvider)
environment.WriteLine (TlsProvider == null ? defaultTlsProvider : $"XA_TLS_PROVIDER={TlsProvider.Trim ()}");
if (!haveMonoGCParams) {
if (EnableSGenConcurrent)
environment.WriteLine ("MONO_GC_PARAMS=major=marksweep-conc");
else
environment.WriteLine ("MONO_GC_PARAMS=major=marksweep");
}

apk.Archive.AddEntry ("environment", environment.ToString (),
new UTF8Encoding (encoderShouldEmitUTF8Identifier:false));
}

class LibInfo
{
public string Path;
Expand Down
Loading

1 comment on commit b90d3ab

@jstawski
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hello, has this commit made it to a release? We are seeing that our Android app is indeed loading all references at startup, which we believe is contributing to the slow start times of our app.

Please sign in to comment.