You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
Context: dotnet/android#3706
A memory leak in an app is reported.
What Do We Do™? We enable GREF logging and use `logcat-parse`!
GREF logging is enabled via the `debug.mono.log` Android system
property, by having it include `gref`:
adb shell setprop debug.mono.log gref,timing,
When GREF logging is enabled, the app will write a `grefs.txt` file
into the `.__override__` directory. Launch the app, use it for
awhile, then extract the `grefs.txt` file:
adb shell run-as ActivityRecreateTest.ActivityRecreateTest cat files/.__override__/grefs.txt > grefs.txt
Once you have `grefs.txt`, use `logcat-parse.exe` to read it:
$ mono /Library/Frameworks/Xamarin.Android.framework/Versions/Current/lib/xamarin.android/xbuild/Xamarin/Android/logcat-parse.exe grefs.txt
# A different path is used on Windows, but it's still `logcat-parse.exe`
// `adb logcat` GREF parsing utility
//
// Use `Grefs.Parse(stream)` to parse a file containing `adb logcat` output.
// Grefs.AllocatedPeers contains all exposed Java.Lang.Object instances.
// Grefs.AlivePeers contains those still alive by the end of parsing.
var grefs = Grefs.Parse("grefs.txt");
That's when things get...weird:
csharp> grefs.GrefCount;
245
csharp> grefs.AlivePeers.Count();
18
There's a GREF count of 245, which matches what we can see within
`grefs.txt`, which has the following line toward the end:
+g+ grefc 245 gwrefc 0 obj-handle 0x79/I -> new-handle 0x2aa6/G from thread '(null)'(1)
...but there's only *18* peers? For 245 GREFs?
That does *not* make sense.
(It *is* possible to "alias" GREFs, but that's not very common in a
Xamarin.Android app, and the above would require ~14 GREFs per peer,
which is *very* unlikely.)
Turns Out™, `logcat-parse` has bugs!
![Bugs Everywhere][0]
~~ Initial Handle Reuse ~~
One of the problems was that the handle used when an instance entered
managed code could be *reused*:
+g+ grefc 11 gwrefc 0 obj-handle 0x71/L -> new-handle 0x266a/G from thread '(null)'(1)
...
+g+ grefc 15 gwrefc 0 obj-handle 0x71/I -> new-handle 0x26aa/G from thread '(null)'(1)
...
+g+ grefc 21 gwrefc 0 obj-handle 0x71/I -> new-handle 0x2786/G from thread '(null)'(1)
...
+g+ grefc 25 gwrefc 0 obj-handle 0x71/I -> new-handle 0x280a/G from thread '(null)'(1)
...
+g+ grefc 26 gwrefc 0 obj-handle 0x71/I -> new-handle 0x2816/G from thread '(null)'(1)
Note that `obj-handle 0x71` is present in *all* of these messages, but
they *all* refer to *different object instances*. However, because of
how `Grefs.GetPeerInfo()` and `PeerInfo.Handles` worked, they were all
associated with the same `PeerInfo` instance, because the *first*
`obj-handle 0x71` became the "owner" of all the *other*
`obj-handle 0x71` instances.
To address this, make two thanges to `Grefs` and `PeerInfo`:
1. Split up `PeerInfo.Handles` into `PeerInfo.Handles`, which
contains all *current* handles, and `PeerInfo.RemovedHandles`,
which contains all *previously seen but no longer valid*
JNI handles.
2. When creating a new `PeerInfo` instance, DO NOT use the
`obj-handle` value found in the `+g+` message. That is
*immediately* considered a `RemovedHandle` value.
These two changes prevent "accidental aliasing," in which
`logcat-parse` believes that two entirely unrelated JNI handles
actually belong to the same instance.
~~ Alive Peer Validation ~~
To help find related bugs, `GrefParseOptions` was overhauled so that
information about "Alive Peers" could be validated.
The semantics of `GrefParseOptions.CheckCounts` was altered so that
it's now a unique state; *just* specifying it won't do anything, it
needs to be combined with `GrefParseOptions.LogWarningOnMismatch` or
`GrefParseOptions.ThrowExceptionOnMismatch`, or continue using the
previously existing `GrefParseOptions.WarnOnCountMismatch` or
`GrefParseOptions.ThrowOnCountMismatch` options.
To these, we add:
partial enum GrefParseOptions {
CheckAlivePeers = 1 << 3,
WarnOnAlivePeerMismatch = CheckAlivePeers | LogWarningOnMismatch,
ThrowOnAlivePeerMismatch = CheckAlivePeers | ThrowExceptionOnMismatch,
}
You can enable Alive Peer validation by using the `Grefs.Parse()`
overload within `logcat-parse.exe`:
csharp> var grefs = Grefs.Parse ("grefs.txt", null, GrefParseOptions.ThrowOnAlivePeerMismatch);
which will cause an exception to be thrown when an "alive peer"
mismatch is encountered. This will happen when:
* A `Disposing handle` message is encountered, but no `PeerInfo` can
be found owning the specified handle.
* A `Finalizing.*handle` message is encountered, but no `PeerInfo`
can be found owning the specified handle.
* A ``handle HANDLE; key_handle HANDLE; Java Type: `...`; MCW Type: `...```
message is encountered, and (1) no `PeerInfo` can be found which
owns the specified handle, or (2) `PeerInfo.KeyHandle` has already
been set on the instance, and thus `logcat-parse` is erroneously
trying to *alter* an already-existing `PeerInfo` instance.
* A `-g-` message is encountered, and no `PeerInfo` can be found
which owns the specified GREF.
~~ Assorted Extras ~~
`JniHandleInfo` was updated so that a "full" handle can be used in
comparisons, e.g.:
grefs.AlivePeers.Count(p => p.Handles.Contains ("0x1234/G"));
Previously this wouldn't match, because the `0x1234/G` would be
compared against `0x1234` (no `/G`) in `JniHandleInfo.Handle`.
`PeerInfo.Handles` is now an `IList<JniHandleInfo>`, instead of an
`ISet<JniHandleInfo>`, so that we can now reason about *time*: earlier
entries will be created earlier in time, and the order of
`PeerInfo.Handles` and `PeerInfo.RemovedHandles` is the order
encountered within the log file.
~~ Result ~~
With the above changes, processing `grefs.txt` makes more sense:
$ mono /Library/Frameworks/Xamarin.Android.framework/Versions/Current/lib/xamarin.android/xbuild/Xamarin/Android/logcat-parse.exe grefs.txt
...
csharp> grefs.GrefCount;
245
csharp> grefs.AlivePeers.Count();
245
This in turn allows us to get appropriate type counts:
csharp> grefs.GetAliveJniTypeCounts();
{{ "", 14 },
{ "com/android/internal/os/RuntimeInit$KillApplicationHandler", 1 },
{ "android/runtime/UncaughtExceptionHandler", 1 },
{ "md5327d1d288bcaf8c0cc06d09d4b2f8e3a/MainActivity", 45 },
{ "android/support/v7/widget/Toolbar", 45 },
{ "android/support/design/widget/FloatingActionButton", 45 },
{ "android/support/v7/view/menu/MenuBuilder", 45 },
{ "android/support/v7/view/SupportMenuInflater", 45 },
{ "mono/android/view/View_OnClickListenerImplementor", 3 },
{ "android/os/Bundle", 1 }}
For this run, there are 45 `MainActivity` instances, along with
instances which `MainActivity` references, such as `ToolBar`,
`FloatingActionButton`, `MenuBuilder`, etc.
[0]: https://media.makeameme.org/created/bugs-bugs-everywhere-kyn0a3.jpg
LogWarning(GrefParseOptions.CheckAlivePeers,$"at line {l}: could not find PeerInfo for disposed handle {GetHandle(m,"handle")}");
132
+
return;
133
+
}
130
134
p.Disposed=true;
131
135
}},
132
136
{newRegex(fm),(m,l)=>{
133
-
varp=GetPeerInfo(m);
137
+
varp=GetAlivePeerInfo(m);
138
+
if(p==null){
139
+
LogWarning(GrefParseOptions.CheckAlivePeers,$"at line {l}: could not find PeerInfo for finalized handle {GetHandle(m,"handle")}");
140
+
return;
141
+
}
134
142
p.Finalized=true;
135
143
}},
136
144
{newRegex(hm),(m,l)=>{
137
-
varp=GetPeerInfo(m);
145
+
varp=GetAlivePeerInfo(m);
146
+
if(p==null){
147
+
LogWarning(GrefParseOptions.CheckAlivePeers,$"at line {l}: could not find PeerInfo for handle {GetHandle(m,"handle")}");
148
+
return;
149
+
}
150
+
if(!string.IsNullOrEmpty(p.KeyHandle)){
151
+
LogWarning(GrefParseOptions.CheckAlivePeers,$"at line {l}: Attempting to re-set p.KeyHandle {p.KeyHandle} for `{p.JniType}` to {m.Groups["key_handle"].Value} for {m.Groups["jtype"].Value}");
152
+
return;
153
+
}
138
154
p.KeyHandle=m.Groups["key_handle"].Value;
139
155
p.JniType=m.Groups["jtype"].Value;
140
156
p.McwType=m.Groups["mtype"].Value;
141
157
}},
142
158
{newRegex(remGm),(m,l)=>{
143
159
varh=GetHandle(m,"handle");
144
-
varp=GetPeerInfo(m);
160
+
varp=GetAlivePeerInfo(m);
161
+
if(p==null){
162
+
LogWarning(GrefParseOptions.CheckAlivePeers,$"at line {l}: could not find PeerInfo to remove gref for handle {h}");
0 commit comments