static MonoProfileMethodFunc jit_start;
static MonoProfileMethodResult jit_end;
static MonoProfileMethodResult man_unman_transition;
+static MonoProfileAllocFunc allocation_cb;
static MonoProfileMethodFunc method_enter;
static MonoProfileMethodFunc method_leave;
man_unman_transition = callback;
}
+void
+mono_profiler_install_allocation (MonoProfileAllocFunc callback)
+{
+ allocation_cb = callback;
+}
+
void
mono_profiler_install_appdomain (MonoProfileAppDomainFunc start_load, MonoProfileAppDomainResult end_load,
MonoProfileAppDomainFunc start_unload, MonoProfileAppDomainFunc end_unload)
man_unman_transition (current_profiler, method, result);
}
+void
+mono_profiler_allocation (MonoObject *obj, MonoClass *klass)
+{
+ if ((mono_profiler_events & MONO_PROFILE_ALLOCATIONS) && allocation_cb)
+ allocation_cb (current_profiler, obj, klass);
+}
+
void
-mono_profiler_thread_start (HANDLE thread)
+mono_profiler_thread_start (guint32 tid)
{
if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_start)
- thread_start (current_profiler, thread);
+ thread_start (current_profiler, tid);
}
void
-mono_profiler_thread_end (HANDLE thread)
+mono_profiler_thread_end (guint32 tid)
{
if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_end)
- thread_end (current_profiler, thread);
+ thread_end (current_profiler, tid);
}
void
*/
#define USE_X86TSC 0
+#define USE_WIN32COUNTER 0
#if USE_X86TSC
typedef struct {
#define MONO_TIMER_STOP(t) rdtsc ((t).lowe, (t).highe);
#define MONO_TIMER_ELAPSED(t) rdtsc_elapsed (&(t))
+#elif USE_WIN32COUNTER
+#include <windows.h>
+
+typedef struct {
+ LARGE_INTEGER start, stop;
+} MonoWin32Timer;
+
+static int freq;
+
+static double
+win32_elapsed (MonoWin32Timer *t)
+{
+ LONGLONG diff = t->stop.QuadPart - t->start.QuadPart;
+ return ((double)diff / freq) / 1000000; /* have to return the result in seconds */
+}
+
+static int
+have_win32counter (void) {
+ LARGE_INTEGER f;
+
+ if (!QueryPerformanceFrequency (&f))
+ return 0;
+ return f.LowPart;
+}
+
+#define MONO_TIMER_STARTUP \
+ if (!(freq = have_win32counter ())) g_error ("Compiled with Win32 counter support, but none found");
+#define MONO_TIMER_TYPE MonoWin32Timer
+#define MONO_TIMER_INIT(t)
+#define MONO_TIMER_DESTROY(t)
+#define MONO_TIMER_START(t) QueryPerformanceCounter (&(t).start)
+#define MONO_TIMER_STOP(t) QueryPerformanceCounter (&(t).stop)
+#define MONO_TIMER_ELAPSED(t) win32_elapsed (&(t))
+
#else
+typedef struct {
+ GTimeVal start, stop;
+} MonoGLibTimer;
+
+static double
+timeval_elapsed (MonoGLibTimer *t)
+{
+ if (t->start.tv_usec > t->stop.tv_usec) {
+ t->stop.tv_usec += G_USEC_PER_SEC;
+ t->stop.tv_sec--;
+ }
+ return (t->stop.tv_sec - t->start.tv_sec)
+ + ((double)(t->stop.tv_usec - t->start.tv_usec))/ G_USEC_PER_SEC;
+}
+
#define MONO_TIMER_STARTUP
-#define MONO_TIMER_TYPE GTimer *
-#define MONO_TIMER_INIT(t) (t) = g_timer_new ()
-#define MONO_TIMER_DESTROY(t) g_timer_destroy ((t))
-#define MONO_TIMER_START(t) g_timer_start ((t))
-#define MONO_TIMER_STOP(t) g_timer_stop ((t))
-#define MONO_TIMER_ELAPSED(t) g_timer_elapsed ((t), NULL)
+#define MONO_TIMER_TYPE MonoGLibTimer
+#define MONO_TIMER_INIT(t)
+#define MONO_TIMER_DESTROY(t)
+#define MONO_TIMER_START(t) g_get_current_time (&(t).start)
+#define MONO_TIMER_STOP(t) g_get_current_time (&(t).stop)
+#define MONO_TIMER_ELAPSED(t) timeval_elapsed (&(t))
#endif
+typedef struct _AllocInfo AllocInfo;
+typedef struct _CallerInfo CallerInfo;
+
struct _MonoProfiler {
GHashTable *methods;
- GHashTable *newobjs;
MONO_TIMER_TYPE jit_timer;
double jit_time;
int methods_jitted;
+ GSList *callers;
+ /* allocations unassigned to an IL method */
+ AllocInfo *alloc_info;
};
typedef struct {
} u;
guint64 count;
double total;
+ AllocInfo *alloc_info;
+ CallerInfo *caller_info;
} MethodProfile;
+typedef struct _MethodCallProfile MethodCallProfile;
+
+struct _MethodCallProfile {
+ MethodCallProfile *next;
+ MONO_TIMER_TYPE timer;
+ MonoMethod *method;
+};
+
+struct _AllocInfo {
+ AllocInfo *next;
+ MonoClass *klass;
+ guint count;
+ guint mem;
+};
+
+struct _CallerInfo {
+ CallerInfo *next;
+ MonoMethod *caller;
+ guint count;
+};
+
static gint
compare_profile (MethodProfile *profa, MethodProfile *profb)
{
*funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_profile);
}
+static char*
+method_get_name (MonoMethod* method)
+{
+ char *sig, *res;
+
+ sig = mono_signature_get_desc (method->signature, FALSE);
+ res = g_strdup_printf ("%s.%s::%s(%s)", method->klass->name_space, method->klass->name,
+ method->name, sig);
+ g_free (sig);
+ return res;
+}
+
+static void output_callers (MethodProfile *p);
+
static void
output_profile (GList *funcs)
{
GList *tmp;
MethodProfile *p;
- char buf [256];
- char *sig;
+ char *m;
+ guint64 total_calls = 0;
if (funcs)
- g_print ("Method name\t\t\t\t\tTotal (ms) Calls Per call (ms)\n");
+ g_print ("Time(ms) Count P/call(ms) Method name\n");
for (tmp = funcs; tmp; tmp = tmp->next) {
p = tmp->data;
+ total_calls += p->count;
if (!(gint)(p->total*1000))
continue;
- sig = mono_signature_get_desc (p->u.method->signature, FALSE);
- g_snprintf (buf, sizeof (buf), "%s.%s::%s(%s)",
- p->u.method->klass->name_space, p->u.method->klass->name,
- p->u.method->name, sig);
- g_free (sig);
- printf ("%-52s %7d %7llu %7d\n", buf,
- (gint)(p->total*1000), p->count, (gint)((p->total*1000)/p->count));
+ m = method_get_name (p->u.method);
+ printf ("########################\n% 8.3f %7llu % 8.3f %s\n",
+ (double)(p->total*1000), p->count, (double)(p->total*1000)/(double)p->count, m);
+ g_free (m);
+ /* callers */
+ output_callers (p);
}
+ printf ("Total number of calls: %lld\n", total_calls);
}
typedef struct {
- MonoClass *klass;
+ MethodProfile *mp;
guint count;
} NewobjProfile;
}
static void
-build_newobj_profile (MonoClass *class, gpointer count, GList **funcs)
+build_newobj_profile (MonoClass *class, MethodProfile *mprof, GList **funcs)
{
NewobjProfile *prof = g_new (NewobjProfile, 1);
- prof->klass = class;
- prof->count = GPOINTER_TO_UINT (count);
+ AllocInfo *tmp;
+ guint count = 0;
+
+ prof->mp = mprof;
+ /* we use the total amount of memory to sort */
+ for (tmp = mprof->alloc_info; tmp; tmp = tmp->next)
+ count += tmp->mem;
+ prof->count = count;
*funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_newobj_profile);
}
+static int
+compare_caller (CallerInfo *a, CallerInfo *b)
+{
+ return b->count - a->count;
+}
+
+static int
+compare_alloc (AllocInfo *a, AllocInfo *b)
+{
+ return b->mem - a->mem;
+}
+
+static GSList*
+sort_alloc_list (AllocInfo *ai)
+{
+ GSList *l = NULL;
+ AllocInfo *tmp;
+ for (tmp = ai; tmp; tmp = tmp->next) {
+ l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_alloc);
+ }
+ return l;
+}
+
+static GSList*
+sort_caller_list (CallerInfo *ai)
+{
+ GSList *l = NULL;
+ CallerInfo *tmp;
+ for (tmp = ai; tmp; tmp = tmp->next) {
+ l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_caller);
+ }
+ return l;
+}
+
+static void
+output_callers (MethodProfile *p) {
+ guint total_callers, percent;
+ GSList *sorted, *tmps;
+ CallerInfo *cinfo;
+ char *m;
+
+ g_print (" Callers (with count) that contribute at least for 1%%:\n");
+ total_callers = 0;
+ for (cinfo = p->caller_info; cinfo; cinfo = cinfo->next) {
+ total_callers += cinfo->count;
+ }
+ sorted = sort_caller_list (p->caller_info);
+ for (tmps = sorted; tmps; tmps = tmps->next) {
+ cinfo = tmps->data;
+ percent = (cinfo->count * 100)/total_callers;
+ if (percent < 1)
+ continue;
+ m = method_get_name (cinfo->caller);
+ g_print (" %8d % 3d %% %s\n", cinfo->count, percent, m);
+ g_free (m);
+ }
+}
+
static void
output_newobj_profile (GList *proflist)
{
GList *tmp;
NewobjProfile *p;
+ MethodProfile *mp;
+ AllocInfo *ainfo;
MonoClass *klass;
const char* isarray;
char buf [256];
+ char *m;
+ guint total = 0;
+ GSList *sorted, *tmps;
+
+ g_print ("\nAllocation profiler\n");
if (proflist)
- g_print ("\n%-52s %9s\n", "Objects created:", "count");
+ g_print ("%-9s %s\n", "Total mem", "Method");
for (tmp = proflist; tmp; tmp = tmp->next) {
p = tmp->data;
- klass = p->klass;
- if (strcmp (klass->name, "Array") == 0) {
- isarray = "[]";
- klass = klass->element_class;
- } else {
- isarray = "";
+ total += p->count;
+ if (p->count < 50000)
+ continue;
+ mp = p->mp;
+ m = method_get_name (mp->u.method);
+ g_print ("########################\n%8d KB %s\n", p->count / 1024, m);
+ g_free (m);
+ sorted = sort_alloc_list (mp->alloc_info);
+ for (tmps = sorted; tmps; tmps = tmps->next) {
+ ainfo = tmps->data;
+ if (ainfo->mem < 50000)
+ continue;
+ klass = ainfo->klass;
+ if (klass->rank) {
+ isarray = "[]";
+ klass = klass->element_class;
+ } else {
+ isarray = "";
+ }
+ g_snprintf (buf, sizeof (buf), "%s.%s%s",
+ klass->name_space, klass->name, isarray);
+ g_print (" %8d KB %8d %-48s\n", ainfo->mem / 1024, ainfo->count, buf);
}
- g_snprintf (buf, sizeof (buf), "%s.%s%s",
- klass->name_space, klass->name, isarray);
- g_print ("%-52s %9d\n", buf, p->count);
+ /* callers */
+ output_callers (mp);
}
+ g_print ("Total memory allocated: %d KB\n", total / 1024);
}
static void
}
profile_info->count++;
MONO_TIMER_START (profile_info->u.timer);
+ if (prof->callers) {
+ CallerInfo *cinfo;
+ MonoMethod *caller = prof->callers->data;
+ for (cinfo = profile_info->caller_info; cinfo; cinfo = cinfo->next) {
+ if (cinfo->caller == caller)
+ break;
+ }
+ if (!cinfo) {
+ cinfo = g_new0 (CallerInfo, 1);
+ cinfo->caller = caller;
+ cinfo->next = profile_info->caller_info;
+ profile_info->caller_info = cinfo;
+ }
+ cinfo->count++;
+ }
+ prof->callers = g_slist_prepend (prof->callers, method);
}
static void
MONO_TIMER_STOP (profile_info->u.timer);
profile_info->total += MONO_TIMER_ELAPSED (profile_info->u.timer);
+ prof->callers = g_slist_remove (prof->callers, method);
+}
+
+static void
+simple_allocation (MonoProfiler *prof, MonoObject *obj, MonoClass *klass)
+{
+ MethodProfile *profile_info;
+ AllocInfo *tmp;
+
+ if (prof->callers) {
+ if (!(profile_info = g_hash_table_lookup (prof->methods, prof->callers->data)))
+ g_assert_not_reached ();
+ } else {
+ return; /* fine for now */
+ }
+
+ for (tmp = profile_info->alloc_info; tmp; tmp = tmp->next) {
+ if (tmp->klass == klass)
+ break;
+ }
+ if (!tmp) {
+ tmp = g_new0 (AllocInfo, 1);
+ tmp->klass = klass;
+ tmp->next = profile_info->alloc_info;
+ profile_info->alloc_info = tmp;
+ }
+ tmp->count++;
+ if (klass == mono_defaults.string_class) {
+ tmp->mem += sizeof (MonoString) + 2 * mono_string_length ((MonoString*)obj) + 2;
+ } else if (klass->parent == mono_defaults.array_class) {
+ tmp->mem += sizeof (MonoArray) + mono_array_element_size (klass) * mono_array_length ((MonoArray*)obj);
+ } else {
+ tmp->mem += mono_class_instance_size (klass);
+ }
}
static void
simple_method_jit (MonoProfiler *prof, MonoMethod *method)
{
- MONO_TIMER_START (prof->jit_timer);
prof->methods_jitted++;
+ MONO_TIMER_START (prof->jit_timer);
}
static void
g_list_free (profile);
profile = NULL;
- g_hash_table_foreach (prof->newobjs, (GHFunc)build_newobj_profile, &profile);
+ g_hash_table_foreach (prof->methods, (GHFunc)build_newobj_profile, &profile);
output_newobj_profile (profile);
g_list_free (profile);
}
MONO_TIMER_STARTUP;
prof->methods = g_hash_table_new (g_direct_hash, g_direct_equal);
- prof->newobjs = g_hash_table_new (g_direct_hash, g_direct_equal);
MONO_TIMER_INIT (prof->jit_timer);
mono_profiler_install (prof, simple_shutdown);
/* later do also object creation */
mono_profiler_install_enter_leave (simple_method_enter, simple_method_leave);
mono_profiler_install_jit_compile (simple_method_jit, simple_method_end_jit);
- mono_profiler_set_events (MONO_PROFILE_ENTER_LEAVE|MONO_PROFILE_JIT_COMPILATION);
+ mono_profiler_install_allocation (simple_allocation);
+ mono_profiler_set_events (MONO_PROFILE_ENTER_LEAVE|MONO_PROFILE_JIT_COMPILATION|MONO_PROFILE_ALLOCATIONS);
}