diff --git a/src/Mono.Android/Microsoft.Android.Runtime/JavaMarshalRegisteredPeers.cs b/src/Mono.Android/Microsoft.Android.Runtime/JavaMarshalRegisteredPeers.cs index cf6f550b5fd..1fabb20bd09 100644 --- a/src/Mono.Android/Microsoft.Android.Runtime/JavaMarshalRegisteredPeers.cs +++ b/src/Mono.Android/Microsoft.Android.Runtime/JavaMarshalRegisteredPeers.cs @@ -6,6 +6,7 @@ using System.Runtime.CompilerServices; using System.Runtime.InteropServices; using System.Runtime.InteropServices.Java; +using System.Threading; using Android.Runtime; using Java.Interop; @@ -58,6 +59,85 @@ internal static void InitializeIfNeeded () } } + /// + /// Diagnostics for dotnet/android#10973. The registry only ever disagrees with a cached + /// reference such as Application.Context if a *second* managed peer is created for + /// the same Java instance. Record the two places observes that -- an + /// existing entry being replaced, and a second entry being appended because the existing + /// one's weak reference was cleared -- so a failing test can report which happened, to + /// whom, and how often. + /// + /// Published via so tests in other assemblies can read them + /// without needing InternalsVisibleTo. Recording only: behaviour is unchanged. + /// + internal const string LiveEvictionsKey = "Microsoft.Android.Runtime.LivePeerEvictions"; + internal const string ReplacementsKey = "Microsoft.Android.Runtime.PeerReplacements"; + internal const string DuplicateAppendsKey = "Microsoft.Android.Runtime.PeerDuplicateAppends"; + internal const string NotReplacedKey = "Microsoft.Android.Runtime.PeerNotReplaced"; + internal const string RemovedKey = "Microsoft.Android.Runtime.PeerRemoved"; + internal const string DeadEvictionsKey = "Microsoft.Android.Runtime.DeadPeerEvictions"; + + static int liveEvictions; + static int deadEvictions; + static int replacements; + static int duplicateAppends; + static int notReplaced; + static int removed; + + static string Id (IJavaPeerable peer) + => $"{peer.GetType ().FullName}@managed-0x{RuntimeHelpers.GetHashCode (peer).ToString ("x", CultureInfo.InvariantCulture)}/{peer.PeerReference}"; + + static void RecordIfLive (int key, ReferenceTrackingHandle peer) + { + if (peer.Target is not IJavaPeerable live) + return; + + int count = Interlocked.Increment (ref liveEvictions); + AppContext.SetData (LiveEvictionsKey, + $"{count} (most recent: key=0x{key.ToString ("x", CultureInfo.InvariantCulture)} {Id (live)})"); + GC.KeepAlive (live); + } + + static void RecordReplacement (int key, IJavaPeerable replaced, IJavaPeerable replacement) + { + int count = Interlocked.Increment (ref replacements); + AppContext.SetData (ReplacementsKey, + $"{count} (most recent: key=0x{key.ToString ("x", CultureInfo.InvariantCulture)} " + + $"replaced {Id (replaced)} with {Id (replacement)})"); + } + + static void RecordDuplicateAppend (int key, IJavaPeerable value, int existing) + { + int count = Interlocked.Increment (ref duplicateAppends); + AppContext.SetData (DuplicateAppendsKey, + $"{count} (most recent: key=0x{key.ToString ("x", CultureInfo.InvariantCulture)} " + + $"appended {Id (value)} alongside {existing} existing entr{(existing == 1 ? "y" : "ies")})"); + } + + // The peer that registers *first* wins, so this also records the registration order: + // `kept` was registered before `rejected` ever reached AddPeer(). + static void RecordNotReplaced (int key, IJavaPeerable kept, IJavaPeerable rejected) + { + int count = Interlocked.Increment (ref notReplaced); + AppContext.SetData (NotReplacedKey, + $"{count} (most recent: key=0x{key.ToString ("x", CultureInfo.InvariantCulture)} " + + $"kept {Id (kept)}, did not register {Id (rejected)})"); + } + + static void RecordRemoved (int key, IJavaPeerable value) + { + int count = Interlocked.Increment (ref removed); + AppContext.SetData (RemovedKey, + $"{count} (most recent: key=0x{key.ToString ("x", CultureInfo.InvariantCulture)} {Id (value)})"); + } + + static void RecordDeadEviction (int key) + { + int count = Interlocked.Increment (ref deadEvictions); + AppContext.SetData (DeadEvictionsKey, + $"{count} (most recent: key=0x{key.ToString ("x", CultureInfo.InvariantCulture)})"); + } + public static void CollectPeers () { unsafe { @@ -81,6 +161,8 @@ void Remove (HandleContext* context) for (int i = peers.Count - 1; i >= 0; i--) { var peer = peers [i]; if (peer.BelongsToContext (context)) { + RecordIfLive (key, peer); + RecordDeadEviction (key); peers.RemoveAt (i); } } @@ -120,16 +202,44 @@ public static void AddPeer (IJavaPeerable value) continue; if (!JniEnvironment.Types.IsSameObject (target.PeerReference, value.PeerReference)) continue; - if (target.JniManagedPeerState.HasFlag (JniManagedPeerStates.Replaceable)) { + // JNIEnv.NewObject/JNIEnv.CreateInstance() compatibility. + // When two MCWs are created for one Java instance [0], we want the 2nd + // MCW to replace the 1st, as the 2nd is the one the dev created; the + // 1st is an implicit intermediary. + // + // Meanwhile, a new "replaceable" instance must *not* replace an existing + // "replaceable" instance; see dotnet/android#9862. Doing so orphans any + // already-cached reference to the existing peer -- notably + // `Application.Context`, which caches the peer it first sees and never + // re-reads it -- so `PeekPeer()` then hands out a different peer for the + // same Java instance; see dotnet/android#10973. + // + // This mirrors `AndroidRuntime.JavaObjectValueManager`; MonoVM has always + // had the second condition, which is why this only ever fails on CoreCLR. + // + // [0]: If a Java ctor invokes an overridden virtual method, we transition + // into managed code w/o a registered instance, and thus create an + // "intermediary" via the (IntPtr, JniHandleOwnership) .ctor. + if (target.JniManagedPeerState.HasFlag (JniManagedPeerStates.Replaceable) && + !value.JniManagedPeerState.HasFlag (JniManagedPeerStates.Replaceable)) { + RecordReplacement (key, target, value); peer.Dispose (); peers [i] = new ReferenceTrackingHandle (value); } else { - WarnNotReplacing (key, value, target); + RecordNotReplaced (key, target, value); + if (JniEnvironment.Runtime.ObjectReferenceManager.LogGlobalReferenceMessages) { + // Now a normal startup path rather than a rare one, and the + // arguments below are evaluated eagerly -- including two JNI + // round-trips for `GetJniTypeNameFromInstance()` -- even though + // `WriteGlobalReferenceLine()` discards them when logging is off. + WarnNotReplacing (key, value, target); + } } GC.KeepAlive (target); return; } + RecordDuplicateAppend (key, value, peers.Count); peers.Add (new ReferenceTrackingHandle (value)); } } @@ -192,6 +302,7 @@ public static void RemovePeer (IJavaPeerable value) ReferenceTrackingHandle peer = peers [i]; IJavaPeerable? target = peer.Target; if (ReferenceEquals (value, target)) { + RecordRemoved (key, value); peers.RemoveAt (i); peer.Dispose (); } diff --git a/tests/Mono.Android-Tests/Mono.Android-Tests/Android.Runtime/ContextPeerWatch.cs b/tests/Mono.Android-Tests/Mono.Android-Tests/Android.Runtime/ContextPeerWatch.cs new file mode 100644 index 00000000000..10fdccb1e3a --- /dev/null +++ b/tests/Mono.Android-Tests/Mono.Android-Tests/Android.Runtime/ContextPeerWatch.cs @@ -0,0 +1,58 @@ +using System; + +using Android.App; + +using Java.Interop; + +using NUnit.Framework; +using NUnit.Framework.Interfaces; + +[assembly: Android.RuntimeTests.ContextPeerWatchAttribute] + +namespace Android.RuntimeTests { + + // `Application.Context` caches one managed peer for the lifetime of the process, so + // `JniValueManager.PeekPeer()` should keep returning that same peer forever. On CoreCLR it + // intermittently stops doing so, and the first test to *notice* is + // `JnienvArrayMarshaling.GetObjectArray()` -- which is not necessarily the test that broke + // it. Diagnostics there confirmed the registry was already wrong on entry, so sample after + // every test to name the test we were actually running when it diverged. + [AttributeUsage (AttributeTargets.Assembly)] + public sealed class ContextPeerWatchAttribute : Attribute, ITestAction { + + // Only the *first* divergence is interesting; later tests just observe the same + // already-broken registry. Prefixed with "before"/"after" so a divergence that is + // already present when the very first test starts -- i.e. one that happened during + // app startup -- is distinguishable from one a test body caused. + public static string DivergedAfter; + + public ActionTargets Targets => ActionTargets.Test; + + public void BeforeTest (ITest test) + { + Check (test, "before"); + } + + public void AfterTest (ITest test) + { + Check (test, "after"); + } + + static void Check (ITest test, string when) + { + if (DivergedAfter != null) + return; + + var context = Application.Context; + if (context == null || !context.PeerReference.IsValid) + return; + + // `PeekPeer()` only reads the registry -- in particular it does not drain the + // collected-peer queue the way `GetSurfacedPeers()` does -- so sampling it this + // often does not itself perturb the behaviour under investigation. + var peeked = JniRuntime.CurrentRuntime.ValueManager.PeekPeer (context.PeerReference); + if (!ReferenceEquals (peeked, context)) + DivergedAfter = $"{when} {test.FullName}"; + } + } +} diff --git a/tests/Mono.Android-Tests/Mono.Android-Tests/Android.Runtime/JnienvArrayMarshaling.cs b/tests/Mono.Android-Tests/Mono.Android-Tests/Android.Runtime/JnienvArrayMarshaling.cs index 1d16aa30af0..520bef71037 100644 --- a/tests/Mono.Android-Tests/Mono.Android-Tests/Android.Runtime/JnienvArrayMarshaling.cs +++ b/tests/Mono.Android-Tests/Mono.Android-Tests/Android.Runtime/JnienvArrayMarshaling.cs @@ -1,5 +1,7 @@ using System; using System.Collections.Generic; +using System.Runtime.CompilerServices; +using System.Text; using Android.App; using Android.Content; @@ -7,6 +9,8 @@ using Android.Runtime; using Android.Views; +using Java.Interop; + using NUnit.Framework; using Java.LangTests; @@ -326,25 +330,130 @@ public void SetArrayItem_JavaLangString () [Category ("JNIObjectArray")] public void GetObjectArray () { + var context = Application.Context; + // Sample the registry at each step, so a failure says *when* `Application.Context` + // stopped being the registered peer rather than only that it did. + var atEntry = ProbeContextPeer (context); using (var byteArray = new Java.Lang.Object (JNIEnv.NewArray (new byte[]{1,2,3}), JniHandleOwnership.TransferLocalRef)) { object[] data = JNIEnv.GetObjectArray (byteArray.Handle, new[]{typeof (byte), typeof (byte), typeof (byte)}); AssertArrays ("GetObjectArray", data, (object) 1, (object) 2, (object) 3); } + var beforeNewArray = ProbeContextPeer (context); using (var objectArray = new Java.Lang.Object ( JNIEnv.NewArray ( - new Java.Lang.Object[]{Application.Context, 42L, "string"}, + new Java.Lang.Object[]{context, 42L, "string"}, typeof (Java.Lang.Object)), JniHandleOwnership.TransferLocalRef)) { + var afterNewArray = ProbeContextPeer (context); object[] values = JNIEnv.GetObjectArray (objectArray.Handle, new[]{typeof(Context), typeof (int)}); Assert.AreEqual (3, values.Length); - Assert.AreSame (Application.Context, values [0], $"Expected existing Context peer, got {values [0]?.GetType ()}."); + // Deliberately not `Assert.AreSame()`: this intermittently fails on CoreCLR + // (dotnet/android#10973), and both peers render identically, so the default + // message tells us nothing. Only build the diagnostic when it actually fails. + if (!ReferenceEquals (context, values [0])) + Assert.Fail (DescribeContextPeerMismatch (context, values [0], atEntry, beforeNewArray, afterNewArray)); Assert.IsInstanceOf (values [1], $"Expected converted Int32, got {values [1]?.GetType ()}: {values [1]}."); Assert.AreEqual (42, (int)values [1]); Assert.AreEqual ("string", values [2].ToString ()); } } + // What the registry reports for `Application.Context` at one point in time. Records a + // description rather than the peer itself: retaining the peer would keep it alive and + // could perturb the very GC behaviour being investigated. + readonly struct PeerProbe { + + readonly bool isExpected; + readonly string description; + + public PeerProbe (bool isExpected, string description) + { + this.isExpected = isExpected; + this.description = description; + } + + public override string ToString () + => $"{description} (is expected: {isExpected})"; + } + + static PeerProbe ProbeContextPeer (Context expected) + { + if (!expected.PeerReference.IsValid) + return new PeerProbe (false, ""); + var peeked = JniRuntime.CurrentRuntime.ValueManager.PeekPeer (expected.PeerReference); + return new PeerProbe (ReferenceEquals (peeked, expected), Describe (peeked)); + } + + // `GetObjectArray()` should hand back the *same* managed peer that `Application.Context` + // holds, because `JniValueManager.GetPeer()` peeks the registry before creating a new peer. + // When that fails, the Java instance is the same but the managed peers differ, so dump + // enough of the registry to tell *why* they disagree: whether the entry was replaced by a + // second `AddPeer()`, evicted entirely, or its weak reference was cleared. + static string DescribeContextPeerMismatch (Context expected, object actual, PeerProbe atEntry, PeerProbe beforeNewArray, PeerProbe afterNewArray) + { + var sb = new StringBuilder (); + sb.AppendLine ("Expected `Application.Context` and `GetObjectArray ()[0]` to be the same managed peer."); + AppendPeer (sb, "expected (Application.Context)", expected); + AppendPeer (sb, "actual (GetObjectArray ()[0])", actual); + + // The registry over time. If the peer was already wrong `atEntry`, something evicted + // or replaced it *before* this test ran and the marshaling is only the messenger. + sb.AppendLine (" PeekPeer (Application.Context) over time:"); + sb.AppendLine ($" at test entry: {atEntry}"); + sb.AppendLine ($" before NewArray: {beforeNewArray}"); + sb.AppendLine ($" after NewArray: {afterNewArray}"); + sb.AppendLine ($" Registry first diverged: {ContextPeerWatchAttribute.DivergedAfter ?? ""}"); + // Set by JavaMarshalRegisteredPeers: the registry can only disagree with a cached + // `Application.Context` if a second managed peer was created for the same Java + // instance, so report how that happened. + sb.AppendLine ($" CollectPeers() evicted live peers: {AppContext.GetData ("Microsoft.Android.Runtime.LivePeerEvictions") ?? ""}"); + sb.AppendLine ($" CollectPeers() evictions (total): {AppContext.GetData ("Microsoft.Android.Runtime.DeadPeerEvictions") ?? ""}"); + sb.AppendLine ($" AddPeer() replaced registrations: {AppContext.GetData ("Microsoft.Android.Runtime.PeerReplacements") ?? ""}"); + sb.AppendLine ($" AddPeer() appended duplicates: {AppContext.GetData ("Microsoft.Android.Runtime.PeerDuplicateAppends") ?? ""}"); + // Which peer registered *first* -- the kept one -- and which was turned away. + sb.AppendLine ($" AddPeer() declined to replace: {AppContext.GetData ("Microsoft.Android.Runtime.PeerNotReplaced") ?? ""}"); + sb.AppendLine ($" RemovePeer() removals: {AppContext.GetData ("Microsoft.Android.Runtime.PeerRemoved") ?? ""}"); + + // Did `Application.Context` itself change after we captured it? + sb.AppendLine ($" Application.Context still == expected: {ReferenceEquals (Application.Context, expected)}"); + + if (actual is IJavaPeerable actualPeer && expected.PeerReference.IsValid && actualPeer.PeerReference.IsValid) + sb.AppendLine ($" IsSameObject (expected, actual): {JniEnvironment.Types.IsSameObject (expected.PeerReference, actualPeer.PeerReference)}"); + + var manager = JniRuntime.CurrentRuntime.ValueManager; + + // If this returns `actual`, the registry entry was replaced out from under + // `Application.Context`; if it returns null, the entry was evicted or collected. + var peeked = expected.PeerReference.IsValid ? manager.PeekPeer (expected.PeerReference) : null; + sb.AppendLine ($" PeekPeer (expected.PeerReference) => {Describe (peeked)}"); + sb.AppendLine ($" is expected: {ReferenceEquals (peeked, expected)}; is actual: {ReferenceEquals (peeked, actual)}"); + + sb.AppendLine ($" Surfaced peers with JniIdentityHashCode=0x{expected.JniIdentityHashCode:x}:"); + foreach (var info in manager.GetSurfacedPeers ()) { + if (info.JniIdentityHashCode != expected.JniIdentityHashCode) + continue; + info.SurfacedPeer.TryGetTarget (out var target); + sb.AppendLine ($" {Describe (target)} (is expected: {ReferenceEquals (target, expected)}; is actual: {ReferenceEquals (target, actual)})"); + } + return sb.ToString (); + } + + static void AppendPeer (StringBuilder sb, string label, object value) + { + sb.AppendLine ($" {label}: {Describe (value)}"); + if (value is not IJavaPeerable peer) + return; + sb.AppendLine ($" JniIdentityHashCode=0x{peer.JniIdentityHashCode:x} PeerReference={peer.PeerReference} JniManagedPeerState={peer.JniManagedPeerState}"); + } + + // The Java-side `toString()` is identical for every peer over the same instance, so + // identify peers by their *managed* hash code instead. + static string Describe (object value) + => value == null + ? "" + : $"{value.GetType ().FullName}@managed-0x{RuntimeHelpers.GetHashCode (value):x}"; + [Test] public void NewArray_Int32ArrayArray () { diff --git a/tests/Mono.Android-Tests/Mono.Android-Tests/Mono.Android.NET-Tests.csproj b/tests/Mono.Android-Tests/Mono.Android-Tests/Mono.Android.NET-Tests.csproj index ee23c0b6f13..40e710d8d6b 100644 --- a/tests/Mono.Android-Tests/Mono.Android-Tests/Mono.Android.NET-Tests.csproj +++ b/tests/Mono.Android-Tests/Mono.Android-Tests/Mono.Android.NET-Tests.csproj @@ -129,6 +129,7 @@ +