Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

JNIEnv.Initialize optimization #3729

Merged
merged 1 commit into from
Oct 10, 2019

Conversation

grendello
Copy link
Contributor

@grendello grendello commented Oct 2, 2019

JNIEnv.Initialize is part of the Xamarin.Android runtime startup sequence and
it contributes a sizable chunk of time to it. Some code executed during startup
sequence wasn't as optimized as it could be and this commit aims to pick all the
low-hanging fruit in that area:

  • Don't use the Logger class.
    This removes one class instantiation which wasn't absolutely necessary.
    Calls to Logger are replaced with calls to a new native function
    monodroid_log
  • Use native functions for timing.
    It won't affect the user's code (unless it runs with timing enabled, of
    course) but will allow our timing to be more precise and have less impact on
    code performance. Implemented with two new native functions
    monodroid_timing_start and monodroid_timing_stop
  • Remove calls to Environment.GetEnvironmentVariable
    The calls took a non-trivial amount of time (around 4ms each) and were
    replaced by putting the environment variables in libxamarin-app.so, in the
    application environment configuration block.
  • Do not fully initialize UncaughtExceptionHandler during init
    The handler's initialization is quite heavy while the handler itself is
    going to be used only when there's an unhandled exception thrown. Delay full
    initialization to the point in time when the handler is actually needed.
  • Avoid parsing of the PackageNamingPolicy enum values on runtime.
    Instead, the desired value is placed in the application's environment
    configuration block and simply cast from int to the enum.
  • Initialize Logger lazily.
    The logging category is requested by Logger lazily instead of being set
    from JNIEnv.Initialize. This allows the Logger class not to be
    instantiated during startup.
  • Avoid static initialization of the Java.Interop.Runtime class.
  • Avoid heavy static initialization of the Java.Interop.TypeManager class.
    This is done by initializing the type lookup dictionaries lazily, via
    another "proxy" class.
  • Make Java class name lookup faster.
    This is done by moving the lookup (and processing) to native code and
    p/invoking the new monodroid_TypeManager_get_java_class_name function.

Other changes:

  • Remove dead code from JNIEnv
    The JAVA_INTEROP symbol is always "defined" now, remove code used when it
    was not defined.
  • Introduce fast performance measurement for managed code.
    The timing code used by the native runtime is now exposed to the managed
    land, thus allowing us fast and accurate (to the nanosecond level) timing
    measurement.

Impact of the above changes on performance is summarized in the table below.

Device name: Pixel 3 XL
Device architecture: arm64-v8a
Number of test runs: 10

Runtime init Displayed Notes
this commit 187.907 828.90 preload enabled; 32-bit build
master 218.804 852.70
this commit 154.718 803.50 preload disabled; 32-bit build
master 185.240 827.40
this commit 174.211 754.50 preload enabled; 64-bit build
master 201.779 783.20
this commit 144.158 741.80 preload disabled; 64-bit build
master 173.322 759.40

@grendello grendello added do-not-merge PR should not be merged. full-mono-integration-build For PRs; run a full build (~6-10h for mono bumps), not the faster PR subset (~2h for mono bumps) Area: App Runtime Issues in `libmonodroid.so`. labels Oct 2, 2019
@grendello grendello self-assigned this Oct 2, 2019
@grendello grendello force-pushed the init-sequence-rework branch 2 times, most recently from 9358e3d to 6303191 Compare October 2, 2019 20:04
@@ -29,7 +29,9 @@ struct JnienvInitializeArgs {
public int localRefsAreIndirect;
public int grefGcThreshold;
public IntPtr grefIGCUserPeer;
public int isRunningOnDesktop;
Copy link
Member

Choose a reason for hiding this comment

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

I wonder if this could possibly break the Designer... Just a rando fear.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Designer tests did fail in this build, although it doesn't appear to be related (but might be?):

1) Failed : Xamarin.AndroidDesigner.Tests.Moyeu.CanLoadLayoutsInProject
  /var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/ADT-0/RT-Moyeu-1/Moyeu/Resources/layout/InfoPaneLayout.axml
  Expected: no item equal to "MockView"
  But was:  < "MockView" >
  First non-matching item at index [0]:  "MockView"
  at Xamarin.AndroidDesigner.Tests.RegressionTest.CanLoadLayoutsInProject () [0x00000] in <055988ff4d7c4b6f95c58bd23af8596c>:0 
  at System.Runtime.CompilerServices.AsyncMethodBuilderCore+MoveNextRunner.InvokeMoveNext (System.Object stateMachine) [0x00000] in <208e3d8480c243b7804b22b6a5eb72fc>:0

Copy link
Contributor Author

Choose a reason for hiding this comment

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

And they failed again in the same way after reverting this change, so this is not the cause

public int isRunningOnDesktop;
public byte isRunningOnDesktop;
public byte brokenExceptionTransitions;
public PackageNamingPolicy packageNamingPolicy;
Copy link
Member

Choose a reason for hiding this comment

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

As this struct is shared with C++/libmonodroid.so, I think this field should properly be an int, and then we cast in JNIEnv.Initialize(). The cast should be optimized away to ~nothing.

}

[DllImport ("__Internal")]
extern static void monodroid_log (LogLevel level, LogCategories category, string message);
Copy link
Member

Choose a reason for hiding this comment

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

At this point in time, it's "weird" to have this and the following methods declared when they're not actually used from C#. I imagine this will change in the future, but for now, this is weird.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

The other two are used, this one was used instead of passing a string to monodroid_timing_{start,end} but it will still come useful IMO (I think it might be a good idea to replace Logger.Log calls with this in the code we ship)

@@ -193,60 +177,34 @@ internal static unsafe void Initialize (JnienvInitializeArgs* args)

Mono.SystemDependencyProvider.Initialize ();

#if JAVA_INTEROP
// TODO: env, javaVm, grefLoader, Loader_loadClass should all be obtained by AndroidRuntime constructor with p/invokes
Copy link
Member

Choose a reason for hiding this comment

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

Related: P/Invokes may be "fast", but let's not do one P/Invoke per value. Bundle them! Minimize P/Invoke transitions!

Copy link
Contributor Author

Choose a reason for hiding this comment

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

That's the plan :)

Error,
Fatal,
Silent
Unknown = 0x00,
Copy link
Member

Choose a reason for hiding this comment

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

Why the "noise"?

For that matter, why hex for values which aren't flags/bitfields?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

The "noise" is to keep it explicit since the enum is "shared" with C++ - it's better to have the values stated clearly IMO. And why hex? I like the way hex numbers look, no other reason :)

@@ -21,26 +21,6 @@ public static partial class TypeManager {

internal static IntPtr id_Class_getName;

static TypeManager ()
Copy link
Member

Choose a reason for hiding this comment

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

Relatedly, in this file, we want to remove the allocations on lines 19 & 20, as that will require JIT'ing Dictionary instantiations which we'd rather avoid if at all possible, especially on-device, when we shouldn't really need those fields at all. (Not needing them will require additional changes, but they shouldn't be needed...)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yep, that's the next step here.

uint monoAOTMode = 0;
string androidPackageName = null;
var environmentVariables = new Dictionary<string, string> (StringComparer.Ordinal);
var systemProperties = new Dictionary<string, string> (StringComparer.Ordinal);

if (!Enum.TryParse (PackageNamingPolicy, out PackageNamingPolicy pnp)) {
pnp = PackageNamingPolicyEnum.LowercaseHash;
Copy link
Member

Choose a reason for hiding this comment

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

As of 88a1d6c, this should probably default to PackageNamingPolicy.LowercaseCrc64.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

it was a copy-and-paste, oops. I'll change the default in the original location too, then (the default should be really specified somewhere else...)

@@ -120,11 +120,11 @@ Copyright (C) 2011-2012 Xamarin. All rights reserved.
<!--
*******************************************
Extensibility hook that allows VS to
provide extra behavior without modifying
provide extra behavior without modifying
Copy link
Member

Choose a reason for hiding this comment

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

Is there any way to avoid all of these whitespace changes?

Sure, in theory, they improve the code base. But it's making this PR really noisy.

Copy link
Contributor Author

@grendello grendello Oct 3, 2019

Choose a reason for hiding this comment

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

The *.targets files (and some .cs too - like JNIEnv.cs) are often badly formatted and my editor removes trailing whitespace (as I want it to). I'll hand-edit the changes.

@grendello grendello force-pushed the init-sequence-rework branch 5 times, most recently from d181b4c to 26110b8 Compare October 7, 2019 19:17

static Logger ()
{
lock (initLock) {
Copy link
Member

Choose a reason for hiding this comment

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

Is this strictly necessary? Static constructors will only ever be executed once, so this seems redundant.

@grendello grendello force-pushed the init-sequence-rework branch 3 times, most recently from 1dce36d to a6055e1 Compare October 8, 2019 12:04
@grendello grendello removed the do-not-merge PR should not be merged. label Oct 8, 2019
@grendello grendello changed the title [WIP] JNIEnv.Initialize optimization JNIEnv.Initialize optimization Oct 8, 2019
@grendello grendello added the do-not-merge PR should not be merged. label Oct 8, 2019
@grendello grendello force-pushed the init-sequence-rework branch 5 times, most recently from 4e670f6 to 2825067 Compare October 9, 2019 16:43
@grendello grendello removed the do-not-merge PR should not be merged. label Oct 9, 2019
@@ -58,18 +60,26 @@ internal static class Logger {
System.Console.WriteLine ("[{0}] {1}: {2}", level, appname, line);
}
}

[DllImport ("__Internal")]
Copy link
Member

Choose a reason for hiding this comment

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

Shouldn't this specify CallingConvention=CallingConvention.Cdecl?

static Logger ()
{
logCategories = (LogCategories) monodroid_get_log_categories ();
}
}

internal enum LogLevel {
Copy link
Member

Choose a reason for hiding this comment

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

If these need to be kept in-sync with libmonodroid, we should add an appropriate comment here, as was done with LogCategories.

extern static IntPtr monodroid_TypeManager_get_java_class_name (IntPtr klass);

[DllImport ("__Internal", CallingConvention = CallingConvention.Cdecl)]
extern static void monodroid_free (IntPtr ptr);
Copy link
Member

Choose a reason for hiding this comment

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

AndroidEnvironment already has this P/Invoke declaration. We should make the AndroidEnvironment method internal, or move it to some shared location, instead of having two separate monodroid_free() declarations.

timing->release_sequence (sequence);
}

MONO_API __stdcall const char*
Copy link
Member

Choose a reason for hiding this comment

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

I believe that this line should not have __stdcall anymore.

Comment on lines 910 to 931
MonoImage *image = mono_assembly_get_image (assm);
MonoImage *image = mono_assembly_get_image (assm);
Copy link
Member

Choose a reason for hiding this comment

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

The whitespace changes here are weird. Two spaces before (?

@@ -1759,6 +1759,29 @@ MonodroidRuntime::Java_mono_android_Runtime_destroyContexts (JNIEnv *env, jclass
log_info (LOG_DEFAULT, "All domain cleaned up");
}

const char*
Copy link
Member

Choose a reason for hiding this comment

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

This should have a char* return type, not const char*, because the returned string should be free'd by the caller.

{
timing_diff diff (period);

log_debug_nocheck (LOG_TIMING, MESSAGE_FORMAT, message == nullptr ? "" : message, diff.sec, diff.ms, diff.ns);
Copy link
Member

Choose a reason for hiding this comment

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

Why the _nocheck variant here?

For that matter, why's it exist? I can't see any mention of Timing::debug in this PR. I do see Timing::info...

Copy link
Contributor Author

Choose a reason for hiding this comment

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

_nocheck is used because we always hide timing stuff behind a check if the timing category is enabled, so there's no point in re-checking it. And why it exists? Because I used it in test code and forgot to remove.

{
timing_diff diff (period);

log_info_nocheck (LOG_TIMING, MESSAGE_FORMAT, message == nullptr ? "" : message, diff.sec, diff.ms, diff.ns);
Copy link
Member

Choose a reason for hiding this comment

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

~Same question as with Timing::debug(): why the _nocheck variant? Currently all callers appear to check the log level before calling Timing::info before hand, but will that remain the case in the future?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yes, this is the intention - that it will remain so in the future.

return;

std::lock_guard<std::mutex> lock (sequence_lock);
if (sequence->dynamic) {
Copy link
Member

Choose a reason for hiding this comment

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

Shouldn't this be done before lock is constructed? We don't need the mutex when sequence->dynamic is true.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

If you do it before the lock you introduce a race condition

`JNIEnv.Initialize` is part of the Xamarin.Android runtime startup sequence and
it contributes a sizable chunk of time to it. Some code executed during startup
sequence wasn't as optimized as it could be and this commit aims to pick all the
low-hanging fruit in that area:

  * Don't use the `Logger` class.
    This removes one class instantiation which wasn't absolutely necessary.
    Calls to `Logger` are replaced with calls to a new native function
    `monodroid_log`
  * Use native functions for timing.
    It won't affect the user's code (unless it runs with timing enabled, of
    course) but will allow our timing to be more precise and have less impact on
    code performance. Implemented with two new native functions
    `monodroid_timing_start` and `monodroid_timing_stop`
  * Remove calls to `Environment.GetEnvironmentVariable`
    The calls took a non-trivial amount of time (around 4ms each) and were
    replaced by putting the environment variables in `libxamarin-app.so`, in the
    application environment configuration block.
  * Do not fully initialize `UncaughtExceptionHandler` during init
    The handler's initialization is quite heavy while the handler itself is
    going to be used only when there's an unhandled exception thrown. Delay full
    initialization to the point in time when the handler is actually needed.
  * Avoid parsing of the `PackageNamingPolicy` enum values on runtime.
    Instead, the desired value is placed in the application's environment
    configuration block and simply cast from `int` to the enum.
  * Initialize `Logger` lazily.
    The logging category is requested by `Logger` lazily instead of being set
    from `JNIEnv.Initialize`. This allows the `Logger` class not to be
    instantiated during startup.
  * Avoid static initialization of the `Java.Interop.Runtime` class.
  * Avoid heavy static initialization of the `Java.Interop.TypeManager` class.
    This is done by initializing the type lookup dictionaries lazily, via
    another "proxy" class.
  * Make Java class name lookup faster.
    This is done by moving the lookup (and processing) to native code and
    p/invoking the new `monodroid_TypeManager_get_java_class_name` function.

Other changes:

  * Remove dead code from `JNIEnv`
    The `JAVA_INTEROP` symbol is always "defined" now, remove code used when it
    was not defined.
  * Introduce fast performance measurement for managed code.
    The timing code used by the native runtime is now exposed to the managed
    land, thus allowing us fast and accurate (to the nanosecond level) timing
    measurement.

Impact of the above changes on performance is summarized in the table below.

Device name: **Pixel 3 XL**
Device architecture: **arm64-v8a**
Number of test runs: **10**

|                 | **Runtime init** | **Displayed** | **Notes**                      |
|-----------------|------------------|---------------|--------------------------------|
| **this commit** | 187.907          | 828.90        |  preload enabled; 32-bit build |
| **master**      | 218.804          | 852.70        |                                |
| **this commit** | 154.718          | 803.50        | preload disabled; 32-bit build |
| **master**      | 185.240          | 827.40        |                                |
| **this commit** | 174.211          | 754.50        |  preload enabled; 64-bit build |
| **master**      | 201.779          | 783.20        |                                |
| **this commit** | 144.158          | 741.80        | preload disabled; 64-bit build |
| **master**      | 173.322          | 759.40        |                                |
@jonpryor jonpryor merged commit af02a65 into dotnet:master Oct 10, 2019
@grendello grendello deleted the init-sequence-rework branch October 10, 2019 21:09
@github-actions github-actions bot locked and limited conversation to collaborators Jan 24, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Area: App Runtime Issues in `libmonodroid.so`. full-mono-integration-build For PRs; run a full build (~6-10h for mono bumps), not the faster PR subset (~2h for mono bumps)
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants