[android] .NET 8 performance regression in System.Reflection.MethodInfo/ConstructorInfo.Invoke() #83893

jonathanpeppers · 2023-03-24T17:31:15Z

Description

.NET 7 added a code path that uses System.Reflection.Emit for ConstructorInfo/MethodInfo for coreclr. This makes sense for throughput, scenarios like ASP.NET.

On mobile, however, we are more concerned about a fast startup. I found that we may have accidentally introduced this behavior for Mono (or at least Android) in .NET 8:

#72717

In .NET MAUI apps that heavily use things like data-binding, Microsoft.Extensions.DI, etc. It appears that this change noticeably slows down startup.

In my benchmark, I setup a "first run" / "cold start" scenario:

Version	Method	Mean	Allocated
.NET 7	ContructorInfo_Invoke	530.5 us	552 B
.NET 7	MethodInfo_Invoke	457.6 us	128 B
.NET 8	ContructorInfo_Invoke	607.7 us	4.09 KB
.NET 8	MethodInfo_Invoke	1,202.1 us	2.38 KB

/cc @steveisok

Reproduction Steps

Try my instructions here: https://github.com/jonathanpeppers/BenchmarkDotNet-Android/tree/System.Reflection

Expected behavior

We probably shouldn't hit the S.R.E codepath by default on Android.

We should have a flag to opt into it? It may be useful for some apps, although it appears to slow down startup in the apps I've tried.

Actual behavior

We hit the S.R.E codepath by default on Android.

Regression?

Yes, it appears .NET 7 does not have this issue.

Known Workarounds

Use .NET 7?

Configuration

.NET SDK: 8.0.100-preview.3.23170.5

Other information

No response

ghost · 2023-03-24T17:35:02Z

Tagging subscribers to 'arch-android': @steveisok, @akoeplinger
See info in area-owners.md if you want to be subscribed.

Issue Details

Description

.NET 7 added a code path that uses System.Reflection.Emit for ConstructorInfo/MethodInfo for coreclr. This makes sense for throughput, scenarios like ASP.NET.

On mobile, however, we are more concerned about a fast startup. I found that we may have accidentally introduced this behavior for Mono (or at least Android) in .NET 8:

#72717

In .NET MAUI apps that heavily use things like data-binding, Microsoft.Extensions.DI, etc. It appears that this change noticeably slows down startup.

In my benchmark, I setup a "first run" / "cold start" scenario:

Version	Method	Mean	Allocated
.NET 7	ContructorInfo_Invoke	530.5 us	552 B
.NET 7	MethodInfo_Invoke	457.6 us	128 B
.NET 8	ContructorInfo_Invoke	607.7 us	4.09 KB
.NET 8	MethodInfo_Invoke	1,202.1 us	2.38 KB

/cc @steveisok

Reproduction Steps

Try my instructions here: https://github.com/jonathanpeppers/BenchmarkDotNet-Android/tree/System.Reflection

Expected behavior

We probably shouldn't hit the S.R.E codepath by default on Android.

We should have a flag to opt into it? It may be useful for some apps, although it appears to slow down startup in the apps I've tried.

Actual behavior

We hit the S.R.E codepath by default on Android.

Regression?

Yes, it appears .NET 7 does not have this issue.

Known Workarounds

Use .NET 7?

Configuration

.NET SDK: 8.0.100-preview.3.23170.5

Other information

No response

Author:	jonathanpeppers
Assignees:	-
Labels:	`os-android`, `area-CoreLib-mono`
Milestone:	-

steveisok · 2023-03-24T17:36:23Z

@lambdageek what are your thoughts?

lambdageek · 2023-03-24T17:40:44Z

Maybe we can have a heuristic: if SRE classes like DynamicMethod are already loaded and initialized for some other purpose, use the SRE invoke path. otherwise go via the runtime.

We could add a static flag somewhere in the invoke code and toggle it from the static cctor for ILGenerator, for example.

steveisok · 2023-03-24T17:46:46Z

@SamMonoRT can someone from your team take a look and maybe prototype @lambdageek's idea?

jonathanpeppers · 2023-03-24T18:19:23Z

Should these somehow use the existing feature switches?

System.Runtime.CompilerServices.RuntimeFeature.IsDynamicCodeSupported
System.Runtime.CompilerServices.RuntimeFeature.IsDynamicCodeCompiled

https://github.com/dotnet/runtime/blob/main/docs/workflow/trimming/feature-switches.md

In theory, an MSBuild property would let users be able to opt into IsDynamicCodeCompiled (or some new feature switch).

SamMonoRT · 2023-03-24T18:19:57Z

@ivanpovazan - can take a look sometime next week.

lambdageek · 2023-03-24T18:29:14Z

Should these somehow use the existing feature switches?

System.Runtime.CompilerServices.RuntimeFeature.IsDynamicCodeSupported

System.Runtime.CompilerServices.RuntimeFeature.IsDynamicCodeCompiled

These switches are used already. They disable the SRE codepath when we're on the interpreter or on fullaot, etc.

Don't we want the SRE path in the steady state on platforms where we have a JIT?

I assume the issue on Android is just that at startup we don't want to bother with loading SRE support for one-off callbacks. But presumably once the app is running, we want the SRE codepath?

I'm assuming the SRE codepath is faster in the steady state (I think we have microbenchmarks to back that up, right @SamMonoRT ?)

In theory, an MSBuild property would let users be able to opt into IsDynamicCodeCompiled (or some new feature switch).

I don't think this should be a user-visible switch - we should figure out how Android could have fast startup and fast steady state.

Or if SRE is never faster for mono, then we should disable the SRE Invoke machinery. Messing with IsDynamicCodeXYZ feature switches will have much wider impact (for example in Linq; in trimming; etc)

jkotas · 2023-03-24T18:34:21Z

The SRE optimization is not used for one-off callbacks. It should be only used if the method is called at least twice. Maybe you want to bump this threshold to be more than 2 on Mono?

ivanpovazan · 2023-03-30T11:40:39Z

The SRE optimization is not used for one-off callbacks. It should be only used if the method is called at least twice. Maybe you want to bump this threshold to be more than 2 on Mono?

I am currently working on experimental setup to profile how many times each method is called during startup, to determine if it possible to use a different strategy with SRE optimization. Will provide an update once I gather some data.

ivanpovazan · 2023-04-03T15:55:53Z

I might be doing something wrong, but I was not able to reproduce the effect of the startup performance regression by using the provided benchmarks.
In my setup I am using the following configuration

.NET7 SDK - 7.0.100 release
.NET8 SDK - 8.0.100-preview.3.23170.5 preview
Device: OnePlus 7 Pro
OS: Android 11

Observation

By running the benchmarks multiple times and recording the outputs, the results showed oscillations between the runs.
The following table compares average execution times of 10 benchmark runs (without the warm-up -p:ColdStart=true) between .NET7 and .NET8.
The benchmarks were executed with:

.NET7: dotnet build ./DotNetRunner/DotNetRunner.csproj -c Release -t:Benchmark -p:ColdStart=true
.NET8: /Users/ivan/dotnet-test/8.0.100-preview.3.23170.5/dotnet build ./DotNetRunner/DotNetRunner.csproj -c Release -t:Benchmark -p:ColdStart=true -p:Targeting=net8.0

Runs	.NET7		.NET8
#	ContructorInfo_Invoke	MethodInfo_Invoke	ContructorInfo_Invoke	MethodInfo_Invoke
1	444,70	510,9	452,8	564,8
2	504,10	494,1	464,6	824,2
3	524,90	666,7	494,5	554,2
4	530,70	1299,3	458,1	528,7
5	519,40	534,5	459,7	577,6
6	465,50	1244,3	478,7	1280,1
7	522,80	893,1	568,4	978,6
8	459,20	1215,6	504,6	327,1
9	612,7	1864,4	495,3	426,3
10	461,6	511,7	554,3	1179,2
Average	504,56 us	923,46 us	493,10 us	724,08 us

The full benchmark logs are available here:

From the provided results I was not able to confirm that the regression was introduced.

@jonathanpeppers Am I maybe missing some configuration parameter or using a different build version?

Further analysis

Even though I was not able to reproduce the regression I have experimented with how to collect stats on dynamically invoked constructors and methods. On an experimental branch, I have extended System.Reflection library to log all the methods that get dynamically invoked into a static dictionary. This dictionary can be later dumped once an application launches to provide more details about the startup behaviour. Hopefully, this would give us more data to decide whether a different strategy has to be applied with SRE optimization when targeting mobile devices.

The experimental branch: main...ivanpovazan:runtime:wip-method-invoke-stats
To be built with: ./build.sh mono+libs -os android -arch arm64
Example of how the map can be dumped: ivanpovazan/samples@d77ecc6
The dumped output can be retrieved from adb logcat via: adb logcat | grep "<<<---"
Which shows how many times which method was dynamically invoked.
The output looks something like this for a dotnet new maui app: https://gist.github.com/ivanpovazan/a16cc83726a505f84169978b3163850e

jonathanpeppers · 2023-04-10T16:39:26Z

@ivanpovazan let's discuss in Teams when you have a chance.

We first found new SRE calls in .NET 8 here:

dotnet/android@30e9487#diff-dd3a2df0f1e5bd8fc55250ba096d4ee06782c3c9544dfdffbb30885ef5ea29caR2333

I updated the .aotprofile for "Hello World" Android apps -- and noticed it odd these calls appeared.

Maybe the issue isn't MethodInfo/ConstructorInfo, but something else? Would Delegate.CreateDelegate() hit the SRE code path?

ivanpovazan · 2023-04-19T12:53:14Z

I have measured the MAUI android template app startup time with and without hitting the SRE path as described here.
The results bellow do not seem to show a noticeable regression.

Results

Dotnet version: 8.0.100-preview.3.23178.7
App: dotnet new maui
Device: GM1913
Android version: 11

#	SRE (ms)	noSRE (ms)
1	824	842
2	812	794
3	847	806
4	767	815
5	803	794
6	797	758
7	766	768
8	762	778
9	767	779
10	856	814
AVG:	800,1	794,8

NOTE: There is a regression of 5,3 ms when comparing the average execution times, but at least to me, this does not seem to have a significant impact to the overall results considering the oscillations in the individual runs.

I am providing the repro steps bellow and the script I was using to measure this.

Repro

Prerequistes

Download/install dotnetSDK version: 8.0.100-preview.3.23178.7 (further refered as <path-to-dotnet8>)
Install MAUI workload

Create a new template app

<path-to-dotnet8> new maui -n "StartupTest"

Download the script for running and profiling the startup time n times

curl https://gist.githubusercontent.com/ivanpovazan/8eba37fa4300d48ce6223bacd1af6630/raw/e8a0cc4e9566fcd7e1eeb1a7f109b3bad265cddf/run_n_times.sh -o StartupTest/run_n_times.sh; cd StartupTest

Run the script to collect results with the SRE optimisation (default behaviour):

bash ./run_n_times.sh 10 <path-to-dotnet8>

Run the script to collect results without the SRE optimisation:

bash ./run_n_times.sh 10 <path-to-dotnet8> noSRE

After the runs are completed, the measurements are available in:

run_SRE.log - default behaviour
run_noSRE.log - SRE optimisation turned off

Additional info

The provided script is using the Switch.System.Reflection.ForceInterpretedInvoke variable to test turning SRE optimisation off. This can be achieved by setting the mentioned property in runtimeconfig.template.json to true (this is what the script is doing when noSRE is passed as a 3rd parameter)
To prove that the above works here are the two speedscope traces with and without setting the Switch.System.Reflection.ForceInterpretedInvoke:
- SRE-trace.json
- noSRE-trace.json
By looking for the CreateInvokeDelegate method name in the traces, we can see that the SRE-trace.json includes hitting this code path, while the noSRE-trace.json doesn't, which proves the correctness of the runs

@jonathanpeppers could you give it a go on your end and check the results, as from what I measured it does not seem that SRE optimisation caused a regression.

jonathanpeppers · 2023-04-19T13:18:57Z

The ~5.3ms (maybe regression) might scale a lot worse when you go from a project template to a customer's real app. It appears that Java/C# interop can easily cause ConstructorInfo/MethodInfo to be invoked multiple times.

Can Switch.System.Reflection.ForceInterpretedInvoke be turned on from MSBuild?

ivanpovazan · 2023-04-19T14:51:18Z

Can Switch.System.Reflection.ForceInterpretedInvoke be turned on from MSBuild?

Yes, it is possible to add this to the project file for example:

	<ItemGroup Condition="'$(noSRE)' == 'true'">
  		<RuntimeHostConfigurationOption Include="Switch.System.Reflection.ForceInterpretedInvoke" Value="true" />
	</ItemGroup>

and the pass -p:noSRE=true when building the app as desired.

…nterpretedInvoke Fixes: dotnet/runtime#83893 In .NET 8, `System.Reflection.ConstructorInfo/MethodInfo.Invoke()` will call `System.Reflection.Emit` when called more than once. This impacts startup in mobile applications, so it may not be a desired feature. Unfortunately, this appears to happen quite easily in Android apps, some examples: * https://gist.github.com/ivanpovazan/2563ea9d2fea320e6425cfcc58da3ee5 * https://gist.github.com/ivanpovazan/d2546d4abad17900d4366cc29e1689b2 The types of situations this happens: * You call a Java method from C# that returns a `Java.Lang.Object` subclass. * You override a Java method in C#, that has a `Java.Lang.Object` parameter. To solve this problem, we can set: <ItemGroup> <RuntimeHostConfigurationOption Include="Switch.System.Reflection.ForceInterpretedInvoke" Value="$(_SystemReflectionForceInterpretedInvoke)" Trim="true" /> </ItemGroup> And we can set `$(_SystemReflectionForceInterpretedInvoke)` to test out the setting in various apps. I also updated the `.aotprofile` to verify that all `System.Reflection.Emit` code paths disappear from `dotnet new android` applications.

…nterpretedInvoke Fixes: dotnet/runtime#83893 In .NET 8, `System.Reflection.ConstructorInfo/MethodInfo.Invoke()` will call `System.Reflection.Emit` when called more than once. This impacts startup in mobile applications, so it may not be a desired feature. Unfortunately, this appears to happen quite easily in Android apps, some examples: * https://gist.github.com/ivanpovazan/2563ea9d2fea320e6425cfcc58da3ee5 * https://gist.github.com/ivanpovazan/d2546d4abad17900d4366cc29e1689b2 The types of situations this happens: * You call a Java method from C# that returns a `Java.Lang.Object` subclass. * You override a Java method in C#, that has a `Java.Lang.Object` parameter. To solve this problem, we can set: <ItemGroup> <RuntimeHostConfigurationOption Include="Switch.System.Reflection.ForceInterpretedInvoke" Value="$(_SystemReflectionForceInterpretedInvoke)" Trim="true" /> </ItemGroup> And we can set `$(_SystemReflectionForceInterpretedInvoke)` to test out the setting in various apps. I added a test to verify the "private" switch is actually set. I also updated the `.aotprofile` to verify that all `System.Reflection.Emit` code paths disappear from `dotnet new android` applications.

dotnet-issue-labeler bot added the needs-area-label An area label is needed to ensure this gets routed to the appropriate area owners label Mar 24, 2023

ghost added the untriaged New issue has not been triaged by the area owner label Mar 24, 2023

jonathanpeppers added the area-CoreLib-mono label Mar 24, 2023

steveisok added os-android and removed needs-area-label An area label is needed to ensure this gets routed to the appropriate area owners untriaged New issue has not been triaged by the area owner labels Mar 24, 2023

steveisok added this to the 8.0.0 milestone Mar 24, 2023

steveisok added the tenet-performance Performance related issue label Mar 24, 2023

ivanpovazan self-assigned this Mar 27, 2023

jonathanpeppers mentioned this issue Apr 19, 2023

[Xamarin.Android.Build.Tasks] disable Switch.System.Reflection.ForceInterpretedInvoke dotnet/android#7972

Merged

lambdageek mentioned this issue Apr 19, 2023

Use emit-based invoke for all of WASM including DI #85065

Merged

jonathanpeppers closed this as completed in jonathanpeppers/xamarin-android@5687506 Apr 24, 2023

ghost locked as resolved and limited conversation to collaborators May 25, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[android] .NET 8 performance regression in System.Reflection.MethodInfo/ConstructorInfo.Invoke() #83893

[android] .NET 8 performance regression in System.Reflection.MethodInfo/ConstructorInfo.Invoke() #83893

jonathanpeppers commented Mar 24, 2023

ghost commented Mar 24, 2023

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

steveisok commented Mar 24, 2023

lambdageek commented Mar 24, 2023 •

edited

Loading

steveisok commented Mar 24, 2023

jonathanpeppers commented Mar 24, 2023 •

edited

Loading

SamMonoRT commented Mar 24, 2023

lambdageek commented Mar 24, 2023

jkotas commented Mar 24, 2023

ivanpovazan commented Mar 30, 2023

ivanpovazan commented Apr 3, 2023

jonathanpeppers commented Apr 10, 2023

ivanpovazan commented Apr 19, 2023

jonathanpeppers commented Apr 19, 2023

ivanpovazan commented Apr 19, 2023

[android] .NET 8 performance regression in System.Reflection.MethodInfo/ConstructorInfo.Invoke() #83893

[android] .NET 8 performance regression in System.Reflection.MethodInfo/ConstructorInfo.Invoke() #83893

Comments

jonathanpeppers commented Mar 24, 2023

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

ghost commented Mar 24, 2023

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

steveisok commented Mar 24, 2023

lambdageek commented Mar 24, 2023 • edited Loading

steveisok commented Mar 24, 2023

jonathanpeppers commented Mar 24, 2023 • edited Loading

SamMonoRT commented Mar 24, 2023

lambdageek commented Mar 24, 2023

jkotas commented Mar 24, 2023

ivanpovazan commented Mar 30, 2023

ivanpovazan commented Apr 3, 2023

Observation

Further analysis

jonathanpeppers commented Apr 10, 2023

ivanpovazan commented Apr 19, 2023

Results

Repro

Prerequistes

Additional info

jonathanpeppers commented Apr 19, 2023

ivanpovazan commented Apr 19, 2023

lambdageek commented Mar 24, 2023 •

edited

Loading

jonathanpeppers commented Mar 24, 2023 •

edited

Loading