Skip to content

Commit d0bc88d

Browse files
grendellogrendello
committed
Spiff up method JIT tracing a bit
1 parent 715a36a commit d0bc88d

File tree

7 files changed

+241
-42
lines changed

7 files changed

+241
-42
lines changed

‎src/native/monodroid/CMakeLists.txt‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -108,6 +108,7 @@ set(XAMARIN_MONODROID_SOURCES
108108
monodroid-tracing.cc
109109
monovm-properties.cc
110110
osbridge.cc
111+
performance-methods.cc
111112
runtime-util.cc
112113
timezones.cc
113114
xamarin_getifaddrs.cc

‎src/native/monodroid/monodroid-glue-internal.hh‎

Lines changed: 20 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010
#include "osbridge.hh"
1111
#include "timing.hh"
1212
#include "cpp-util.hh"
13+
#include "performance-methods.hh"
1314
#include "xxhash.hh"
1415
#include "monodroid-dl.hh"
1516

@@ -59,6 +60,14 @@ namespace xamarin::android::internal
5960
Signals = 0x08,
6061
};
6162

63+
enum class MethodEvent
64+
{
65+
JitBegin,
66+
JitFailed,
67+
JitDone,
68+
Enter,
69+
};
70+
6271
class MonodroidRuntime
6372
{
6473
using load_assemblies_context_type = MonoAssemblyLoadContextGCHandle;
@@ -146,6 +155,7 @@ namespace xamarin::android::internal
146155
void propagate_uncaught_exception (JNIEnv *env, jobject javaThread, jthrowable javaException);
147156
char* get_java_class_name_for_TypeManager (jclass klass);
148157
void log_traces (JNIEnv *env, TraceKind kind, const char *first_line) noexcept;
158+
void dump_method_events ();
149159

150160
private:
151161
static void mono_log_handler (const char *log_domain, const char *log_level, const char *message, mono_bool fatal, void *user_data);
@@ -212,12 +222,18 @@ namespace xamarin::android::internal
212222
void set_trace_options ();
213223
void set_profile_options ();
214224

215-
void log_jit_event (MonoMethod *method, const char *event_name);
225+
void log_method_event (MonoMethod *method, MethodEvent event);
216226
static void jit_begin (MonoProfiler *prof, MonoMethod *method);
217227
static void jit_failed (MonoProfiler *prof, MonoMethod *method);
218228
static void jit_done (MonoProfiler *prof, MonoMethod *method, MonoJitInfo* jinfo);
219229
static void thread_start (MonoProfiler *prof, uintptr_t tid);
220230
static void thread_end (MonoProfiler *prof, uintptr_t tid);
231+
static void prof_method_begin_invoke (MonoProfiler *prof, MonoMethod *method) noexcept;
232+
static void prof_method_end_invoke (MonoProfiler *prof, MonoMethod *method) noexcept;
233+
static void prof_method_enter (MonoProfiler *prof, MonoMethod *method, MonoProfilerCallContext *context) noexcept;
234+
static void prof_method_leave (MonoProfiler *prof, MonoMethod *method, MonoProfilerCallContext *context) noexcept;
235+
static MonoProfilerCallInstrumentationFlags prof_method_filter (MonoProfiler *prof, MonoMethod *method) noexcept;
236+
221237
#if !defined (RELEASE)
222238
static MonoReflectionType* typemap_java_to_managed (MonoString *java_type_name) noexcept;
223239
static const char* typemap_managed_to_java (MonoReflectionType *type, const uint8_t *mvid) noexcept;
@@ -252,7 +268,6 @@ namespace xamarin::android::internal
252268
jmethodID java_System_identityHashCode;
253269
jmethodID Class_getName;
254270
jclass java_TimeZone;
255-
timing_period jit_time;
256271
FILE *jit_log;
257272
MonoProfilerHandle profiler_handle;
258273

@@ -274,6 +289,9 @@ namespace xamarin::android::internal
274289

275290
static MonoCoreRuntimeProperties monovm_core_properties;
276291
MonovmRuntimeConfigArguments runtime_config_args;
292+
293+
std::unique_ptr<method_event_map_t> method_event_map{};
294+
static inline std::unique_ptr<xamarin::android::mutex> method_event_map_write_lock;
277295
};
278296
}
279297
#endif

‎src/native/monodroid/monodroid-glue.cc‎

Lines changed: 95 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -102,37 +102,93 @@ MonodroidRuntime::thread_end ([[maybe_unused]] MonoProfiler *prof, [[maybe_unuse
102102
}
103103

104104
inline void
105-
MonodroidRuntime::log_jit_event (MonoMethod *method, const char *event_name)
105+
MonodroidRuntime::log_method_event (MonoMethod *method, MethodEvent event)
106106
{
107-
jit_time.mark_end ();
108-
109-
if (jit_log == nullptr)
107+
if (!method_event_map) [[unlikely]] {
110108
return;
109+
}
110+
111+
char* name = mono_method_full_name (method, TRUE);
112+
hash_t name_hash = xxhash::hash (name, strlen (name));
111113

112-
char* name = mono_method_full_name (method, 1);
114+
lock_guard write_lock { *method_event_map_write_lock.get () };
113115

114-
timing_diff diff (jit_time);
115-
fprintf (jit_log, "JIT method %6s: %s elapsed: %lis:%u::%u\n", event_name, name, static_cast<long>(diff.sec), diff.ms, diff.ns);
116+
auto iter = method_event_map->find (name_hash);
117+
if (iter == method_event_map->end ()) {
118+
(*method_event_map)[name_hash] = MethodEventRecord {
119+
.method_name_hash = name_hash,
120+
.method_name = name,
121+
};
122+
}
116123

117-
free (name);
124+
MethodEventRecord &record = method_event_map->at (name_hash);
125+
switch (event) {
126+
case MethodEvent::JitBegin:
127+
record.jit_elapsed.mark_start ();
128+
record.state |= MethodEventRecord::JitStateStarted;
129+
break;
130+
131+
case MethodEvent::JitDone:
132+
record.state |= MethodEventRecord::JitStateSuccess;
133+
[[fallthrough]];
134+
135+
case MethodEvent::JitFailed:
136+
record.jit_elapsed.mark_end ();
137+
record.state |= MethodEventRecord::JitStateCompleted;
138+
break;
139+
140+
case MethodEvent::Enter:
141+
record.invocation_count++;
142+
break;
143+
}
118144
}
119145

120146
void
121147
MonodroidRuntime::jit_begin ([[maybe_unused]] MonoProfiler *prof, MonoMethod *method)
122148
{
123-
monodroidRuntime.log_jit_event (method, "begin");
149+
monodroidRuntime.log_method_event (method, MethodEvent::JitBegin);
124150
}
125151

126152
void
127153
MonodroidRuntime::jit_failed ([[maybe_unused]] MonoProfiler *prof, MonoMethod *method)
128154
{
129-
monodroidRuntime.log_jit_event (method, "failed");
155+
monodroidRuntime.log_method_event (method, MethodEvent::JitFailed);
130156
}
131157

132158
void
133159
MonodroidRuntime::jit_done ([[maybe_unused]] MonoProfiler *prof, MonoMethod *method, [[maybe_unused]] MonoJitInfo* jinfo)
134160
{
135-
monodroidRuntime.log_jit_event (method, "done");
161+
monodroidRuntime.log_method_event (method, MethodEvent::JitDone);
162+
}
163+
164+
// This is called only for `mono_runtime_invoke`
165+
void
166+
MonodroidRuntime::prof_method_begin_invoke ([[maybe_unused]] MonoProfiler *prof, MonoMethod *method) noexcept
167+
{
168+
monodroidRuntime.log_method_event (method, MethodEvent::Enter);
169+
}
170+
171+
void
172+
MonodroidRuntime::prof_method_end_invoke ([[maybe_unused]] MonoProfiler *prof, MonoMethod *method) noexcept
173+
{}
174+
175+
// This is called only when the interpreter is used
176+
void
177+
MonodroidRuntime::prof_method_enter ([[maybe_unused]] MonoProfiler *prof, MonoMethod *method, [[maybe_unused]] MonoProfilerCallContext *context) noexcept
178+
{
179+
log_debug (LOG_ASSEMBLY, "prof_method_enter");
180+
monodroidRuntime.log_method_event (method, MethodEvent::Enter);
181+
}
182+
183+
void
184+
MonodroidRuntime::prof_method_leave ([[maybe_unused]] MonoProfiler *prof, MonoMethod *method, [[maybe_unused]] MonoProfilerCallContext *context) noexcept
185+
{}
186+
187+
MonoProfilerCallInstrumentationFlags
188+
MonodroidRuntime::prof_method_filter ([[maybe_unused]] MonoProfiler *prof, [[maybe_unused]] MonoMethod *method) noexcept
189+
{
190+
return MONO_PROFILER_CALL_INSTRUMENTATION_ENTER |
191+
MONO_PROFILER_CALL_INSTRUMENTATION_LEAVE;
136192
}
137193

138194
#ifndef RELEASE
@@ -631,9 +687,11 @@ MonodroidRuntime::mono_runtime_init ([[maybe_unused]] JNIEnv *env, [[maybe_unuse
631687

632688
bool log_methods = FastTiming::enabled () && !FastTiming::is_bare_mode ();
633689
if (log_methods) [[unlikely]] {
690+
log_debug (LOG_ASSEMBLY, "Enabling method logging");
634691
std::unique_ptr<char> jit_log_path {Util::path_combine (AndroidSystem::override_dirs [0], "methods.txt")};
692+
log_debug (LOG_ASSEMBLY, "JIT log path: %s", jit_log_path.get ());
635693
Util::create_directory (AndroidSystem::override_dirs [0], 0755);
636-
jit_log = Util::monodroid_fopen (jit_log_path.get (), "a");
694+
jit_log = Util::monodroid_fopen (jit_log_path.get (), "w");
637695
Util::set_world_accessable (jit_log_path.get ());
638696
}
639697

@@ -642,10 +700,31 @@ MonodroidRuntime::mono_runtime_init ([[maybe_unused]] JNIEnv *env, [[maybe_unuse
642700
mono_profiler_set_thread_stopped_callback (profiler_handle, thread_end);
643701

644702
if (log_methods) [[unlikely]]{
645-
jit_time.mark_start ();
703+
method_event_map_write_lock = std::make_unique<mutex> ();
704+
method_event_map = std::make_unique<method_event_map_t> ();
705+
646706
mono_profiler_set_jit_begin_callback (profiler_handle, jit_begin);
647707
mono_profiler_set_jit_done_callback (profiler_handle, jit_done);
648708
mono_profiler_set_jit_failed_callback (profiler_handle, jit_failed);
709+
mono_profiler_set_method_begin_invoke_callback (profiler_handle, prof_method_begin_invoke);
710+
mono_profiler_set_method_end_invoke_callback (profiler_handle, prof_method_end_invoke);
711+
712+
// The method enter/leave callbacks are supported only when the interpreter is used.
713+
switch (AndroidSystem::get_mono_aot_mode ()) {
714+
case MonoAotMode::MONO_AOT_MODE_INTERP:
715+
case MonoAotMode::MONO_AOT_MODE_INTERP_ONLY:
716+
case MonoAotMode::MONO_AOT_MODE_INTERP_LLVMONLY:
717+
case MonoAotMode::MONO_AOT_MODE_LLVMONLY_INTERP:
718+
log_debug (LOG_ASSEMBLY, "Enabling method enter/leave profiler callbacks");
719+
mono_profiler_set_call_instrumentation_filter_callback (profiler_handle, prof_method_filter);
720+
mono_profiler_set_method_enter_callback (profiler_handle, prof_method_enter);
721+
mono_profiler_set_method_leave_callback (profiler_handle, prof_method_leave);
722+
break;
723+
724+
default:
725+
// Other AOT modes are ignored
726+
break;
727+
}
649728
}
650729

651730
parse_gdb_options ();
@@ -1624,11 +1703,11 @@ MonodroidRuntime::Java_mono_android_Runtime_register (JNIEnv *env, jstring manag
16241703
JNIEXPORT void
16251704
JNICALL Java_mono_android_Runtime_dumpTimingData ([[maybe_unused]] JNIEnv *env, [[maybe_unused]] jclass klass)
16261705
{
1627-
if (internal_timing == nullptr) {
1628-
return;
1706+
if (internal_timing != nullptr) {
1707+
internal_timing->dump ();
16291708
}
16301709

1631-
internal_timing->dump ();
1710+
monodroidRuntime.dump_method_events ();
16321711
}
16331712

16341713
JNIEXPORT void

‎src/native/monodroid/performance-methods.cc‎

Lines changed: 77 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,77 @@
1+
#include <cstdlib>
2+
#include <inttypes.h>
3+
4+
#include "cppcompat.hh"
5+
#include "logger.hh"
6+
#include "monodroid-glue-internal.hh"
7+
#include "performance-methods.hh"
8+
9+
using namespace xamarin::android::internal;
10+
11+
namespace {
12+
const char *jit_state_description (uint32_t status) noexcept
13+
{
14+
if ((status & MethodEventRecord::JitStateStarted) != MethodEventRecord::JitStateStarted) {
15+
return "never JIT-ed";
16+
}
17+
18+
if ((status & MethodEventRecord::JitStateCompleted) != MethodEventRecord::JitStateCompleted) {
19+
return "started but not completed";
20+
}
21+
22+
if ((status & MethodEventRecord::JitStateSuccess) == MethodEventRecord::JitStateSuccess) {
23+
return "success";
24+
}
25+
26+
return "failure";
27+
}
28+
}
29+
30+
void
31+
MonodroidRuntime::dump_method_events ()
32+
{
33+
if (!method_event_map) {
34+
return;
35+
}
36+
37+
log_debug (LOG_ASSEMBLY, "Dumping method events");
38+
lock_guard<mutex> write_mutex { *method_event_map_write_lock.get () };
39+
40+
mono_profiler_set_jit_begin_callback (profiler_handle, nullptr);
41+
mono_profiler_set_jit_done_callback (profiler_handle, nullptr);
42+
mono_profiler_set_jit_failed_callback (profiler_handle, nullptr);
43+
44+
fprintf (
45+
jit_log,
46+
R"(<?xml version="1.0" encoding="utf-8"?>)
47+
<methods count="%zu">
48+
)",
49+
method_event_map->size ()
50+
);
51+
52+
for (auto item : *method_event_map.get ()) {
53+
MethodEventRecord &record = item.second;
54+
bool was_jited = (record.state & MethodEventRecord::JitStateStarted) == MethodEventRecord::JitStateStarted;
55+
timing_diff diff { record.jit_elapsed };
56+
57+
fprintf (
58+
jit_log,
59+
R"( <method name="%s" invocation_count="%)" PRIu64 R"(" jit_time="%li:%u::%u" jit_status="%s" />
60+
)",
61+
record.method_name,
62+
record.invocation_count,
63+
was_jited ? static_cast<long>(diff.sec) : 0,
64+
was_jited ? diff.ms : 0,
65+
was_jited ? diff.ns : 0,
66+
jit_state_description (record.state)
67+
);
68+
::free (static_cast<void*>(const_cast<char *>(record.method_name)));
69+
record.method_name = nullptr;
70+
}
71+
72+
method_event_map->clear ();
73+
fprintf (jit_log, "</methods>\n");
74+
fflush (jit_log);
75+
fclose (jit_log);
76+
jit_log = nullptr;
77+
}

‎src/native/monodroid/performance-methods.hh‎

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,22 @@
1+
#pragma once
2+
3+
#include "timing.hh"
4+
#include "xxhash.hh"
5+
#include "robin_map.hh"
6+
7+
namespace xamarin::android::internal {
8+
struct MethodEventRecord
9+
{
10+
static inline constexpr uint32_t JitStateStarted = 0x01u;
11+
static inline constexpr uint32_t JitStateCompleted = 0x02u;
12+
static inline constexpr uint32_t JitStateSuccess = 0x04u;
13+
14+
uint32_t state = 0u;
15+
uint64_t invocation_count = 0u;
16+
hash_t method_name_hash = 0u;
17+
const char* method_name = nullptr;
18+
timing_period jit_elapsed {};
19+
};
20+
21+
using method_event_map_t = tsl::robin_map<hash_t, MethodEventRecord>;
22+
}

‎src/native/pinvoke-override/pinvoke-override-api.hh‎

Lines changed: 1 addition & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -3,32 +3,9 @@
33
#include <string>
44

55
#include "cppcompat.hh"
6+
#include "robin_map.hh"
67
#include "xxhash.hh"
78

8-
// NDEBUG causes robin_map.h not to include <iostream> which, in turn, prevents indirect inclusion of <mutex>. <mutex>
9-
// conflicts with our std::mutex definition in cppcompat.hh
10-
#if !defined (NDEBUG)
11-
#define NDEBUG
12-
#define NDEBUG_UNDEFINE
13-
#endif
14-
15-
// hush some compiler warnings
16-
#if defined (__clang__)
17-
#pragma clang diagnostic push
18-
#pragma clang diagnostic ignored "-Wunused-parameter"
19-
#endif // __clang__
20-
21-
#include <tsl/robin_map.h>
22-
23-
#if defined (__clang__)
24-
#pragma clang diagnostic pop
25-
#endif // __clang__
26-
27-
#if defined (NDEBUG_UNDEFINE)
28-
#undef NDEBUG
29-
#undef NDEBUG_UNDEFINE
30-
#endif
31-
329
namespace xamarin::android {
3310
struct PinvokeEntry
3411
{

0 commit comments

Comments
 (0)