Skip to content

Commit

Permalink
[monodroid] Add new gref+, lref+ log options (#6543)
Browse files Browse the repository at this point in the history
Context: https://bugzilla.xamarin.com/25/25443/bug.html#c23
Context: xamarin/monodroid@bf9dc9e

Once upon a time, JNI Global Reference (GREF) and
JNI Local Reference (LREF) logging was written only to `adb logcat`.
This worked, until it didn't work; around Android 5.0,
[`__android_log_print()`][0] appeared to become "less reliable", and
`adb logcat` would no longer "reliably" contain all GREF messages.
We "fixed" this in xamarin/monodroid@bf9dc9ee (2015-Feb-6) by writing
GREF messages to `grefs.txt`.

While this improved reliability, there was a "usability" cost:
`grefs.txt` can only be accessed if the app is ["debuggable"][1],
which isn't necessarily easy (requires rebuilding from source), and
hinders diagnosis and review.

Add new `gref+` and `lref+` options, which re-introduce spamming
`adb logcat` with GREF and LREF messages:

	adb shell setprop debug.mono.log 'gref+,lref+'

This will allow non-debuggable apps to produce accessible GREF logs:

	adb logcat > log.txt &
	msbuild /t:StartAndroidActivity App.csproj

…and (again!) *spam* logcat:

	monodroid-gref: +g+ grefc 5 gwrefc 0 obj-handle 0x7fc13ebc70/I -> new-handle 0x29e6/G from thread '(null)'(1)
	monodroid-gref:   at Android.Runtime.AndroidObjectReferenceManager.CreateGlobalReference (Java.Interop.JniObjectReference value) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Java.Interop.JniObjectReference.NewGlobalRef () [0x00000] in <66190dc38bc34d07af752fceda80105a>:0
	monodroid-gref:   at Android.Runtime.JNIEnv.NewGlobalRef (System.IntPtr jobject) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Android.Runtime.AndroidValueManager.AddPeer (Java.Interop.IJavaPeerable value, System.IntPtr handle, Android.Runtime.JniHandleOwnership transfer, System.IntPtr& handleField) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Java.Lang.Object.SetHandle (System.IntPtr value, Android.Runtime.JniHandleOwnership transfer) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Java.Lang.Object..ctor (System.IntPtr handle, Android.Runtime.JniHandleOwnership transfer) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Android.Content.Context..ctor (System.IntPtr javaReference, Android.Runtime.JniHandleOwnership transfer) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Android.Content.ContextWrapper..ctor (System.IntPtr javaReference, Android.Runtime.JniHandleOwnership transfer) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Android.Views.ContextThemeWrapper..ctor (System.IntPtr javaReference, Android.Runtime.JniHandleOwnership transfer) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Android.App.Activity..ctor () [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at HelloWorld.MainActivity..ctor () [0x00000] in <01eae2bf5ab14181a2c9706cec17ab4e>:0
	monodroid-gref:   at Android.Runtime.DynamicMethodNameCounter.3 (System.IntPtr , System.Object[] ) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Java.Interop.TypeManager.Activate (Java.Interop.IJavaPeerable o, System.IntPtr jobject, System.Reflection.ConstructorInfo cinfo, System.Object[] parms) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Java.Interop.TypeManager.n_Activate (System.IntPtr jnienv, System.IntPtr jclass, System.IntPtr typename_ptr, System.IntPtr signature_ptr, System.IntPtr jobject, System.IntPtr parameters_ptr) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref:   at Android.Runtime.DynamicMethodNameCounter.2 (System.IntPtr , System.IntPtr , System.IntPtr , System.IntPtr , System.IntPtr , System.IntPtr ) [0x00000] in <31a674ae732f498eaa71dc8ffa7c6f81>:0
	monodroid-gref: handle 0x29e6; key_handle 0xc2ad59d: Java Type: `example/MainActivity`; MCW type: `HelloWorld.MainActivity`

The new `gref+` and `lref+` log categories should not be considered
to be "reliable"; message delivery is up to `adb logcat`, which has a
known history of skipping messages.  That said, this may be better
than nothing, which was the previous alternative.

[0]: https://developer.android.com/ndk/reference/group/logging#__android_log_print
[1]: https://developer.android.com/guide/topics/manifest/application-element#debug
  • Loading branch information
jonpryor committed Dec 3, 2021
1 parent 7dec1d5 commit 2e499bf
Show file tree
Hide file tree
Showing 5 changed files with 66 additions and 11 deletions.
18 changes: 16 additions & 2 deletions Documentation/workflow/SystemProperties.md
Expand Up @@ -118,16 +118,30 @@ categories:
* `gref`
Enable global reference logging and log messages to the default
`grefs.txt` file.
* `gref+`
Enable global reference logging, writing messages to `adb logcat`.
***Note***: this will spam `adb logcat`, possibly impacting app
performance, and Android might not preserve all messages.
This is provided as a "last ditch effort", and is not as reliable
as the normal `gref` or `gref=` options which write to a file.
Added in Xamarin.Android 12.2.
* `lref-`
Enable local reference logging but without writing the logged
messages to a file.
* `lref=FILE`
Enable global reference logging and write messages to the
Enable local reference logging and write messages to the
specified `FILE`
* `lref`
Enable global reference logging and log messages to the default
Enable local reference logging and log messages to the default
`lrefs.txt` file, unless `gref` or `gref=` are also present, in
which case messages will be logged to the `gref` file.
* `lref+`
Enable local reference logging, writing messages to `adb logcat`.
***Note***: this will spam `adb logcat`, possibly impacting app
performance, and Android might not preserve all messages.
This is provided as a "last ditch effort", and is not as reliable
as the normal `lref` or `lref=` options which write to a file.
Added in Xamarin.Android 12.2.
* `mono_log_level=LEVEL`
Set Mono runtime log level. The default value is `error` to log
only errors, unless `gc` or `assembly` log categories are enabled,
Expand Down
10 changes: 10 additions & 0 deletions src/monodroid/jni/logger.cc
Expand Up @@ -215,6 +215,11 @@ init_logging_categories (char*& mono_log_mask, char*& mono_log_level)
continue;
}

if (set_category ("gref+", param, LOG_GREF)) {
gref_to_logcat = true;
continue;
}

constexpr char CAT_LREF_EQUALS[] = "lref=";
constexpr size_t CAT_LREF_EQUALS_LEN = sizeof(CAT_LREF_EQUALS) - 1;
if (set_category (CAT_LREF_EQUALS, param, LOG_LREF, true /* arg_starts_with_name */)) {
Expand All @@ -227,6 +232,11 @@ init_logging_categories (char*& mono_log_mask, char*& mono_log_level)
continue;
}

if (set_category ("lref+", param, LOG_LREF)) {
lref_to_logcat = true;
continue;
}

if (param.starts_with ("timing=bare")) {
log_categories |= LOG_TIMING;
log_timing_categories |= LOG_TIMING_BARE;
Expand Down
2 changes: 2 additions & 0 deletions src/monodroid/jni/monodroid-glue.hh
Expand Up @@ -24,4 +24,6 @@ JNIEnv* get_jnienv (void);

extern FILE *gref_log;
extern FILE *lref_log;
extern bool gref_to_logcat;
extern bool lref_to_logcat;
#endif /* __MONODROID_GLUE_H */
45 changes: 37 additions & 8 deletions src/monodroid/jni/osbridge.cc
Expand Up @@ -32,6 +32,8 @@
// These two must stay here until JavaInterop is converted to C++
FILE *gref_log;
FILE *lref_log;
bool gref_to_logcat;
bool lref_to_logcat;

using namespace xamarin::android;
using namespace xamarin::android::internal;
Expand Down Expand Up @@ -208,7 +210,7 @@ OSBridge::_get_stack_trace_line_end (char *m)
}

void
OSBridge::_write_stack_trace (FILE *to, const char *from)
OSBridge::_write_stack_trace (FILE *to, char *from, LogCategories category)
{
char *n = const_cast<char*> (from);

Expand All @@ -220,15 +222,24 @@ OSBridge::_write_stack_trace (FILE *to, const char *from)
n = end + 1;
c = *end;
*end = '\0';
fprintf (to, "%s\n", m);
fflush (to);
if ((category == LOG_GREF && gref_to_logcat) ||
(category == LOG_LREF && lref_to_logcat)) {
log_debug (category, "%s", m);
}
if (to != nullptr) {
fprintf (to, "%s\n", m);
fflush (to);
}
*end = c;
} while (c);
}

void
OSBridge::_monodroid_gref_log (const char *message)
{
if (gref_to_logcat) {
log_debug (LOG_GREF, "%s", message);
}
if (!gref_log)
return;
fprintf (gref_log, "%s", message);
Expand All @@ -250,6 +261,9 @@ OSBridge::_monodroid_gref_log_new (jobject curHandle, char curType, jobject newH
newType,
threadName,
threadId);
if (gref_to_logcat) {
_write_stack_trace (nullptr, const_cast<char*>(from), LOG_GREF);
}
if (!gref_log)
return c;
fprintf (gref_log, "+g+ grefc %i gwrefc %i obj-handle %p/%c -> new-handle %p/%c from thread '%s'(%i)\n",
Expand Down Expand Up @@ -284,6 +298,9 @@ OSBridge::_monodroid_gref_log_delete (jobject handle, char type, const char *thr
type,
threadName,
threadId);
if (gref_to_logcat) {
_write_stack_trace (nullptr, const_cast<char*>(from), LOG_GREF);
}
if (!gref_log)
return;
fprintf (gref_log, "-g- grefc %i gwrefc %i handle %p/%c from thread '%s'(%i)\n",
Expand All @@ -294,7 +311,7 @@ OSBridge::_monodroid_gref_log_delete (jobject handle, char type, const char *thr
threadName,
threadId);
if (from_writable)
_write_stack_trace (gref_log, from);
_write_stack_trace (gref_log, const_cast<char*>(from));
else
fprintf (gref_log, "%s\n", from);

Expand All @@ -316,6 +333,9 @@ OSBridge::_monodroid_weak_gref_new (jobject curHandle, char curType, jobject new
newType,
threadName,
threadId);
if (gref_to_logcat) {
_write_stack_trace (nullptr, const_cast<char*>(from), LOG_GREF);
}
if (!gref_log)
return;
fprintf (gref_log, "+w+ grefc %i gwrefc %i obj-handle %p/%c -> new-handle %p/%c from thread '%s'(%i)\n",
Expand All @@ -328,7 +348,7 @@ OSBridge::_monodroid_weak_gref_new (jobject curHandle, char curType, jobject new
threadName,
threadId);
if (from_writable)
_write_stack_trace (gref_log, from);
_write_stack_trace (gref_log, const_cast<char*>(from));
else
fprintf (gref_log, "%s\n", from);

Expand All @@ -348,6 +368,9 @@ OSBridge::_monodroid_weak_gref_delete (jobject handle, char type, const char *th
type,
threadName,
threadId);
if (gref_to_logcat) {
_write_stack_trace (nullptr, const_cast<char*>(from), LOG_GREF);
}
if (!gref_log)
return;
fprintf (gref_log, "-w- grefc %i gwrefc %i handle %p/%c from thread '%s'(%i)\n",
Expand All @@ -358,7 +381,7 @@ OSBridge::_monodroid_weak_gref_delete (jobject handle, char type, const char *th
threadName,
threadId);
if (from_writable)
_write_stack_trace (gref_log, from);
_write_stack_trace (gref_log, const_cast<char*>(from));
else
fprintf (gref_log, "%s\n", from);

Expand All @@ -376,6 +399,9 @@ OSBridge::_monodroid_lref_log_new (int lrefc, jobject handle, char type, const c
type,
threadName,
threadId);
if (lref_to_logcat) {
_write_stack_trace (nullptr, const_cast<char*>(from), LOG_LREF);
}
if (!lref_log)
return;
fprintf (lref_log, "+l+ lrefc %i handle %p/%c from thread '%s'(%i)\n",
Expand All @@ -385,7 +411,7 @@ OSBridge::_monodroid_lref_log_new (int lrefc, jobject handle, char type, const c
threadName,
threadId);
if (from_writable)
_write_stack_trace (lref_log, from);
_write_stack_trace (lref_log, const_cast<char*>(from));
else
fprintf (lref_log, "%s\n", from);

Expand All @@ -403,6 +429,9 @@ OSBridge::_monodroid_lref_log_delete (int lrefc, jobject handle, char type, cons
type,
threadName,
threadId);
if (lref_to_logcat) {
_write_stack_trace (nullptr, const_cast<char*>(from), LOG_LREF);
}
if (!lref_log)
return;
fprintf (lref_log, "-l- lrefc %i handle %p/%c from thread '%s'(%i)\n",
Expand All @@ -412,7 +441,7 @@ OSBridge::_monodroid_lref_log_delete (int lrefc, jobject handle, char type, cons
threadName,
threadId);
if (from_writable)
_write_stack_trace (lref_log, from);
_write_stack_trace (lref_log, const_cast<char*>(from));
else
fprintf (lref_log, "%s\n", from);

Expand Down
2 changes: 1 addition & 1 deletion src/monodroid/jni/osbridge.hh
Expand Up @@ -135,7 +135,7 @@ namespace xamarin::android::internal
int _monodroid_gref_inc ();
int _monodroid_gref_dec ();
char* _get_stack_trace_line_end (char *m);
void _write_stack_trace (FILE *to, const char *from);
void _write_stack_trace (FILE *to, char *from, LogCategories = LOG_NONE);
mono_bool take_global_ref_2_1_compat (JNIEnv *env, MonoObject *obj);
mono_bool take_weak_global_ref_2_1_compat (JNIEnv *env, MonoObject *obj);
mono_bool take_global_ref_jni (JNIEnv *env, MonoObject *obj);
Expand Down

0 comments on commit 2e499bf

Please sign in to comment.