diff --git a/samples/HelloWorld/HelloWorld/HelloWorld.DotNet.csproj b/samples/HelloWorld/HelloWorld/HelloWorld.DotNet.csproj index 996e0ddb2da..6e3b96a7e47 100644 --- a/samples/HelloWorld/HelloWorld/HelloWorld.DotNet.csproj +++ b/samples/HelloWorld/HelloWorld/HelloWorld.DotNet.csproj @@ -7,6 +7,10 @@ + + + + diff --git a/samples/HelloWorld/HelloWorld/MainActivity.cs b/samples/HelloWorld/HelloWorld/MainActivity.cs index 43d1421ef7f..e736aac0616 100644 --- a/samples/HelloWorld/HelloWorld/MainActivity.cs +++ b/samples/HelloWorld/HelloWorld/MainActivity.cs @@ -1,6 +1,13 @@ -using Android.App; +using System; +using Android.App; using Android.Widget; using Android.OS; +using OpenTelemetry; +using OpenTelemetry.Exporter; +using OpenTelemetry.Metrics; +using OpenTelemetry.Resources; +using OpenTelemetry.Trace; +using System.Reflection; namespace HelloWorld { @@ -11,10 +18,19 @@ namespace HelloWorld Name = "example.MainActivity")] public class MainActivity : Activity { + const string TypemapInstrumentationName = "Microsoft.Android.Runtime.TrimmableTypeMap"; + const string OtlpHeadersExtra = "OTEL_EXPORTER_OTLP_HEADERS"; + + static readonly object TelemetryLock = new object (); + static TracerProvider tracerProvider; + static MeterProvider meterProvider; + static bool telemetryConfigured; + int count = 1; protected override void OnCreate (Bundle savedInstanceState) { + ConfigureTelemetry (Intent?.GetStringExtra (OtlpHeadersExtra)); base.OnCreate (savedInstanceState); // Set our view from the "main" layout resource @@ -28,7 +44,61 @@ protected override void OnCreate (Bundle savedInstanceState) button.Text = string.Format ("{0} clicks!", count++); }; } - } -} + static void ConfigureTelemetry (string otlpHeaders) + { + lock (TelemetryLock) { + if (telemetryConfigured) + return; + + var endpoint = System.Environment.GetEnvironmentVariable ("OTEL_EXPORTER_OTLP_ENDPOINT"); + if (string.IsNullOrEmpty (endpoint)) + endpoint = "http://127.0.0.1:4318"; + + var resourceBuilder = ResourceBuilder.CreateDefault () + .AddService ("helloworld-android"); + + tracerProvider = Sdk.CreateTracerProviderBuilder () + .SetResourceBuilder (resourceBuilder) + .AddSource (TypemapInstrumentationName) + .AddOtlpExporter (options => { + options.Protocol = OtlpExportProtocol.HttpProtobuf; + options.Endpoint = GetOtlpEndpoint (endpoint, "v1/traces"); + if (!string.IsNullOrEmpty (otlpHeaders)) + options.Headers = otlpHeaders; + }) + .Build (); + + meterProvider = Sdk.CreateMeterProviderBuilder () + .SetResourceBuilder (resourceBuilder) + .AddMeter (TypemapInstrumentationName) + .AddOtlpExporter (options => { + options.Protocol = OtlpExportProtocol.HttpProtobuf; + options.Endpoint = GetOtlpEndpoint (endpoint, "v1/metrics"); + if (!string.IsNullOrEmpty (otlpHeaders)) + options.Headers = otlpHeaders; + }) + .Build (); + telemetryConfigured = true; + FlushBufferedTypemapEvents (); + } + } + + static void FlushBufferedTypemapEvents () + { + var telemetryType = typeof (Android.Runtime.JNIEnv).Assembly.GetType ("Microsoft.Android.Runtime.TrimmableTypeMapTelemetry"); + var flushMethod = telemetryType?.GetMethod ("FlushBufferedEvents", BindingFlags.Static | BindingFlags.NonPublic); + flushMethod?.Invoke (null, null); + } + + static Uri GetOtlpEndpoint (string endpoint, string signalPath) + { + var builder = new UriBuilder (endpoint); + var path = builder.Path; + if (string.IsNullOrEmpty (path) || path == "/") + builder.Path = signalPath; + return builder.Uri; + } + } +} diff --git a/samples/HelloWorld/HelloWorld/Properties/AndroidManifest.xml b/samples/HelloWorld/HelloWorld/Properties/AndroidManifest.xml index 4c3650a714e..7930b5b7e8f 100644 --- a/samples/HelloWorld/HelloWorld/Properties/AndroidManifest.xml +++ b/samples/HelloWorld/HelloWorld/Properties/AndroidManifest.xml @@ -1,5 +1,6 @@  - + + diff --git a/samples/TypemapOtelAspire/README.md b/samples/TypemapOtelAspire/README.md new file mode 100644 index 00000000000..f0eb66ade09 --- /dev/null +++ b/samples/TypemapOtelAspire/README.md @@ -0,0 +1,114 @@ +# Typemap OTEL Aspire sample + +This AppHost launches `samples/HelloWorld` as a Release/CoreCLR/trimmable typemap Android app and sends typemap telemetry to the Aspire dashboard over OTLP/HTTP. + +## What it measures + +The runtime emits spans and metrics from the `Microsoft.Android.Runtime.TrimmableTypeMap` instrumentation source. + +Important startup spans: + +- `jnienv.initialize`: managed `JNIEnvInit.Initialize` startup boundary. +- `typemap.data.initialize`: generated trimmable typemap data load. +- `typemap.initialize`: runtime typemap initialization. +- `typemap.register_native_methods`: native registration setup. +- `typemap.buffered_events`: flush marker for operations buffered before the app configured OpenTelemetry. + +Lookup and steady-state spans: + +- `typemap.llvm.lookup.jni_name` +- `typemap.llvm.lookup.jni_name.uncached` +- `typemap.llvm.peer.create` +- `typemap.llvm.proxy.create` +- `typemap.llvm.activation` +- `typemap.lookup.jni_name` +- `typemap.lookup.jni_name.uncached` +- `typemap.lookup.managed_type` +- `typemap.lookup.managed_type.uncached` +- `typemap.lookup.java_object` +- `typemap.lookup.java_interfaces` +- `typemap.lookup.java_interfaces.uncached` +- `typemap.type_manager.get_simple_reference` +- `typemap.type_manager.get_simple_reference.uncached` +- `typemap.type_manager.get_invoker_type` +- `typemap.peer.create` +- `typemap.on_register_natives` + +Each span also has a `duration.us` attribute for microsecond precision, because the Aspire CLI and dashboard duration fields are rounded to milliseconds. + +## Prerequisites + +- Build the local Android SDK first: + + ```bash + make all + ``` + +- Connect exactly one Android device, or set `ANDROID_SERIAL`. +- Trust Aspire HTTPS dev certificates if needed: + + ```bash + dotnet dev-certs https --trust + aspire certs trust + ``` + +## Run + +Run from this directory: + +```bash +export PATH="$HOME/.dotnet/tools:$PATH" +ASPIRE_ALLOW_UNSECURED_TRANSPORT=true \ +ASPIRE_DASHBOARD_OTLP_HTTP_ENDPOINT_URL=http://localhost:4318 \ +aspire run --detach --non-interactive +``` + +By default the AppHost launches Release/CoreCLR/trimmable. Override the type map to compare against LLVM-IR: + +```bash +ASPIRE_ALLOW_UNSECURED_TRANSPORT=true \ +ASPIRE_DASHBOARD_OTLP_HTTP_ENDPOINT_URL=http://localhost:4318 \ +HELLOWORLD_ANDROID_TYPEMAP=llvm-ir \ +aspire run --detach --non-interactive +``` + +The `helloworld-android` resource builds, installs, and starts the sample app. It also: + +- runs `adb reverse tcp:4318 tcp:`; +- uninstalls any existing `com.xamarin.android.helloworld` app to avoid signature mismatch errors; +- discovers the dashboard-generated OTLP API key and passes it to the Activity as `OTEL_EXPORTER_OTLP_HEADERS`; +- keeps the Aspire resource alive while the Android app process is running. + +Restart just the Android app resource after code changes: + +```bash +aspire resource helloworld-android restart +``` + +## Inspect telemetry + +The dashboard URL is printed by `aspire run`. You can also use the CLI: + +```bash +aspire describe +aspire otel traces --format Json -n 100 +aspire otel spans --format Json -n 500 +aspire logs helloworld-android --tail 200 +``` + +If the browser dashboard shows `An unhandled error has occurred` and the CLI still returns telemetry, clear site data/cache for the dashboard URL or open it in a fresh private window. One observed stale-browser failure was: + +```text +Microsoft.JSInterop.JSException: The value 'Blazor._internal.Virtualize.setAnchorMode' is not a function. +``` + +## Notes + +- `am start -W` only reports integer millisecond `TotalTime` and `WaitTime`. +- Use span attribute `duration.us` for microsecond duration data. +- Startup spans emitted before app-level OpenTelemetry setup are buffered and replayed as spans once the sample configures its provider. +- Do not leave Android diagnostics startup suspend enabled when using this sample normally: + + ```bash + adb shell setprop debug.mono.profile none + ``` diff --git a/samples/TypemapOtelAspire/apphost.cs b/samples/TypemapOtelAspire/apphost.cs new file mode 100644 index 00000000000..74f9b0a751b --- /dev/null +++ b/samples/TypemapOtelAspire/apphost.cs @@ -0,0 +1,20 @@ +#:sdk Aspire.AppHost.Sdk@13.3.5 + +var builder = DistributedApplication.CreateBuilder(args); + +var otlpHttpEndpoint = Environment.GetEnvironmentVariable("ASPIRE_DASHBOARD_OTLP_HTTP_ENDPOINT_URL") ?? "http://localhost:4318"; +var configuration = Environment.GetEnvironmentVariable("HELLOWORLD_ANDROID_CONFIGURATION") ?? "Release"; +var runtime = Environment.GetEnvironmentVariable("HELLOWORLD_ANDROID_RUNTIME") ?? "CoreCLR"; +var typemap = Environment.GetEnvironmentVariable("HELLOWORLD_ANDROID_TYPEMAP") ?? "trimmable"; + +builder.AddExecutable( + "helloworld-android", + "bash", + "../..", + "samples/TypemapOtelAspire/run-helloworld-android.sh") + .WithEnvironment("OTEL_EXPORTER_OTLP_ENDPOINT", otlpHttpEndpoint) + .WithEnvironment("HELLOWORLD_ANDROID_CONFIGURATION", configuration) + .WithEnvironment("HELLOWORLD_ANDROID_RUNTIME", runtime) + .WithEnvironment("HELLOWORLD_ANDROID_TYPEMAP", typemap); + +builder.Build().Run(); diff --git a/samples/TypemapOtelAspire/aspire.config.json b/samples/TypemapOtelAspire/aspire.config.json new file mode 100644 index 00000000000..acffea3e2b3 --- /dev/null +++ b/samples/TypemapOtelAspire/aspire.config.json @@ -0,0 +1,20 @@ +{ + "appHost": { + "path": "apphost.cs" + }, + "profiles": { + "http": { + "applicationUrl": "http://localhost:15269", + "environmentVariables": { + "ASPNETCORE_ENVIRONMENT": "Development", + "DOTNET_ENVIRONMENT": "Development", + "ASPNETCORE_URLS": "http://localhost:18888", + "ASPIRE_DASHBOARD_OTLP_ENDPOINT_URL": "http://localhost:19001", + "ASPIRE_DASHBOARD_OTLP_HTTP_ENDPOINT_URL": "http://localhost:19002", + "ASPIRE_RESOURCE_SERVICE_ENDPOINT_URL": "http://localhost:20156", + "ASPIRE_ALLOW_UNSECURED_TRANSPORT": "true", + "ASPIRE_DASHBOARD_UNSECURED_ALLOW_ANONYMOUS": "true" + } + } + } +} diff --git a/samples/TypemapOtelAspire/run-helloworld-android.sh b/samples/TypemapOtelAspire/run-helloworld-android.sh new file mode 100755 index 00000000000..858499149d1 --- /dev/null +++ b/samples/TypemapOtelAspire/run-helloworld-android.sh @@ -0,0 +1,139 @@ +#!/usr/bin/env bash +set -euo pipefail + +repo_root="$(cd "$(dirname "${BASH_SOURCE[0]}")/../.." && pwd)" +cd "$repo_root" + +project="${HELLOWORLD_ANDROID_PROJECT:-samples/HelloWorld/HelloWorld/HelloWorld.DotNet.csproj}" +configuration="${HELLOWORLD_ANDROID_CONFIGURATION:-Release}" +runtime="${HELLOWORLD_ANDROID_RUNTIME:-CoreCLR}" +typemap="${HELLOWORLD_ANDROID_TYPEMAP:-trimmable}" +package_name="${HELLOWORLD_ANDROID_PACKAGE:-com.xamarin.android.helloworld}" +activity_name="${HELLOWORLD_ANDROID_ACTIVITY:-example.MainActivity}" +otlp_endpoint="${OTEL_EXPORTER_OTLP_ENDPOINT:-${ASPIRE_DASHBOARD_OTLP_HTTP_ENDPOINT_URL:-http://localhost:4318}}" +otlp_headers="${OTEL_EXPORTER_OTLP_HEADERS:-}" +keep_resource_alive="${HELLOWORLD_ANDROID_KEEP_RESOURCE_ALIVE:-true}" + +adb_args=() +if [[ -n "${ANDROID_SERIAL:-}" ]]; then + adb_args=(-s "$ANDROID_SERIAL") +fi + +adb_cmd() { + if [[ ${#adb_args[@]} -gt 0 ]]; then + adb "${adb_args[@]}" "$@" + else + adb "$@" + fi +} + +timestamp() { + date "+%H:%M:%S" +} + +log() { + echo "[$(timestamp)] $*" +} + +host_port="4318" +if [[ "$otlp_endpoint" =~ ^https?://[^:/]+:([0-9]+) ]]; then + host_port="${BASH_REMATCH[1]}" +fi + +if [[ -z "$otlp_headers" ]] && command -v pgrep >/dev/null 2>&1; then + while read -r pid; do + if [[ -z "$pid" ]]; then + continue + fi + dashboard_environment="$(ps eww -p "$pid" | tr ' ' '\n')" + if ! grep -q '^DASHBOARD__FRONTEND__PUBLICURL=' <<< "$dashboard_environment"; then + continue + fi + otlp_api_key="$(sed -n 's/^DASHBOARD__OTLP__PRIMARYAPIKEY=//p' <<< "$dashboard_environment" | head -1)" + if [[ -n "$otlp_api_key" ]]; then + otlp_headers="x-otlp-api-key=$otlp_api_key" + break + fi + done < <(pgrep -x dotnet || true) +fi + +case "$runtime" in + MonoVM|mono|monovm) + use_mono_runtime="true" + ;; + CoreCLR|coreclr) + use_mono_runtime="false" + ;; + *) + echo "Unknown HELLOWORLD_ANDROID_RUNTIME '$runtime'. Expected CoreCLR or MonoVM." >&2 + exit 1 + ;; +esac + +if ! command -v adb >/dev/null 2>&1; then + echo "adb was not found on PATH." >&2 + exit 1 +fi + +if [[ ! -x "$repo_root/dotnet-local.sh" ]]; then + echo "dotnet-local.sh was not found or is not executable in $repo_root." >&2 + exit 1 +fi + +device_count="$(adb_cmd devices | awk 'NR > 1 && $2 == "device" { count++ } END { print count + 0 }')" +if [[ "$device_count" -eq 0 ]]; then + echo "No Android device is connected. Start an emulator or connect a device, then rerun Aspire." >&2 + exit 1 +fi +if [[ "$device_count" -gt 1 && -z "${ANDROID_SERIAL:-}" ]]; then + echo "Multiple Android devices are connected. Set ANDROID_SERIAL before rerunning Aspire." >&2 + exit 1 +fi + +log "Using OTLP endpoint from Aspire: $otlp_endpoint" +if [[ -n "$otlp_headers" ]]; then + log "Using OTLP headers from Aspire dashboard." +fi +log "Forwarding Android tcp:4318 to host tcp:$host_port" +adb_cmd reverse "tcp:4318" "tcp:$host_port" + +log "Removing any existing $package_name install" +adb_cmd uninstall "$package_name" >/dev/null 2>&1 || true + +log "Building and installing $project" +log "Configuration=$configuration Runtime=$runtime TypeMap=$typemap" +"$repo_root/dotnet-local.sh" build "$project" \ + -c "$configuration" \ + -t:Install \ + -p:UseMonoRuntime="$use_mono_runtime" \ + -p:_AndroidTypeMapImplementation="$typemap" \ + -p:AndroidPackageFormats=apk + +log "Starting $package_name/$activity_name" +adb_cmd shell am force-stop "$package_name" >/dev/null +adb_cmd logcat -c || true +start_args=(-W -n "$package_name/$activity_name") +if [[ -n "$otlp_headers" ]]; then + start_args+=(--es OTEL_EXPORTER_OTLP_HEADERS "$otlp_headers") +fi +adb_cmd shell am start "${start_args[@]}" + +for _ in {1..10}; do + if adb_cmd shell pidof "$package_name" >/dev/null 2>&1; then + log "HelloWorld is running. Typemap telemetry should appear in the Aspire dashboard under service helloworld-android." + if [[ "$keep_resource_alive" == "true" ]]; then + log "Keeping the Aspire resource alive while the Android process is running." + while adb_cmd shell pidof "$package_name" >/dev/null 2>&1; do + sleep 2 + done + log "HelloWorld process exited." + exit 1 + fi + exit 0 + fi + sleep 1 +done + +echo "HelloWorld did not stay running after launch." >&2 +adb_cmd logcat -b crash -d -t 80 >&2 || true +exit 1 diff --git a/src/Mono.Android/Android.Runtime/JNIEnvInit.cs b/src/Mono.Android/Android.Runtime/JNIEnvInit.cs index 3d339d16eb7..fc4468ca2c0 100644 --- a/src/Mono.Android/Android.Runtime/JNIEnvInit.cs +++ b/src/Mono.Android/Android.Runtime/JNIEnvInit.cs @@ -125,6 +125,7 @@ internal static void InitializeNativeAotRuntime (JniRuntime runtime, JnienvIniti [UnmanagedCallersOnly] internal static unsafe void Initialize (JnienvInitializeArgs* args) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("jnienv.initialize"); if (RuntimeFeature.IsNativeAotRuntime) { throw new NotSupportedException ("JNIEnvInit.Initialize cannot be used to initialize NativeAOT."); } @@ -232,6 +233,7 @@ static void RegisterTrimmableTypeMapNativeMethodsIfNeeded () [MethodImpl (MethodImplOptions.NoInlining)] static void InitializeTrimmableTypeMapData () { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.data.initialize"); TypeMapLoader.Initialize (); } diff --git a/src/Mono.Android/Java.Interop/JavaPeerProxy.cs b/src/Mono.Android/Java.Interop/JavaPeerProxy.cs index fec5337d347..ff27d38967b 100644 --- a/src/Mono.Android/Java.Interop/JavaPeerProxy.cs +++ b/src/Mono.Android/Java.Interop/JavaPeerProxy.cs @@ -3,6 +3,7 @@ using System; using System.Diagnostics.CodeAnalysis; using Android.Runtime; +using Microsoft.Android.Runtime; namespace Java.Interop { @@ -94,23 +95,39 @@ protected JavaPeerProxy ( /// public static bool ShouldSkipActivation (IntPtr jniSelf) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.activation.should_skip"); var reference = new JniObjectReference (jniSelf, JniObjectReferenceType.Invalid); var peer = JniEnvironment.Runtime.ValueManager.PeekPeer (reference); if (peer != null && !IsActivationPeer (peer)) { + if (operation.IsActive) { + operation.SetTag ("skip", true); + operation.SetTag ("reason", "existing-peer"); + } return true; } - return JniEnvironment.WithinNewObjectScope; + var skip = JniEnvironment.WithinNewObjectScope; + if (operation.IsActive) { + operation.SetTag ("skip", skip); + operation.SetTag ("reason", skip ? "new-object-scope" : "activate"); + } + return skip; } public static IJavaPeerable? GetActivationPeer (IntPtr jniSelf) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.activation.get_peer"); var reference = new JniObjectReference (jniSelf, JniObjectReferenceType.Invalid); var peer = JniEnvironment.Runtime.ValueManager.PeekPeer (reference); - return peer != null && IsActivationPeer (peer) ? peer : null; + var activationPeer = peer != null && IsActivationPeer (peer) ? peer : null; + if (operation.IsActive) { + operation.SetTag ("found", activationPeer is not null); + } + return activationPeer; } public static void SetActivationPeerReference (IJavaPeerable peer, IntPtr jniSelf) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.activation.set_peer_reference"); var reference = new JniObjectReference (jniSelf, JniObjectReferenceType.Invalid); peer.SetPeerReference (reference); peer.SetJniIdentityHashCode (JniEnvironment.References.GetIdentityHashCode (reference)); @@ -118,12 +135,19 @@ public static void SetActivationPeerReference (IJavaPeerable peer, IntPtr jniSel public static void MarkActivationPeerReplaceable (IntPtr jniSelf) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.activation.mark_replaceable"); var reference = new JniObjectReference (jniSelf, JniObjectReferenceType.Invalid); var peer = JniEnvironment.Runtime.ValueManager.PeekPeer (reference); if (peer == null) { + if (operation.IsActive) { + operation.SetTag ("found", false); + } return; } + if (operation.IsActive) { + operation.SetTag ("found", true); + } peer.SetJniManagedPeerState (peer.JniManagedPeerState | JniManagedPeerStates.Replaceable); } diff --git a/src/Mono.Android/Java.Interop/TypeManager.cs b/src/Mono.Android/Java.Interop/TypeManager.cs index cc0b22936bd..f6ab7d49362 100644 --- a/src/Mono.Android/Java.Interop/TypeManager.cs +++ b/src/Mono.Android/Java.Interop/TypeManager.cs @@ -119,12 +119,24 @@ internal static bool ActivationEnabled { [UnconditionalSuppressMessage ("Trimming", "IL2057", Justification = "Type.GetType() can never statically know the string value from parameter 'signature'.")] static Type[] GetParameterTypes (string? signature) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.get_parameter_types"); if (String.IsNullOrEmpty (signature)) return Array.Empty (); string[] typenames = signature!.Split (':'); + if (operation.IsActive) { + operation.SetTag ("parameter.count", typenames.Length); + } Type[] result = new Type [typenames.Length]; - for (int i = 0; i < typenames.Length; i++) + for (int i = 0; i < typenames.Length; i++) { + using var resolveOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.resolve_parameter_type"); + if (resolveOperation.IsActive) { + resolveOperation.SetTag ("managed.type.name", typenames [i]); + } result [i] = Type.GetType (typenames [i], throwOnError:true)!; + if (resolveOperation.IsActive) { + resolveOperation.SetTag ("managed.type", result [i].FullName); + } + } return result; } @@ -132,38 +144,91 @@ static Type[] GetParameterTypes (string? signature) [UnconditionalSuppressMessage ("Trimming", "IL2057", Justification = "Type.GetType() can never statically know the string value from parameter 'typename_ptr'.")] static void n_Activate (IntPtr jnienv, IntPtr jclass, IntPtr typename_ptr, IntPtr signature_ptr, IntPtr jobject, IntPtr parameters_ptr) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation"); if (!global::Java.Interop.JniEnvironment.BeginMarshalMethod (jnienv, out var __envp, out var __r)) return; try { - var o = Java.Lang.Object.PeekObject (jobject); - var ex = o as IJavaPeerable; + IJavaPeerable? o; + using (var peekOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.peek_object")) { + o = Java.Lang.Object.PeekObject (jobject); + if (peekOperation.IsActive) { + peekOperation.SetTag ("has.peer", o is not null); + peekOperation.SetTag ("peer.type", o?.GetType ().FullName); + } + } + var ex = o; if (ex != null) { var state = ex.JniManagedPeerState; - if (!state.HasFlag (JniManagedPeerStates.Activatable) && !state.HasFlag (JniManagedPeerStates.Replaceable)) + if (operation.IsActive) { + operation.SetTag ("peer.state", state.ToString ()); + } + if (!state.HasFlag (JniManagedPeerStates.Activatable) && !state.HasFlag (JniManagedPeerStates.Replaceable)) { + if (operation.IsActive) { + operation.SetTag ("skip", true); + operation.SetTag ("reason", "existing-peer-not-activatable"); + } return; + } } if (!ActivationEnabled) { if (Logger.LogGlobalRef) { Logger.Log (LogLevel.Info, "monodroid-gref", FormattableString.Invariant ($"warning: Skipping managed constructor invocation for handle 0x{jobject:x} (key_handle 0x{JNIEnv.IdentityHash (jobject):x}). Please use JNIEnv.StartCreateInstance() + JNIEnv.FinishCreateInstance() instead of JNIEnv.NewObject() and/or JNIEnv.CreateInstance().")); } + if (operation.IsActive) { + operation.SetTag ("skip", true); + operation.SetTag ("reason", "activation-disabled"); + } return; } - Type type = Type.GetType (JNIEnv.GetString (typename_ptr, JniHandleOwnership.DoNotTransfer)!, throwOnError:true)!; + Type type; + using (var typeOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.resolve_type")) { + var typeName = JNIEnv.GetString (typename_ptr, JniHandleOwnership.DoNotTransfer); + if (typeOperation.IsActive) { + typeOperation.SetTag ("managed.type.name", typeName); + } + type = Type.GetType (typeName!, throwOnError:true)!; + if (typeOperation.IsActive) { + typeOperation.SetTag ("managed.type", type.FullName); + } + } + if (operation.IsActive) { + operation.SetTag ("managed.type", type.FullName); + } if (type.IsGenericTypeDefinition) { throw new NotSupportedException ( "Constructing instances of generic types from Java is not supported, as the type parameters cannot be determined.", CreateJavaLocationException ()); } Type[] ptypes = GetParameterTypes (JNIEnv.GetString (signature_ptr, JniHandleOwnership.DoNotTransfer)); - var parms = JNIEnv.GetObjectArray (parameters_ptr, ptypes); - var cinfo = type.GetConstructor (ptypes); + object? []? parms; + using (var parametersOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.get_object_array")) { + if (parametersOperation.IsActive) { + parametersOperation.SetTag ("parameter.count", ptypes.Length); + } + parms = JNIEnv.GetObjectArray (parameters_ptr, ptypes); + } + ConstructorInfo? cinfo; + using (var constructorOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.constructor_lookup")) { + if (constructorOperation.IsActive) { + constructorOperation.SetTag ("managed.type", type.FullName); + constructorOperation.SetTag ("parameter.count", ptypes.Length); + } + cinfo = type.GetConstructor (ptypes); + if (constructorOperation.IsActive) { + constructorOperation.SetTag ("found", cinfo is not null); + } + } if (cinfo == null) { throw CreateMissingConstructorException (type, ptypes); } if (o != null) { + using var invokeOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.invoke_existing_peer"); + if (invokeOperation.IsActive) { + invokeOperation.SetTag ("managed.type", type.FullName); + } cinfo.Invoke (o, parms); return; } @@ -180,13 +245,30 @@ static void n_Activate (IntPtr jnienv, IntPtr jclass, IntPtr typename_ptr, IntPt [UnconditionalSuppressMessage ("Trimming", "IL2072", Justification = "RuntimeHelpers.GetUninitializedObject() does not statically know the return value from ConstructorInfo.DeclaringType.")] internal static void Activate (IntPtr jobject, ConstructorInfo cinfo, object? []? parms) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.activate_uninitialized"); + if (operation.IsActive) { + operation.SetTag ("managed.type", cinfo.DeclaringType?.FullName); + operation.SetTag ("parameter.count", parms?.Length ?? 0); + } try { var newobj = RuntimeHelpers.GetUninitializedObject (cinfo.DeclaringType!); + if (operation.IsActive) { + operation.SetTag ("created.uninitialized", true); + } if (newobj is IJavaPeerable peer) { - peer.SetPeerReference (new JniObjectReference (jobject)); + using (var peerOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.set_peer_reference")) { + if (peerOperation.IsActive) { + peerOperation.SetTag ("managed.type", cinfo.DeclaringType?.FullName); + } + peer.SetPeerReference (new JniObjectReference (jobject)); + } } else { throw new InvalidOperationException ($"Unsupported type: '{newobj}'"); } + using var invokeOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.activation.invoke_constructor"); + if (invokeOperation.IsActive) { + invokeOperation.SetTag ("managed.type", cinfo.DeclaringType?.FullName); + } cinfo.Invoke (newobj, parms); } catch (Exception e) { var m = FormattableString.Invariant ( @@ -264,24 +346,55 @@ static Type monovm_typemap_java_to_managed (string java_type_name) static Type? GetJavaToManagedTypeCore (string class_name) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.lookup.jni_name"); + if (operation.IsActive) { + operation.SetTag ("jni.name", class_name); + } if (TypeManagerMapDictionaries.JniToManaged.TryGetValue (class_name, out Type? type)) { + if (operation.IsActive) { + operation.SetTag ("cache.hit", true); + operation.SetTag ("managed.type", type.FullName); + } return type; } + if (operation.IsActive) { + operation.SetTag ("cache.hit", false); + } + if (RuntimeFeature.TrimmableTypeMap) { throw new System.Diagnostics.UnreachableException ( $"{nameof (TypeManager)}.{nameof (GetJavaToManagedTypeCore)} should not be used when " + $"{nameof (RuntimeFeature.TrimmableTypeMap)} is enabled. The trimmable path should resolve " + $"types through {nameof (TrimmableTypeMapTypeManager)}."); } else if (RuntimeFeature.IsMonoRuntime) { + using var uncachedOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.lookup.jni_name.uncached"); + if (uncachedOperation.IsActive) { + uncachedOperation.SetTag ("jni.name", class_name); + uncachedOperation.SetTag ("runtime", "monovm"); + } type = monovm_typemap_java_to_managed (class_name); + if (uncachedOperation.IsActive) { + uncachedOperation.SetTag ("managed.type", type?.FullName); + } } else if (RuntimeFeature.IsCoreClrRuntime) { + using var uncachedOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.lookup.jni_name.uncached"); + if (uncachedOperation.IsActive) { + uncachedOperation.SetTag ("jni.name", class_name); + uncachedOperation.SetTag ("runtime", "coreclr"); + } type = clr_typemap_java_to_managed (class_name); + if (uncachedOperation.IsActive) { + uncachedOperation.SetTag ("managed.type", type?.FullName); + } } else { throw new NotSupportedException ("Internal error: unknown runtime not supported"); } if (type != null) { + if (operation.IsActive) { + operation.SetTag ("managed.type", type.FullName); + } TypeManagerMapDictionaries.JniToManaged.Add (class_name, type); return type; } @@ -301,23 +414,69 @@ static Type monovm_typemap_java_to_managed (string java_type_name) [UnconditionalSuppressMessage ("Trimming", "IL2072", Justification = "TypeManager.CreateProxy() does not statically know the value of the 'type' local variable.")] internal static IJavaPeerable? CreateInstance (IntPtr handle, JniHandleOwnership transfer, Type? targetType) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.create"); + if (operation.IsActive) { + operation.SetTag ("target.type", targetType?.FullName); + } Type? type = null; - IntPtr class_ptr = JNIEnv.GetObjectClass (handle); - string? class_name = GetClassName (class_ptr); + IntPtr class_ptr; + using (var classOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.get_object_class")) { + class_ptr = JNIEnv.GetObjectClass (handle); + if (classOperation.IsActive) { + classOperation.SetTag ("class.handle", class_ptr); + } + } + string? class_name; + using (var nameOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.get_class_name")) { + class_name = GetClassName (class_ptr); + if (nameOperation.IsActive) { + nameOperation.SetTag ("jni.name", class_name); + } + } + if (operation.IsActive) { + operation.SetTag ("jni.name", class_name); + } lock (TypeManagerMapDictionaries.AccessLock) { + int depth = 0; while (class_ptr != IntPtr.Zero) { - type = GetJavaToManagedTypeCore (class_name); - if (type != null) { - break; + using (var resolveOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.resolve_class")) { + if (resolveOperation.IsActive) { + resolveOperation.SetTag ("jni.name", class_name); + resolveOperation.SetTag ("depth", depth); + } + type = GetJavaToManagedTypeCore (class_name); + if (resolveOperation.IsActive) { + resolveOperation.SetTag ("managed.type", type?.FullName); + resolveOperation.SetTag ("resolved", type is not null); + } + if (type != null) { + break; + } } - IntPtr super_class_ptr = JNIEnv.GetSuperclass (class_ptr); + IntPtr super_class_ptr; + using (var superOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.get_superclass")) { + if (superOperation.IsActive) { + superOperation.SetTag ("jni.name", class_name); + superOperation.SetTag ("depth", depth); + } + super_class_ptr = JNIEnv.GetSuperclass (class_ptr); + if (superOperation.IsActive) { + superOperation.SetTag ("has.superclass", super_class_ptr != IntPtr.Zero); + } + } JNIEnv.DeleteLocalRef (class_ptr); class_name = null; class_ptr = super_class_ptr; if (class_ptr != IntPtr.Zero) { + using var superclassNameOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.get_superclass_name"); class_name = GetClassName (class_ptr); + if (superclassNameOperation.IsActive) { + superclassNameOperation.SetTag ("jni.name", class_name); + superclassNameOperation.SetTag ("depth", depth + 1); + } } + depth++; } } @@ -331,6 +490,9 @@ static Type monovm_typemap_java_to_managed (string java_type_name) !targetType.IsAssignableFrom (type))) { type = targetType; } + if (operation.IsActive) { + operation.SetTag ("managed.type", type?.FullName); + } if (type == null) { class_name = JNIEnv.GetClassNameFromInstance (handle); @@ -346,9 +508,22 @@ static Type monovm_typemap_java_to_managed (string java_type_name) throw new NotSupportedException ("Unable to find Invoker for type '" + type.FullName + "'. Was it linked away?", CreateJavaLocationException ()); type = invokerType; + if (operation.IsActive) { + operation.SetTag ("invoker.type", type.FullName); + } } - var typeSig = JNIEnvInit.androidRuntime?.TypeManager.GetTypeSignature (type) ?? default; + JniTypeSignature typeSig; + using (var signatureOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.get_type_signature")) { + if (signatureOperation.IsActive) { + signatureOperation.SetTag ("managed.type", type.FullName); + } + typeSig = JNIEnvInit.androidRuntime?.TypeManager.GetTypeSignature (type) ?? default; + if (signatureOperation.IsActive) { + signatureOperation.SetTag ("jni.simple_reference", typeSig.SimpleReference); + signatureOperation.SetTag ("valid", typeSig.IsValid); + } + } if (!typeSig.IsValid || typeSig.SimpleReference == null) { throw new ArgumentException ($"Could not determine Java type corresponding to `{type.AssemblyQualifiedName}`.", nameof (targetType)); } @@ -357,6 +532,10 @@ static Type monovm_typemap_java_to_managed (string java_type_name) JniObjectReference handleClass = default; try { try { + using var findClassOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.find_type_class"); + if (findClassOperation.IsActive) { + findClassOperation.SetTag ("jni.name", typeSig.SimpleReference); + } typeClass = JniEnvironment.Types.FindClass (typeSig.SimpleReference); } catch (Exception e) { throw new ArgumentException ($"Could not find Java class `{typeSig.SimpleReference}`.", @@ -364,8 +543,21 @@ static Type monovm_typemap_java_to_managed (string java_type_name) e); } - handleClass = JniEnvironment.Types.GetObjectClass (new JniObjectReference (handle)); - if (!JniEnvironment.Types.IsAssignableFrom (handleClass, typeClass)) { + using (var handleClassOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.get_handle_class")) { + handleClass = JniEnvironment.Types.GetObjectClass (new JniObjectReference (handle)); + } + bool isAssignable; + using (var assignabilityOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.peer.assignability_check")) { + if (assignabilityOperation.IsActive) { + assignabilityOperation.SetTag ("managed.type", type.FullName); + assignabilityOperation.SetTag ("jni.simple_reference", typeSig.SimpleReference); + } + isAssignable = JniEnvironment.Types.IsAssignableFrom (handleClass, typeClass); + if (assignabilityOperation.IsActive) { + assignabilityOperation.SetTag ("assignable", isAssignable); + } + } + if (!isAssignable) { if (Logger.LogAssembly) { var message = $"Handle 0x{handle:x} is of type '{JNIEnv.GetClassNameFromInstance (handle)}' which is not assignable to '{typeSig.SimpleReference}'"; Logger.Log (LogLevel.Debug, "monodroid-assembly", message); @@ -383,6 +575,9 @@ static Type monovm_typemap_java_to_managed (string java_type_name) try { result = (IJavaPeerable) CreateProxy (type, handle, transfer); + if (operation.IsActive) { + operation.SetTag ("created", true); + } if (Runtime.IsGCUserPeer (result.PeerReference.Handle)) { result.SetJniManagedPeerState (JniManagedPeerStates.Replaceable | JniManagedPeerStates.Activatable); } @@ -404,17 +599,27 @@ internal static object CreateProxy ( IntPtr handle, JniHandleOwnership transfer) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.llvm.proxy.create"); + if (operation.IsActive) { + operation.SetTag ("managed.type", type.FullName); + } // Skip Activator.CreateInstance() as that requires public constructors, // and we want to hide some constructors for sanity reasons. var peer = GetUninitializedObject (type); BindingFlags flags = BindingFlags.Public | BindingFlags.NonPublic | BindingFlags.Instance; var c = type.GetConstructor (flags, null, XAConstructorSignature, null); if (c != null) { + if (operation.IsActive) { + operation.SetTag ("constructor.signature", "IntPtr,JniHandleOwnership"); + } c.Invoke (peer, new object[] { handle, transfer }); return peer; } c = type.GetConstructor (flags, null, JIConstructorSignature, null); if (c != null) { + if (operation.IsActive) { + operation.SetTag ("constructor.signature", "JniObjectReference,JniObjectReferenceOptions"); + } JniObjectReference r = new JniObjectReference (handle); JniObjectReferenceOptions o = JniObjectReferenceOptions.Copy; c.Invoke (peer, new object [] { r, o }); diff --git a/src/Mono.Android/Microsoft.Android.Runtime/JavaMarshalValueManager.cs b/src/Mono.Android/Microsoft.Android.Runtime/JavaMarshalValueManager.cs index e07fda8e225..8a28edb5781 100644 --- a/src/Mono.Android/Microsoft.Android.Runtime/JavaMarshalValueManager.cs +++ b/src/Mono.Android/Microsoft.Android.Runtime/JavaMarshalValueManager.cs @@ -486,14 +486,24 @@ void ProcessContext (HandleContext* context) } if (RuntimeFeature.TrimmableTypeMap) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.peer.create"); + if (operation.IsActive) { + operation.SetTag ("target.type", targetType?.FullName); + } try { // Mirror legacy GetPeerType: callers commonly request universal // interfaces / boxes (IJavaPeerable, object, Exception) — map these // to a concrete peer type so the proxy lookup can succeed. var resolvedTargetType = ResolvePeerType (targetType); + if (operation.IsActive) { + operation.SetTag ("resolved.target.type", resolvedTargetType?.FullName); + } var typeMap = TrimmableTypeMap.Instance; var proxy = typeMap.GetProxyForJavaObject (reference.Handle, resolvedTargetType); + if (operation.IsActive) { + operation.SetTag ("proxy.target.type", proxy?.TargetType.FullName); + } // Open-generic proxies cannot instantiate closed targets. IJavaPeerable? peer; @@ -508,8 +518,14 @@ void ProcessContext (HandleContext* context) peerState |= JniManagedPeerStates.Activatable; } peer.SetJniManagedPeerState (peerState); + if (operation.IsActive) { + operation.SetTag ("created", true); + } return peer; } + if (operation.IsActive) { + operation.SetTag ("created", false); + } // Disambiguate the failure — match the contract of the base // JniRuntime.JniValueManager.CreatePeer so JavaCast / JavaAs diff --git a/src/Mono.Android/Microsoft.Android.Runtime/SingleUniverseTypeMap.cs b/src/Mono.Android/Microsoft.Android.Runtime/SingleUniverseTypeMap.cs index a6afdba2bab..3ad2c8d5e03 100644 --- a/src/Mono.Android/Microsoft.Android.Runtime/SingleUniverseTypeMap.cs +++ b/src/Mono.Android/Microsoft.Android.Runtime/SingleUniverseTypeMap.cs @@ -47,6 +47,10 @@ public SingleUniverseTypeMap ( public IEnumerable GetProxyTypes (string jniName) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.universe.get_proxy_types"); + if (operation.IsActive) { + operation.SetTag ("jni.name", jniName); + } if (!_typeMap.TryGetValue (jniName, out var mappedType)) { yield break; } @@ -73,6 +77,10 @@ public IEnumerable GetProxyTypes (string jniName) public bool TryGetProxyType (Type managedType, [NotNullWhen (true)] out Type? proxyType) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.universe.try_get_proxy_type"); + if (operation.IsActive) { + operation.SetTag ("managed.type", managedType.FullName); + } if (!_proxyTypeMap.TryGetValue (managedType, out var mappedProxyType)) { proxyType = null; return false; diff --git a/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMap.cs b/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMap.cs index a574c00a066..c12a9a23ebe 100644 --- a/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMap.cs +++ b/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMap.cs @@ -62,6 +62,7 @@ public static void Initialize ( { ArgumentNullException.ThrowIfNull (typeMap); ArgumentNullException.ThrowIfNull (proxyMap); + TrimmableTypeMapTelemetry.RecordEntries ("universe", 1); InitializeCore (new SingleUniverseTypeMap (typeMap, proxyMap, arrayMapsByRank)); } @@ -75,6 +76,7 @@ public static void Initialize ( { ArgumentNullException.ThrowIfNull (typeMap); ArgumentNullException.ThrowIfNull (proxyMap); + TrimmableTypeMapTelemetry.RecordEntries ("universe", 1); InitializeCore (new SingleUniverseTypeMap (typeMap, proxyMap, arrayMapsByUniverseAndRank)); } @@ -111,6 +113,7 @@ public static void Initialize ( throw new ArgumentException ($"arrayMapsByUniverseAndRank.Length ({arrayMapsByUniverseAndRank.Length}) must equal typeMaps.Length ({typeMaps.Length}).", nameof (arrayMapsByUniverseAndRank)); } + TrimmableTypeMapTelemetry.RecordEntries ("universe", typeMaps.Length); var universes = new SingleUniverseTypeMap [typeMaps.Length]; for (int i = 0; i < typeMaps.Length; i++) { universes [i] = new SingleUniverseTypeMap (typeMaps [i], proxyMaps [i], arrayMapsByUniverseAndRank? [i]); @@ -120,6 +123,7 @@ public static void Initialize ( static void InitializeCore (ITypeMap typeMap) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.initialize"); lock (s_initLock) { if (s_instance is not null) { throw new InvalidOperationException ("TrimmableTypeMap has already been initialized."); @@ -131,6 +135,7 @@ static void InitializeCore (ITypeMap typeMap) internal static unsafe void RegisterNativeMethods () { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.register_native_methods"); lock (s_initLock) { if (s_nativeMethodsRegistered) { throw new InvalidOperationException ("TrimmableTypeMap native methods have already been registered."); @@ -178,7 +183,15 @@ internal bool TryGetTargetTypes (string jniName, [NotNullWhen (true)] out Type[] /// JavaPeerProxy[] GetProxiesForJniName (string jniName) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.lookup.jni_name"); + if (operation.IsActive) { + operation.SetTag ("jni.name", jniName); + } return _jniProxyCache.GetOrAdd (jniName, static (name, self) => { + using var uncachedOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.lookup.jni_name.uncached"); + if (uncachedOperation.IsActive) { + uncachedOperation.SetTag ("jni.name", name); + } var result = new List (); foreach (var type in self._typeMap.GetProxyTypes (name)) { var proxy = type.GetCustomAttribute (inherit: false); @@ -213,11 +226,19 @@ JavaPeerProxy[] GetProxiesForJniName (string jniName) } JavaPeerProxy? GetProxyForManagedType (Type managedType) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.lookup.managed_type"); + if (operation.IsActive) { + operation.SetTag ("managed.type", managedType.FullName); + } if (managedType.IsGenericType && !managedType.IsGenericTypeDefinition) { managedType = managedType.GetGenericTypeDefinition (); } var proxy = _proxyCache.GetOrAdd (managedType, static (type, self) => { + using var uncachedOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.lookup.managed_type.uncached"); + if (uncachedOperation.IsActive) { + uncachedOperation.SetTag ("managed.type", type.FullName); + } if (!self._typeMap.TryGetProxyType (type, out var proxyType)) { return s_noPeerSentinel; } @@ -235,6 +256,10 @@ internal bool TryGetJniNameForManagedType (Type managedType, [NotNullWhen (true) internal JavaPeerProxy? GetProxyForJavaObject (IntPtr handle, Type? targetType = null) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.lookup.java_object"); + if (operation.IsActive) { + operation.SetTag ("target.type", targetType?.FullName); + } if (handle == IntPtr.Zero) { return null; } @@ -283,9 +308,21 @@ internal bool TryGetJniNameForManagedType (Type managedType, [NotNullWhen (true) static JavaPeerProxy? GetProxyForJavaInterfaces (TrimmableTypeMap self, JniObjectReference jniClass, string className, Type targetType) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.lookup.java_interfaces"); + if (operation.IsActive) { + operation.SetTag ("jni.name", className); + operation.SetTag ("target.type", targetType.FullName); + } var proxy = self._interfaceProxyCache.GetOrAdd ( (className, targetType), - _ => TryMatchInterfaces (self, jniClass, targetType) ?? s_noPeerSentinel); + _ => { + using var uncachedOperation = TrimmableTypeMapTelemetry.StartOperation ("typemap.lookup.java_interfaces.uncached"); + if (uncachedOperation.IsActive) { + uncachedOperation.SetTag ("jni.name", className); + uncachedOperation.SetTag ("target.type", targetType.FullName); + } + return TryMatchInterfaces (self, jniClass, targetType) ?? s_noPeerSentinel; + }); return ReferenceEquals (proxy, s_noPeerSentinel) ? null : proxy; } @@ -347,6 +384,10 @@ static JniMethodInfo GetClassGetInterfacesMethod () static JavaPeerProxy? TryGetProxyFromTargetType (TrimmableTypeMap self, IntPtr handle, Type? targetType) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.lookup.target_type_fallback"); + if (operation.IsActive) { + operation.SetTag ("target.type", targetType?.FullName); + } if (targetType is null) { return null; } @@ -506,6 +547,7 @@ static bool TryGetPrimitiveJniName (Type primitive, [NotNullWhen (true)] out str [UnmanagedCallersOnly] static void OnRegisterNatives (IntPtr jnienv, IntPtr klass, IntPtr nativeClassHandle) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.on_register_natives"); string? className = null; try { if (s_instance is null) { @@ -517,8 +559,14 @@ static void OnRegisterNatives (IntPtr jnienv, IntPtr klass, IntPtr nativeClassHa if (className is null) { return; } + if (operation.IsActive) { + operation.SetTag ("jni.name", className); + } var proxies = s_instance.GetProxiesForJniName (className); + if (operation.IsActive) { + operation.SetTag ("proxy.count", proxies.Length); + } if (proxies.Length == 0) { return; } diff --git a/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMapTelemetry.cs b/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMapTelemetry.cs new file mode 100644 index 00000000000..50cacfb7996 --- /dev/null +++ b/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMapTelemetry.cs @@ -0,0 +1,222 @@ +#nullable enable + +using System; +using System.Diagnostics; +using System.Diagnostics.Metrics; + +namespace Microsoft.Android.Runtime; + +static class TrimmableTypeMapTelemetry +{ + const string InstrumentationName = "Microsoft.Android.Runtime.TrimmableTypeMap"; + const int MaxBufferedOperations = 256; + + static readonly ActivitySource s_activitySource = new (InstrumentationName); + static readonly Meter s_meter = new (InstrumentationName); + static readonly Histogram s_operationDuration = s_meter.CreateHistogram ( + "android.typemap.operation.duration", + unit: "ms", + description: "Duration of trimmable typemap startup and lookup operations."); + static readonly Counter s_operationCount = s_meter.CreateCounter ( + "android.typemap.operation.count", + unit: "{operation}", + description: "Count of trimmable typemap startup and lookup operations."); + static readonly Counter s_entryCount = s_meter.CreateCounter ( + "android.typemap.entries", + unit: "{entry}", + description: "Number of generated trimmable typemap entries loaded by kind."); + static readonly object s_bufferedOperationsLock = new (); + static readonly BufferedOperation[] s_bufferedOperations = new BufferedOperation [MaxBufferedOperations]; + static int s_bufferedOperationCount; + static bool s_bufferedOperationsFlushed; + + public static bool IsEnabled => + s_activitySource.HasListeners () || + s_operationDuration.Enabled || + s_operationCount.Enabled || + s_entryCount.Enabled; + + public static OperationScope StartOperation (string operation) + { + var hasActivityListeners = s_activitySource.HasListeners (); + if (!hasActivityListeners && !ShouldBufferOperations () && !s_operationDuration.Enabled && !s_operationCount.Enabled) { + return default; + } + + if (hasActivityListeners) { + FlushBufferedEvents (); + } + + var activity = hasActivityListeners ? s_activitySource.StartActivity (operation) : null; + var startTimestamp = activity is not null || s_operationDuration.Enabled ? Stopwatch.GetTimestamp () : 0; + return new OperationScope (operation, activity, startTimestamp, bufferOperation: !hasActivityListeners && ShouldBufferOperations ()); + } + + public static void RecordEntries (string kind, long count) + { + if (!s_entryCount.Enabled) { + return; + } + + var tags = new TagList { + { "kind", kind }, + }; + s_entryCount.Add (count, tags); + } + + static bool ShouldBufferOperations () + { + if (s_bufferedOperationsFlushed) { + return false; + } + + lock (s_bufferedOperationsLock) { + return !s_bufferedOperationsFlushed && s_bufferedOperationCount < s_bufferedOperations.Length; + } + } + + static void BufferOperation (string operation, DateTimeOffset startTimestamp, DateTimeOffset endTimestamp) + { + lock (s_bufferedOperationsLock) { + if (s_bufferedOperationsFlushed || s_bufferedOperationCount >= s_bufferedOperations.Length) { + return; + } + + s_bufferedOperations [s_bufferedOperationCount++] = new BufferedOperation (operation, startTimestamp, endTimestamp); + } + } + + static void FlushBufferedEvents () + { + BufferedOperation[]? bufferedOperations = null; + int bufferedOperationCount; + + lock (s_bufferedOperationsLock) { + if (s_bufferedOperationsFlushed) { + return; + } + + bufferedOperationCount = s_bufferedOperationCount; + if (bufferedOperationCount > 0) { + bufferedOperations = new BufferedOperation [bufferedOperationCount]; + Array.Copy (s_bufferedOperations, bufferedOperations, bufferedOperationCount); + } + s_bufferedOperationsFlushed = true; + } + + if (bufferedOperations is null) { + return; + } + + using (var activity = s_activitySource.StartActivity ("typemap.buffered_events")) { + if (activity is not null) { + activity.SetTag ("operation.count", bufferedOperationCount); + } + } + + foreach (var bufferedOperation in bufferedOperations) { + var activity = s_activitySource.StartActivity ( + bufferedOperation.Name, + ActivityKind.Internal, + default (ActivityContext), + tags: null, + links: null, + startTime: bufferedOperation.StartTimestamp); + if (activity is null) { + continue; + } + + activity.SetTag ("buffered", true); + activity.SetTag ("duration.us", (bufferedOperation.EndTimestamp - bufferedOperation.StartTimestamp).TotalMicroseconds); + activity.AddEvent (new ActivityEvent ($"{bufferedOperation.Name}.start", bufferedOperation.StartTimestamp)); + activity.AddEvent (new ActivityEvent ($"{bufferedOperation.Name}.end", bufferedOperation.EndTimestamp)); + activity.SetEndTime (bufferedOperation.EndTimestamp.UtcDateTime); + activity.Dispose (); + + if (s_operationDuration.Enabled) { + var tags = new TagList { + { "operation", bufferedOperation.Name }, + { "buffered", true }, + }; + s_operationDuration.Record ((bufferedOperation.EndTimestamp - bufferedOperation.StartTimestamp).TotalMilliseconds, tags); + } + if (s_operationCount.Enabled) { + var tags = new TagList { + { "operation", bufferedOperation.Name }, + { "buffered", true }, + }; + s_operationCount.Add (1, tags); + } + } + } + + readonly struct BufferedOperation + { + public readonly string Name; + public readonly DateTimeOffset StartTimestamp; + public readonly DateTimeOffset EndTimestamp; + + public BufferedOperation (string name, DateTimeOffset startTimestamp, DateTimeOffset endTimestamp) + { + Name = name; + StartTimestamp = startTimestamp; + EndTimestamp = endTimestamp; + } + } + + public readonly struct OperationScope : IDisposable + { + readonly string? operation; + readonly Activity? activity; + readonly long startTimestamp; + readonly bool bufferOperation; + readonly DateTimeOffset startEventTimestamp; + + public bool IsActive => activity is not null; + + public OperationScope (string operation, Activity? activity, long startTimestamp, bool bufferOperation) + { + this.operation = operation; + this.activity = activity; + this.startTimestamp = startTimestamp; + this.bufferOperation = bufferOperation; + startEventTimestamp = DateTimeOffset.UtcNow; + activity?.AddEvent (new ActivityEvent ($"{operation}.start")); + } + + public void SetTag (string key, object? value) + { + activity?.SetTag (key, value); + } + + public void Dispose () + { + if (operation is not null) { + activity?.AddEvent (new ActivityEvent ($"{operation}.end")); + if (bufferOperation) { + BufferOperation (operation, startEventTimestamp, DateTimeOffset.UtcNow); + } + + if (startTimestamp != 0) { + var elapsed = Stopwatch.GetElapsedTime (startTimestamp).TotalMilliseconds; + activity?.SetTag ("duration.us", elapsed * 1000); + if (s_operationDuration.Enabled) { + var tags = new TagList { + { "operation", operation }, + }; + s_operationDuration.Record (elapsed, tags); + } + } + + if (s_operationCount.Enabled) { + var tags = new TagList { + { "operation", operation }, + }; + s_operationCount.Add (1, tags); + } + } + + activity?.Dispose (); + } + } +} diff --git a/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMapTypeManager.cs b/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMapTypeManager.cs index dea8cb2dcb8..257b21b426d 100644 --- a/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMapTypeManager.cs +++ b/src/Mono.Android/Microsoft.Android.Runtime/TrimmableTypeMapTypeManager.cs @@ -21,6 +21,10 @@ class TrimmableTypeMapTypeManager : JniRuntime.JniTypeManager protected override IEnumerable GetTypesForSimpleReference (string jniSimpleReference) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.type_manager.get_types_for_simple_reference"); + if (operation.IsActive) { + operation.SetTag ("jni.name", jniSimpleReference); + } foreach (var t in base.GetTypesForSimpleReference (jniSimpleReference)) { yield return t; } @@ -34,12 +38,20 @@ protected override IEnumerable GetTypesForSimpleReference (string jniSimpl protected override string? GetSimpleReference (Type type) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.type_manager.get_simple_reference"); + if (operation.IsActive) { + operation.SetTag ("managed.type", type.FullName); + } var simpleReference = _simpleReferenceCache.GetOrAdd (type, GetSimpleReferenceUncached); return simpleReference == NoSimpleReference ? null : simpleReference; } string GetSimpleReferenceUncached (Type type) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.type_manager.get_simple_reference.uncached"); + if (operation.IsActive) { + operation.SetTag ("managed.type", type.FullName); + } if (TrimmableTypeMap.Instance.TryGetJniNameForManagedType (type, out var jniName)) { return jniName; } @@ -61,6 +73,10 @@ string GetSimpleReferenceUncached (Type type) protected override IEnumerable GetSimpleReferences (Type type) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.type_manager.get_simple_references"); + if (operation.IsActive) { + operation.SetTag ("managed.type", type.FullName); + } if (TrimmableTypeMap.Instance.TryGetJniNameForManagedType (type, out var jniName)) { yield return jniName; yield break; @@ -85,6 +101,10 @@ protected override IEnumerable GetSimpleReferences (Type type) [DynamicallyAccessedMembers (DynamicallyAccessedMemberTypes.PublicConstructors | DynamicallyAccessedMemberTypes.NonPublicConstructors)] Type type) { + using var operation = TrimmableTypeMapTelemetry.StartOperation ("typemap.type_manager.get_invoker_type"); + if (operation.IsActive) { + operation.SetTag ("managed.type", type.FullName); + } var invokerType = TrimmableTypeMap.Instance.GetInvokerType (type); if (invokerType != null) { return invokerType; diff --git a/src/Mono.Android/Mono.Android.csproj b/src/Mono.Android/Mono.Android.csproj index d2622d1bfff..bee27fc5f36 100644 --- a/src/Mono.Android/Mono.Android.csproj +++ b/src/Mono.Android/Mono.Android.csproj @@ -370,6 +370,7 @@ + diff --git a/trimmable-typemap-otel-data.md b/trimmable-typemap-otel-data.md new file mode 100644 index 00000000000..6c027218508 --- /dev/null +++ b/trimmable-typemap-otel-data.md @@ -0,0 +1,279 @@ +# Trimmable typemap OTEL data + +Captured from the Aspire dashboard telemetry API with `aspire describe --format Json`, `aspire otel traces --format Json`, `aspire otel spans --format Json`, and `aspire otel logs helloworld-android --format Json`. + +## Capture context + +- Resource: `helloworld-android` / `helloworld-android-sekjyauw` +- Type: `Executable` +- State: `Running` +- Health: `Healthy` +- Dashboard resource URL: https://localhost:17193/?resource=helloworld-android-sekjyauw +- OTLP endpoint in resource environment: `http://localhost:4318` +- Runtime: `CoreCLR` +- Type map: `trimmable` +- Configuration: `Release` + +## Dataset summary + +- Traces returned: **8** +- Spans returned: **31** +- Structured logs returned: **0** +- Span duration range: **0-1 ms** +- Span sources: `helloworld-android` (31) + +> Note: the Aspire CLI exposes traces, spans, and structured logs. Metrics were exported by the app, but no `aspire otel metrics` command is available in the current CLI, so this file records the available OTEL trace/span/log data. + +## Operation counts + +| Operation | Span count | Duration ms | Notable attributes | +| --- | ---: | --- | --- | +| `typemap.activation.should_skip` | 1 | 0-0 | reason=existing-peer | +| `typemap.buffered_events` | 1 | 0-0 | event.count=102 | +| `typemap.lookup.java_object` | 1 | 1-1 | target.type=Android.Views.View | +| `typemap.lookup.jni_name` | 2 | 0-1 | jni.name=android/widget/Button; jni.name=mono/android/view/View_OnClickListenerImplementor | +| `typemap.lookup.jni_name.uncached` | 2 | 0-1 | jni.name=android/widget/Button; jni.name=mono/android/view/View_OnClickListenerImplementor | +| `typemap.lookup.managed_type` | 4 | 0-1 | managed.type=Java.Lang.Object; managed.type=Android.Views.View+IOnClickListenerImplementor; managed.type=Android.Views.View; managed.type=Android.Widget.Button | +| `typemap.lookup.managed_type.uncached` | 4 | 0-1 | managed.type=Java.Lang.Object; managed.type=Android.Views.View+IOnClickListenerImplementor; managed.type=Android.Views.View; managed.type=Android.Widget.Button | +| `typemap.on_register_natives` | 1 | 1-1 | jni.name=mono/android/view/View_OnClickListenerImplementor; proxy.count=1 | +| `typemap.peer.create` | 1 | 1-1 | target.type=Android.Views.View; proxy.target.type=Android.Widget.Button; created=true | +| `typemap.type_manager.get_simple_reference` | 4 | 0-1 | managed.type=Java.Lang.Object; managed.type=Android.Views.View+IOnClickListenerImplementor; managed.type=Android.Views.View; managed.type=Android.Widget.Button | +| `typemap.type_manager.get_simple_reference.uncached` | 4 | 0-1 | managed.type=Java.Lang.Object; managed.type=Android.Views.View+IOnClickListenerImplementor; managed.type=Android.Views.View; managed.type=Android.Widget.Button | +| `typemap.universe.get_proxy_types` | 2 | 0-0 | jni.name=android/widget/Button; jni.name=mono/android/view/View_OnClickListenerImplementor | +| `typemap.universe.try_get_proxy_type` | 4 | 0-1 | managed.type=Java.Lang.Object; managed.type=Android.Views.View+IOnClickListenerImplementor; managed.type=Android.Views.View; managed.type=Android.Widget.Button | + +## Traces + +| Trace | Title | Duration ms | Span count | Status | +| --- | --- | ---: | ---: | --- | +| [75d71f2](https://localhost:17193/traces/detail/75d71f22a3ceab38f9728c03c55ba270) | `typemap.buffered_events` | 0 | 1 | ok | +| [bded42c](https://localhost:17193/traces/detail/bded42cf4e95abec392a14caaacd7398) | `typemap.peer.create` | 1 | 5 | ok | +| [4fdffdb](https://localhost:17193/traces/detail/4fdffdbf23c3cc6d28ffed79a456dd67) | `typemap.type_manager.get_simple_reference` | 0 | 5 | ok | +| [a168e27](https://localhost:17193/traces/detail/a168e2707a279e8d6bf68da7f4f0bb64) | `typemap.type_manager.get_simple_reference` | 1 | 5 | ok | +| [09c3f3a](https://localhost:17193/traces/detail/09c3f3a8a236dc5d76006ff7d5f555cd) | `typemap.on_register_natives` | 1 | 4 | ok | +| [ae0c3c2](https://localhost:17193/traces/detail/ae0c3c26dd40e6a48c9effb852a78a25) | `typemap.activation.should_skip` | 0 | 1 | ok | +| [621e741](https://localhost:17193/traces/detail/621e74123f37e044bf481dc3085558cf) | `typemap.type_manager.get_simple_reference` | 0 | 5 | ok | +| [c7dacaa](https://localhost:17193/traces/detail/c7dacaa8b3ec898b5aac5ee3baac83c5) | `typemap.type_manager.get_simple_reference` | 0 | 5 | ok | + +## Representative span trees + +### `typemap.buffered_events` (`75d71f2`) + +Dashboard: https://localhost:17193/traces/detail/75d71f22a3ceab38f9728c03c55ba270 + +- `typemap.buffered_events` span `059abc7` duration `0 ms` (event.count=102) + +### `typemap.peer.create` (`bded42c`) + +Dashboard: https://localhost:17193/traces/detail/bded42cf4e95abec392a14caaacd7398 + +- `typemap.peer.create` span `a5748d8` duration `1 ms` (target.type=Android.Views.View, resolved.target.type=Android.Views.View, proxy.target.type=Android.Widget.Button, created=true) + - `typemap.lookup.java_object` span `1143e29` duration `1 ms` (target.type=Android.Views.View) + - `typemap.lookup.jni_name` span `1717b09` duration `1 ms` (jni.name=android/widget/Button) + - `typemap.lookup.jni_name.uncached` span `4bc9bcb` duration `1 ms` (jni.name=android/widget/Button) + - `typemap.universe.get_proxy_types` span `c0a7632` duration `0 ms` (jni.name=android/widget/Button) + +### `typemap.type_manager.get_simple_reference` (`4fdffdb`) + +Dashboard: https://localhost:17193/traces/detail/4fdffdbf23c3cc6d28ffed79a456dd67 + +- `typemap.type_manager.get_simple_reference` span `5296e93` duration `0 ms` (managed.type=Java.Lang.Object) + - `typemap.type_manager.get_simple_reference.uncached` span `10f6da6` duration `0 ms` (managed.type=Java.Lang.Object) + - `typemap.lookup.managed_type` span `f2042a9` duration `0 ms` (managed.type=Java.Lang.Object) + - `typemap.lookup.managed_type.uncached` span `5f89088` duration `0 ms` (managed.type=Java.Lang.Object) + - `typemap.universe.try_get_proxy_type` span `441d427` duration `0 ms` (managed.type=Java.Lang.Object) + +### `typemap.type_manager.get_simple_reference` (`a168e27`) + +Dashboard: https://localhost:17193/traces/detail/a168e2707a279e8d6bf68da7f4f0bb64 + +- `typemap.type_manager.get_simple_reference` span `f084d36` duration `1 ms` (managed.type=Android.Views.View+IOnClickListenerImplementor) + - `typemap.type_manager.get_simple_reference.uncached` span `149e0a2` duration `1 ms` (managed.type=Android.Views.View+IOnClickListenerImplementor) + - `typemap.lookup.managed_type` span `ab0764b` duration `1 ms` (managed.type=Android.Views.View+IOnClickListenerImplementor) + - `typemap.lookup.managed_type.uncached` span `7e47917` duration `1 ms` (managed.type=Android.Views.View+IOnClickListenerImplementor) + - `typemap.universe.try_get_proxy_type` span `a500d0b` duration `1 ms` (managed.type=Android.Views.View+IOnClickListenerImplementor) + +### `typemap.on_register_natives` (`09c3f3a`) + +Dashboard: https://localhost:17193/traces/detail/09c3f3a8a236dc5d76006ff7d5f555cd + +- `typemap.on_register_natives` span `c7a582a` duration `1 ms` (jni.name=mono/android/view/View_OnClickListenerImplementor, proxy.count=1) + - `typemap.lookup.jni_name` span `35b71d2` duration `0 ms` (jni.name=mono/android/view/View_OnClickListenerImplementor) + - `typemap.lookup.jni_name.uncached` span `288bd41` duration `0 ms` (jni.name=mono/android/view/View_OnClickListenerImplementor) + - `typemap.universe.get_proxy_types` span `5df335d` duration `0 ms` (jni.name=mono/android/view/View_OnClickListenerImplementor) + +### `typemap.activation.should_skip` (`ae0c3c2`) + +Dashboard: https://localhost:17193/traces/detail/ae0c3c26dd40e6a48c9effb852a78a25 + +- `typemap.activation.should_skip` span `ddd11bb` duration `0 ms` (skip=true, reason=existing-peer) + +### `typemap.type_manager.get_simple_reference` (`621e741`) + +Dashboard: https://localhost:17193/traces/detail/621e74123f37e044bf481dc3085558cf + +- `typemap.type_manager.get_simple_reference` span `fc174ee` duration `0 ms` (managed.type=Android.Views.View) + - `typemap.type_manager.get_simple_reference.uncached` span `8157b18` duration `0 ms` (managed.type=Android.Views.View) + - `typemap.lookup.managed_type` span `91fa5f5` duration `0 ms` (managed.type=Android.Views.View) + - `typemap.lookup.managed_type.uncached` span `63d6a98` duration `0 ms` (managed.type=Android.Views.View) + - `typemap.universe.try_get_proxy_type` span `c9e575c` duration `0 ms` (managed.type=Android.Views.View) + +### `typemap.type_manager.get_simple_reference` (`c7dacaa`) + +Dashboard: https://localhost:17193/traces/detail/c7dacaa8b3ec898b5aac5ee3baac83c5 + +- `typemap.type_manager.get_simple_reference` span `821c5a0` duration `0 ms` (managed.type=Android.Widget.Button) + - `typemap.type_manager.get_simple_reference.uncached` span `592e591` duration `0 ms` (managed.type=Android.Widget.Button) + - `typemap.lookup.managed_type` span `fc4706b` duration `0 ms` (managed.type=Android.Widget.Button) + - `typemap.lookup.managed_type.uncached` span `547a87a` duration `0 ms` (managed.type=Android.Widget.Button) + - `typemap.universe.try_get_proxy_type` span `cb68edc` duration `0 ms` (managed.type=Android.Widget.Button) + +## Raw-data files used + +- Session JSON: `/Users/simonrozsival/.copilot/session-state/334c4935-91fa-4eb9-9b1f-644e1dc6f038/otel/` +- Aspire export bundle captured earlier: `/Users/simonrozsival/Projects/dotnet/android-typemap-otel/samples/TypemapOtelAspire/aspire-export-20260526-111653.zip` + +## 10x launch log collection + +Collected 10 Release/CoreCLR/trimmable launches of `com.xamarin.android.helloworld/example.MainActivity` after clearing `debug.mono.profile` to `none`. + +Raw artifacts: + +- Directory: `/Users/simonrozsival/Projects/dotnet/android-typemap-otel/artifacts/trimmable-typemap-otel-runs/20260526-115846` +- Per run: `run-N/am-start.txt`, `run-N/host-timing.txt`, `run-N/pid.txt`, `run-N/logcat-all.txt`, `run-N/logcat-filtered.txt`, `run-N/aspire-traces.json`, `run-N/aspire-spans.json` +- Aggregate files: `summary.csv`, `stats.csv`, `final-aspire-traces.json`, `final-aspire-spans.json` + +### Precision notes + +- Android `am start -W` reports `TotalTime` and `WaitTime` in integer milliseconds. +- Host-side wall-clock launch timing is stored in microseconds as `host_elapsed_us`. +- Runtime OTEL spans now include a `duration.us` attribute for microsecond precision. This is necessary because Aspire's top-level `durationMs` fields are integer millisecond values. +- Early startup operations that happen before app-level OTEL setup are replayed as buffered spans with original start/end timestamps, so `jnienv.initialize` and `typemap.data.initialize` are visible as timed spans. + +### 10x summary + +| Run | Total ms | Wait ms | Host elapsed us | PID | Trace count | Span count | `jnienv.initialize` us | `typemap.data.initialize` us | +| ---: | ---: | ---: | ---: | ---: | ---: | ---: | ---: | ---: | +| 1 | 557 | 564 | 648734 | 8740 | 134 | 226 | 122651.1 | 82455.6 | +| 2 | 550 | 556 | 652420 | 8836 | 193 | 308 | 99664.9 | 61964.5 | +| 3 | 542 | 545 | 695342 | 8935 | 193 | 308 | 99664.9 | 61964.5 | +| 4 | 539 | 542 | 746665 | 9025 | 200 | 390 | 96694.2 | 60933 | +| 5 | 542 | 545 | 649834 | 9114 | 200 | 472 | 99517.6 | 62330.6 | +| 6 | 528 | 531 | 624504 | 9204 | 200 | 554 | 102958.8 | 62576.6 | +| 7 | 551 | 557 | 670907 | 9293 | 200 | 636 | 98244.1 | 61591.9 | +| 8 | 530 | 538 | 639367 | 9385 | 200 | 718 | 101117 | 63097.5 | +| 9 | 547 | 554 | 678690 | 9501 | 200 | 800 | 99380.3 | 62241.9 | +| 10 | 549 | 556 | 670814 | 9589 | 200 | 882 | 97700.3 | 61176.7 | + +### 10x stats + +| Metric | Count | Min | Median | Max | Mean | +| --- | ---: | ---: | ---: | ---: | ---: | +| `TotalTime` ms | 10 | 528.0 | 544.5 | 557.0 | 543.5 | +| `WaitTime` ms | 10 | 531.0 | 549.5 | 564.0 | 548.8 | +| Host elapsed us | 10 | 624504.0 | 661617.0 | 746665.0 | 667727.7 | +| `jnienv.initialize` us | 10 | 96694.2 | 99591.25 | 122651.1 | 101759.32 | +| `typemap.data.initialize` us | 10 | 60933.0 | 62103.2 | 82455.6 | 64033.28 | + +## LLVM-IR comparison smoke data + +After adding LLVM-IR lookup instrumentation, the same Aspire sample was relaunched with: + +```bash +HELLOWORLD_ANDROID_TYPEMAP=llvm-ir +``` + +The resource environment confirmed `HELLOWORLD_ANDROID_TYPEMAP=llvm-ir`, and `aspire otel spans --format Json` returned the following comparison spans: + +| Span | Duration ms | `duration.us` | Notes | +| --- | ---: | ---: | --- | +| `jnienv.initialize` | 47 | 47354.8 | Buffered startup span | +| `typemap.llvm.activation` | 11 | 10888.9 | Buffered activation path | +| `typemap.llvm.lookup.jni_name` | 1 | 1493.2 | Buffered JNI-name lookup | +| `typemap.llvm.lookup.jni_name.uncached` | 1 | 1487.4 | Buffered native typemap lookup | +| `typemap.llvm.lookup.jni_name` | 0 | 235.3 | Steady-state lookup for `android/widget/Button`, `cache.hit=false` | +| `typemap.llvm.lookup.jni_name.uncached` | 0 | 128.6 | Steady-state CoreCLR lookup for `android/widget/Button` | +| `typemap.llvm.activation` | 0 | 23 | Steady-state activation path | + +This gives direct side-by-side OTEL coverage for LLVM-IR typemap lookups and the trimmable typemap lookup paths in the same Aspire workflow. + +## Detailed LLVM-IR 10x launch log collection + +After adding nested LLVM-IR activation and peer-creation spans, collected 10 Release/CoreCLR/LLVM-IR launches of `com.xamarin.android.helloworld/example.MainActivity`. + +Raw artifacts: + +- Directory: `/Users/simonrozsival/Projects/dotnet/android-typemap-otel/artifacts/llvm-typemap-otel-runs/20260526-130206` +- Per run: `run-N/am-start.txt`, `run-N/host-timing.txt`, `run-N/pid.txt`, `run-N/logcat-all.txt`, `run-N/logcat-filtered.txt`, `run-N/aspire-traces.json`, `run-N/aspire-spans.json` +- Aggregate files: `summary.csv`, `stats.csv`, `final-aspire-traces.json`, `final-aspire-spans.json` + +The detailed LLVM instrumentation now includes spans for activation sub-steps such as `peek_object`, `resolve_type`, `get_parameter_types`, `get_object_array`, `constructor_lookup`, `activate_uninitialized`, `set_peer_reference`, and `invoke_constructor`, plus peer-creation internals such as class lookup, superclass walk, type signature lookup, and assignability checks. + +### LLVM-IR 10x summary + +| Run | Total ms | Wait ms | Host elapsed us | PID | Trace count | Span count | LLVM span count | `jnienv.initialize` us | `typemap.llvm.activation` us | `typemap.llvm.lookup_jni_name.uncached` us | +| ---: | ---: | ---: | ---: | ---: | ---: | ---: | ---: | ---: | ---: | ---: | +| 1 | 484 | 486 | 757226 | 13942 | 22 | 42 | 36 | 37423.2 | 1096.3 | 111.1 | +| 2 | 492 | 494 | 607194 | 14044 | 37 | 42 | 36 | 37423.2 | 1096.3 | 111.1 | +| 3 | 483 | 489 | 635163 | 14130 | 67 | 76 | 66 | 40533.8 | 1000.2 | 84 | +| 4 | 485 | 487 | 594269 | 14222 | 67 | 93 | 81 | 39809.8 | 1040.6 | 82.1 | +| 5 | 470 | 480 | 604356 | 14313 | 97 | 110 | 96 | 38548.6 | 900.6 | 78.7 | +| 6 | 478 | 484 | 577463 | 14399 | 112 | 127 | 111 | 39392.3 | 912.5 | 83 | +| 7 | 478 | 482 | 747416 | 14487 | 112 | 144 | 126 | 38329.9 | 986.5 | 93.3 | +| 8 | 478 | 483 | 586199 | 14575 | 127 | 144 | 126 | 38329.9 | 986.5 | 93.3 | +| 9 | 471 | 473 | 593723 | 14662 | 127 | 161 | 141 | 40153.6 | 963.9 | 127.9 | +| 10 | 483 | 486 | 653005 | 14749 | 142 | 161 | 141 | 40153.6 | 963.9 | 127.9 | + +### LLVM-IR 10x stats + +| Metric | Count | Min | Median | Max | Mean | +| --- | ---: | ---: | ---: | ---: | ---: | +| `TotalTime` ms | 10 | 470.0 | 480.5 | 492.0 | 480.2 | +| `WaitTime` ms | 10 | 473.0 | 485.0 | 494.0 | 484.4 | +| Host elapsed us | 10 | 577463.0 | 605775.0 | 757226.0 | 635601.4 | +| LLVM span count | 10 | 36.0 | 103.5 | 141.0 | 96.0 | +| `jnienv.initialize` us | 10 | 37423.2 | 38970.45 | 40533.8 | 39009.79 | +| `typemap.llvm.activation` us | 10 | 900.6 | 986.5 | 1096.3 | 994.73 | +| `typemap.llvm.lookup_jni_name.uncached` us | 10 | 78.7 | 93.3 | 127.9 | 99.24 | + +## Trimmable vs LLVM-IR paired comparison + +The directly paired startup boundary is `jnienv.initialize`. Trimmable is slower by about **60.6 ms** median, and `typemap.data.initialize` accounts for about **62.1 ms** median. That means the measured trimmable startup regression is almost entirely explained by generated typemap data initialization. + +| Metric | Trimmable median | LLVM-IR median | Delta | Ratio | +| --- | ---: | ---: | ---: | ---: | +| `TotalTime` | 544.5 ms | 480.5 ms | +64.0 ms | 1.13x | +| `WaitTime` | 549.5 ms | 485.0 ms | +64.5 ms | 1.13x | +| Host elapsed | 661,617 us | 605,775 us | +55,842 us | 1.09x | +| `jnienv.initialize` | 99,591.25 us | 38,970.45 us | +60,620.8 us | 2.56x | + +### Paired / analogous spans + +| Concept | Trimmable span | Trimmable median | LLVM-IR span | LLVM-IR median | Notes | +| --- | --- | ---: | --- | ---: | --- | +| JNI runtime init boundary | `jnienv.initialize` | 99,591.25 us | `jnienv.initialize` | 38,970.45 us | Directly comparable boundary. | +| Typemap data setup | `typemap.data.initialize` | 62,103.2 us | none | - | LLVM-IR has no managed generated typemap assembly load equivalent. This is the main trimmable-only cost. | +| Runtime typemap object setup | `typemap.initialize` | 4,249.3 us | none | - | Trimmable wraps generated dictionaries in runtime lookup structures. | +| Native registration setup | `typemap.register_native_methods` | 169.9 us | built-in/native typemap path | - | Not currently separated in LLVM-IR; native path is implicit. | +| Java object -> managed peer creation | `typemap.peer.create` | 1,005.4 us | `typemap.llvm.activation` | 986.5 us | Similar order of magnitude for first activity-related activation. | +| Java object lookup | `typemap.lookup.java_object` | 583.95 us | `typemap.llvm.activation.peek_object` + activation subspans | 8.3 us for `peek_object`; 986.5 us full activation | Trimmable lookup includes more proxy resolution work; LLVM activation breakdown is more granular. | +| JNI-name lookup | `typemap.lookup.jni_name` | 74.25 us | `typemap.llvm.lookup.jni_name` | 201.1 us | Direct lookup concept, but implementation differs. LLVM-IR calls into native typemap metadata; trimmable uses managed dictionaries/proxy attributes. | +| Uncached JNI-name lookup | `typemap.lookup.jni_name.uncached` | 64.95 us | `typemap.llvm.lookup.jni_name.uncached` | 93.3 us | Directly comparable cache-miss path. | +| Managed-type lookup | `typemap.lookup.managed_type` | 63.2 us | no direct measured equivalent yet | - | LLVM-IR managed-to-Java lookup exists elsewhere (`clr_typemap_managed_to_java`) and should be instrumented separately if needed. | +| Uncached managed-type lookup | `typemap.lookup.managed_type.uncached` | 57.55 us | no direct measured equivalent yet | - | Same as above. | +| Register natives for generated proxy | `typemap.on_register_natives` | 844.55 us | no direct measured equivalent | - | Trimmable-specific native registration callback. | + +### LLVM-IR activation breakdown + +| LLVM-IR span | Median | +| --- | ---: | +| `typemap.llvm.activation` | 986.5 us | +| `typemap.llvm.activation.peek_object` | 8.3 us | +| `typemap.llvm.activation.resolve_type` | 114.7 us | +| `typemap.llvm.activation.get_parameter_types` | 0.9 us | +| `typemap.llvm.activation.get_object_array` | 172.2 us | +| `typemap.llvm.activation.constructor_lookup` | 1,182.8 us | +| `typemap.llvm.activation.activate_uninitialized` | 7,673.05 us | +| `typemap.llvm.activation.invoke_constructor` | 6,402.65 us | + +Some nested activation spans exceed the parent `typemap.llvm.activation` median in the cumulative Aspire snapshots, which means the per-run “latest span by name” extraction is not a perfect tree reconstruction. The direction is still useful: LLVM-IR lookup cache misses are sub-millisecond, and the major cross-implementation startup difference is not lookup; it is trimmable-only typemap data initialization.