X-Git-Url: http://wien.tomnetworks.com/gitweb/?a=blobdiff_plain;f=mono%2Fmetadata%2Fprofiler.c;h=8323e3984cfcae0522a6c33690a0f7d3a77f1cee;hb=57cd4050c4c46d4e39717dadeae9516f147af7f6;hp=27eba5f606239b7596d957892eba8283dc04cf96;hpb=f73e0d5c67f0d26e85b92fc4b75fc48783f20d64;p=mono.git diff --git a/mono/metadata/profiler.c b/mono/metadata/profiler.c index 27eba5f6062..8323e3984cf 100644 --- a/mono/metadata/profiler.c +++ b/mono/metadata/profiler.c @@ -1,15 +1,31 @@ +/* + * profiler.c: Profiler interface for Mono + * + * Author: + * Paolo Molaro (lupus@ximian.com) + * + * (C) 2001-2003 Ximian, Inc. + * (C) 2003-2006 Novell, Inc. + */ #include "config.h" #include "mono/metadata/profiler-private.h" #include "mono/metadata/debug-helpers.h" #include "mono/metadata/mono-debug.h" +#include "mono/metadata/debug-mono-symfile.h" +#include "mono/metadata/metadata-internals.h" #include "mono/metadata/class-internals.h" #include "mono/metadata/domain-internals.h" #include "mono/metadata/gc-internal.h" #include "mono/io-layer/io-layer.h" +#include "mono/utils/mono-dl.h" #include +#ifdef HAVE_UNISTD_H +#include +#endif +#ifdef HAVE_SYS_TIME_H #include -#include +#endif #ifdef HAVE_BACKTRACE_SYMBOLS #include #endif @@ -38,12 +54,20 @@ static MonoProfileClassFunc class_end_unload; static MonoProfileMethodFunc jit_start; static MonoProfileMethodResult jit_end; +static MonoProfileJitResult jit_end2; +static MonoProfileMethodFunc method_free; static MonoProfileMethodResult man_unman_transition; static MonoProfileAllocFunc allocation_cb; static MonoProfileStatFunc statistical_cb; +static MonoProfileStatCallChainFunc statistical_call_chain_cb; +static int statistical_call_chain_depth; static MonoProfileMethodFunc method_enter; static MonoProfileMethodFunc method_leave; +static MonoProfileExceptionFunc exception_throw_cb; +static MonoProfileMethodFunc exception_method_leave_cb; +static MonoProfileExceptionClauseFunc exception_clause_cb; + static MonoProfileThreadFunc thread_start; static MonoProfileThreadFunc thread_end; @@ -61,6 +85,17 @@ static CRITICAL_SECTION profiler_coverage_mutex; /* this is directly accessible to other mono libs. */ MonoProfileFlags mono_profiler_events; +/** + * mono_profiler_install: + * @prof: a MonoProfiler structure pointer, or a pointer to a derived structure. + * @callback: the function to invoke at shutdown + * + * Use mono_profiler_install to activate profiling in the Mono runtime. + * Typically developers of new profilers will create a new structure whose + * first field is a MonoProfiler and put any extra information that they need + * to access from the various profiling callbacks there. + * + */ void mono_profiler_install (MonoProfiler *prof, MonoProfileFunc callback) { @@ -71,18 +106,46 @@ mono_profiler_install (MonoProfiler *prof, MonoProfileFunc callback) InitializeCriticalSection (&profiler_coverage_mutex); } +/** + * mono_profiler_set_events: + * @events: an ORed set of values made up of MONO_PROFILER_ flags + * + * The events descriped in the @events argument is a set of flags + * that represent which profiling events must be triggered. For + * example if you have registered a set of methods for tracking + * JIT compilation start and end with mono_profiler_install_jit_compile, + * you will want to pass the MONO_PROFILE_JIT_COMPILATION flag to + * this routine. + * + * You can call mono_profile_set_events more than once and you can + * do this at runtime to modify which methods are invoked. + */ void mono_profiler_set_events (MonoProfileFlags events) { mono_profiler_events = events; } +/** + * mono_profiler_get_events: + * + * Returns a list of active events that will be intercepted. + */ MonoProfileFlags mono_profiler_get_events (void) { return mono_profiler_events; } +/** + * mono_profiler_install_enter_leave: + * @enter: the routine to be called on each method entry + * @fleave: the routine to be called each time a method returns + * + * Use this routine to install routines that will be called everytime + * a method enters and leaves. The routines will receive as an argument + * the MonoMethod representing the method that is entering or leaving. + */ void mono_profiler_install_enter_leave (MonoProfileMethodFunc enter, MonoProfileMethodFunc fleave) { @@ -90,6 +153,14 @@ mono_profiler_install_enter_leave (MonoProfileMethodFunc enter, MonoProfileMetho method_leave = fleave; } +/** + * mono_profiler_install_jit_compile: + * @start: the routine to be called when the JIT process starts. + * @end: the routine to be called when the JIT process ends. + * + * Use this routine to install routines that will be called when JIT + * compilation of a method starts and completes. + */ void mono_profiler_install_jit_compile (MonoProfileMethodFunc start, MonoProfileMethodResult end) { @@ -97,6 +168,18 @@ mono_profiler_install_jit_compile (MonoProfileMethodFunc start, MonoProfileMetho jit_end = end; } +void +mono_profiler_install_jit_end (MonoProfileJitResult end) +{ + jit_end2 = end; +} + +void +mono_profiler_install_method_free (MonoProfileMethodFunc callback) +{ + method_free = callback; +} + void mono_profiler_install_thread (MonoProfileThreadFunc start, MonoProfileThreadFunc end) { @@ -122,6 +205,31 @@ mono_profiler_install_statistical (MonoProfileStatFunc callback) statistical_cb = callback; } +void +mono_profiler_install_statistical_call_chain (MonoProfileStatCallChainFunc callback, int call_chain_depth) { + statistical_call_chain_cb = callback; + statistical_call_chain_depth = call_chain_depth; + if (statistical_call_chain_depth > MONO_PROFILER_MAX_STAT_CALL_CHAIN_DEPTH) { + statistical_call_chain_depth = MONO_PROFILER_MAX_STAT_CALL_CHAIN_DEPTH; + } +} + +int +mono_profiler_stat_get_call_chain_depth (void) { + if (statistical_call_chain_cb != NULL) { + return statistical_call_chain_depth; + } else { + return 0; + } +} + +void mono_profiler_install_exception (MonoProfileExceptionFunc throw_callback, MonoProfileMethodFunc exc_method_leave, MonoProfileExceptionClauseFunc clause_callback) +{ + exception_throw_cb = throw_callback; + exception_method_leave_cb = exc_method_leave; + exception_clause_cb = clause_callback; +} + void mono_profiler_install_coverage_filter (MonoProfileCoverageFilterFunc callback) { @@ -191,10 +299,21 @@ mono_profiler_method_jit (MonoMethod *method) } void -mono_profiler_method_end_jit (MonoMethod *method, int result) +mono_profiler_method_end_jit (MonoMethod *method, MonoJitInfo* jinfo, int result) { - if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION) && jit_end) - jit_end (current_profiler, method, result); + if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION)) { + if (jit_end) + jit_end (current_profiler, method, result); + if (jit_end2) + jit_end2 (current_profiler, method, jinfo, result); + } +} + +void +mono_profiler_method_free (MonoMethod *method) +{ + if ((mono_profiler_events & MONO_PROFILE_METHOD_EVENTS) && method_free) + method_free (current_profiler, method); } void @@ -218,6 +337,34 @@ mono_profiler_stat_hit (guchar *ip, void *context) statistical_cb (current_profiler, ip, context); } +void +mono_profiler_stat_call_chain (int call_chain_depth, guchar **ips, void *context) +{ + if ((mono_profiler_events & MONO_PROFILE_STATISTICAL) && statistical_call_chain_cb) + statistical_call_chain_cb (current_profiler, call_chain_depth, ips, context); +} + +void +mono_profiler_exception_thrown (MonoObject *exception) +{ + if ((mono_profiler_events & MONO_PROFILE_EXCEPTIONS) && exception_throw_cb) + exception_throw_cb (current_profiler, exception); +} + +void +mono_profiler_exception_method_leave (MonoMethod *method) +{ + if ((mono_profiler_events & MONO_PROFILE_EXCEPTIONS) && exception_method_leave_cb) + exception_method_leave_cb (current_profiler, method); +} + +void +mono_profiler_exception_clause_handler (MonoMethod *method, int clause_type, int clause_num) +{ + if ((mono_profiler_events & MONO_PROFILE_EXCEPTIONS) && exception_clause_cb) + exception_clause_cb (current_profiler, method, clause_type, clause_num); +} + void mono_profiler_thread_start (gsize tid) { @@ -430,15 +577,28 @@ mono_profiler_coverage_free (MonoMethod *method) mono_profiler_coverage_unlock (); } +/** + * mono_profiler_coverage_get: + * @prof: The profiler handle, installed with mono_profiler_install + * @method: the method to gather information from. + * @func: A routine that will be called back with the results + * + * If the MONO_PROFILER_INS_COVERAGE flag was active during JIT compilation + * it is posisble to obtain coverage information about a give method. + * + * The function @func will be invoked repeatedly with instances of the + * MonoProfileCoverageEntry structure. + */ void mono_profiler_coverage_get (MonoProfiler *prof, MonoMethod *method, MonoProfileCoverageFunc func) { MonoProfileCoverageInfo* info; int i, offset; - guint32 line, col; - unsigned char *start, *end, *cil_code; + guint32 code_size; + const unsigned char *start, *end, *cil_code; MonoMethodHeader *header; MonoProfileCoverageEntry entry; + MonoDebugMethodInfo *debug_minfo; mono_profiler_coverage_lock (); info = g_hash_table_lookup (coverage_hash, method); @@ -448,21 +608,34 @@ mono_profiler_coverage_get (MonoProfiler *prof, MonoMethod *method, MonoProfileC return; header = mono_method_get_header (method); - start = (unsigned char*)header->code; - end = start + header->code_size; + start = mono_method_header_get_code (header, &code_size, NULL); + debug_minfo = mono_debug_lookup_method (method); + + end = start + code_size; for (i = 0; i < info->entries; ++i) { cil_code = info->data [i].cil_code; if (cil_code && cil_code >= start && cil_code < end) { + char *fname = NULL; offset = cil_code - start; entry.iloffset = offset; entry.method = method; entry.counter = info->data [i].count; - /* the debug interface doesn't support column info, sigh */ - col = line = 1; - entry.filename = mono_debug_source_location_from_il_offset (method, offset, &line); - entry.line = line; - entry.col = col; + entry.line = entry.col = 1; + entry.filename = NULL; + if (debug_minfo) { + MonoDebugSourceLocation *location; + + location = mono_debug_symfile_lookup_location (debug_minfo, offset); + if (location) { + entry.line = location->row; + entry.col = location->column; + entry.filename = fname = g_strdup (location->source_file); + mono_debug_free_source_location (location); + } + } + func (prof, &entry); + g_free (fname); } } } @@ -473,6 +646,8 @@ mono_profiler_coverage_get (MonoProfiler *prof, MonoMethod *method, MonoProfileC * and improve it to do graphs and more accurate timestamping with rdtsc. */ +static FILE* poutput = NULL; + #define USE_X86TSC 0 #define USE_WIN32COUNTER 0 #if USE_X86TSC @@ -654,7 +829,7 @@ create_profiler (void) { MonoProfiler *prof = g_new0 (MonoProfiler, 1); - prof->methods = g_hash_table_new (NULL, NULL); + prof->methods = g_hash_table_new (mono_aligned_addr_hash, NULL); MONO_TIMER_INIT (prof->jit_timer); prof->mempool = mono_mempool_new (); return prof; @@ -715,6 +890,14 @@ method_get_name (MonoMethod* method) static void output_callers (MethodProfile *p); +/* This isn't defined on older glib versions and on some platforms */ +#ifndef G_GUINT64_FORMAT +#define G_GUINT64_FORMAT "ul" +#endif +#ifndef G_GINT64_FORMAT +#define G_GINT64_FORMAT "lld" +#endif + static void output_profile (GList *funcs) { @@ -724,24 +907,24 @@ output_profile (GList *funcs) guint64 total_calls = 0; if (funcs) - g_print ("Time(ms) Count P/call(ms) Method name\n"); + fprintf (poutput, "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; m = method_get_name (p->method); - printf ("########################\n"); - printf ("% 8.3f ", (double) (p->total * 1000)); - printf ("%7llu ", (unsigned long long)p->count); - printf ("% 8.3f ", (double) (p->total * 1000)/(double)p->count); - printf (" %s\n", m); + fprintf (poutput, "########################\n"); + fprintf (poutput, "% 8.3f ", (double) (p->total * 1000)); + fprintf (poutput, "%7" G_GUINT64_FORMAT " ", (guint64)p->count); + fprintf (poutput, "% 8.3f ", (double) (p->total * 1000)/(double)p->count); + fprintf (poutput, " %s\n", m); g_free (m); /* callers */ output_callers (p); } - printf ("Total number of calls: %lld\n", (long long)total_calls); + fprintf (poutput, "Total number of calls: %" G_GINT64_FORMAT "\n", (gint64)total_calls); } typedef struct { @@ -814,7 +997,7 @@ output_callers (MethodProfile *p) { CallerInfo *cinfo; char *m; - g_print (" Callers (with count) that contribute at least for 1%%:\n"); + fprintf (poutput, " 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; @@ -826,16 +1009,11 @@ output_callers (MethodProfile *p) { if (percent < 1) continue; m = method_get_name (cinfo->caller); - g_print (" %8d % 3d %% %s\n", cinfo->count, percent, m); + fprintf (poutput, " %8d % 3d %% %s\n", cinfo->count, percent, m); g_free (m); } } -/* This isn't defined on older glib versions and on some platforms */ -#ifndef G_GUINT64_FORMAT -#define G_GUINT64_FORMAT "ul" -#endif - static void output_newobj_profile (GList *proflist) { @@ -850,10 +1028,10 @@ output_newobj_profile (GList *proflist) guint64 total = 0; GSList *sorted, *tmps; - g_print ("\nAllocation profiler\n"); + fprintf (poutput, "\nAllocation profiler\n"); if (proflist) - g_print ("%-9s %s\n", "Total mem", "Method"); + fprintf (poutput, "%-9s %s\n", "Total mem", "Method"); for (tmp = proflist; tmp; tmp = tmp->next) { p = tmp->data; total += p->count; @@ -861,7 +1039,7 @@ output_newobj_profile (GList *proflist) continue; mp = p->mp; m = method_get_name (mp->method); - g_print ("########################\n%8" G_GUINT64_FORMAT " KB %s\n", (p->count / 1024), m); + fprintf (poutput, "########################\n%8" G_GUINT64_FORMAT " KB %s\n", (p->count / 1024), m); g_free (m); sorted = sort_alloc_list (mp->alloc_info); for (tmps = sorted; tmps; tmps = tmps->next) { @@ -875,14 +1053,14 @@ output_newobj_profile (GList *proflist) } else { isarray = ""; } - g_snprintf (buf, sizeof (buf), "%s%%s%s", + g_snprintf (buf, sizeof (buf), "%s%s%s%s", klass->name_space, klass->name_space ? "." : "", klass->name, isarray); - g_print (" %8" G_GUINT64_FORMAT " KB %8" G_GUINT64_FORMAT " %-48s\n", (ainfo->mem / 1024), ainfo->count, buf); + fprintf (poutput, " %8" G_GUINT64_FORMAT " KB %8" G_GUINT64_FORMAT " %-48s\n", (ainfo->mem / 1024), ainfo->count, buf); } /* callers */ output_callers (mp); } - g_print ("Total memory allocated: %" G_GUINT64_FORMAT " KB\n", total / 1024); + fprintf (poutput, "Total memory allocated: %" G_GUINT64_FORMAT " KB\n", total / 1024); } static void @@ -1132,6 +1310,17 @@ try_addr2line (const char* binary, gpointer ip) const char *addr_argv[] = {"addr2line", "-f", "-e", binary, NULL}; int child_pid; int ch_in, ch_out; +#ifdef __linux__ + char monobin [1024]; + /* non-linux platforms will need different code here */ + if (strcmp (binary, "mono") == 0) { + int count = readlink ("/proc/self/exe", monobin, sizeof (monobin)); + if (count >= 0 && count < sizeof (monobin)) { + monobin [count] = 0; + addr_argv [3] = monobin; + } + } +#endif if (!g_spawn_async_with_pipes (NULL, (char**)addr_argv, NULL, G_SPAWN_SEARCH_PATH, NULL, NULL, &child_pid, &ch_in, &ch_out, NULL, NULL)) { return g_strdup (binary); @@ -1214,13 +1403,13 @@ stat_prof_report (void) if (c > 1) g_free (mn); } - g_print ("prof counts: total/unmanaged: %d/%d\n", pcount, prof_ucounts); + fprintf (poutput, "prof counts: total/unmanaged: %d/%d\n", pcount, prof_ucounts); g_hash_table_foreach (prof_table, (GHFunc)prof_foreach, &sorted); for (tmp = sorted; tmp; tmp = tmp->next) { double perc; c = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, tmp->data)); perc = c*100.0/count; - g_print ("%7d\t%5.2f %% %s\n", c, perc, (char*)tmp->data); + fprintf (poutput, "%7d\t%5.2f %% %s\n", c, perc, (char*)tmp->data); } g_list_free (sorted); } @@ -1229,12 +1418,13 @@ static void simple_appdomain_unload (MonoProfiler *prof, MonoDomain *domain) { /* FIXME: we should actually record partial data for each domain, - * since the ip->ji->method mappings are going away at domain unload time. + * but at this point it's must easier using the new logging profiler. */ - if (domain == mono_get_root_domain ()) - stat_prof_report (); + mono_profiler_shutdown (); } +static gint32 simple_shutdown_done = FALSE; + static void simple_shutdown (MonoProfiler *prof) { @@ -1242,16 +1432,31 @@ simple_shutdown (MonoProfiler *prof) MonoProfiler *tprof; GSList *tmp; char *str; + gint32 see_shutdown_done; + + mono_thread_attach(mono_get_root_domain()); + + // Make sure we execute simple_shutdown only once + see_shutdown_done = InterlockedExchange(& simple_shutdown_done, TRUE); + if (see_shutdown_done) + return; + if (mono_profiler_events & MONO_PROFILE_STATISTICAL) { + stat_prof_report (); + } + + // Stop all incoming events + mono_profiler_set_events (0); + for (tmp = prof->per_thread; tmp; tmp = tmp->next) { tprof = tmp->data; merge_thread_data (prof, tprof); } - printf("Total time spent compiling %d methods (sec): %.4g\n", prof->methods_jitted, prof->jit_time); + fprintf (poutput, "Total time spent compiling %d methods (sec): %.4g\n", prof->methods_jitted, prof->jit_time); if (prof->max_jit_method) { str = method_get_name (prof->max_jit_method); - printf("Slowest method to compile (sec): %.4g: %s\n", prof->max_jit_time, str); + fprintf (poutput, "Slowest method to compile (sec): %.4g: %s\n", prof->max_jit_time, str); g_free (str); } g_hash_table_foreach (prof->methods, (GHFunc)build_profile, &profile); @@ -1276,6 +1481,7 @@ mono_profiler_install_simple (const char *desc) MonoProfileFlags flags = 0; MONO_TIMER_STARTUP; + poutput = stdout; if (!desc) desc = "alloc,time,jit"; @@ -1291,20 +1497,32 @@ mono_profiler_install_simple (const char *desc) for (ptr = args; ptr && *ptr; ptr++) { const char *arg = *ptr; + // Alwais listen to appdomaon events to shutdown at the first unload + flags |= MONO_PROFILE_APPDOMAIN_EVENTS; if (!strcmp (arg, "time")) - flags |= MONO_PROFILE_ENTER_LEAVE; + flags |= MONO_PROFILE_ENTER_LEAVE | MONO_PROFILE_EXCEPTIONS; else if (!strcmp (arg, "alloc")) flags |= MONO_PROFILE_ALLOCATIONS; else if (!strcmp (arg, "stat")) - flags |= MONO_PROFILE_STATISTICAL | MONO_PROFILE_APPDOMAIN_EVENTS; + flags |= MONO_PROFILE_STATISTICAL; else if (!strcmp (arg, "jit")) flags |= MONO_PROFILE_JIT_COMPILATION; - else { + else if (strncmp (arg, "file=", 5) == 0) { + poutput = fopen (arg + 5, "wb"); + if (!poutput) { + poutput = stdout; + fprintf (stderr, "profiler : cannot open profile output file '%s'.\n", arg + 5); + } + } else { fprintf (stderr, "profiler : Unknown argument '%s'.\n", arg); return; } } } + if (flags & MONO_PROFILE_ALLOCATIONS) + flags |= MONO_PROFILE_ENTER_LEAVE | MONO_PROFILE_EXCEPTIONS; + if (!flags) + flags = MONO_PROFILE_ENTER_LEAVE | MONO_PROFILE_ALLOCATIONS | MONO_PROFILE_JIT_COMPILATION | MONO_PROFILE_EXCEPTIONS; prof = create_profiler (); ALLOC_PROFILER (); @@ -1316,6 +1534,7 @@ mono_profiler_install_simple (const char *desc) mono_profiler_install (prof, simple_shutdown); mono_profiler_install_enter_leave (simple_method_enter, simple_method_leave); + mono_profiler_install_exception (NULL, simple_method_leave, NULL); mono_profiler_install_jit_compile (simple_method_jit, simple_method_end_jit); mono_profiler_install_allocation (simple_allocation); mono_profiler_install_appdomain (NULL, NULL, simple_appdomain_unload, NULL); @@ -1328,6 +1547,16 @@ mono_profiler_install_simple (const char *desc) typedef void (*ProfilerInitializer) (const char*); #define INITIALIZER_NAME "mono_profiler_startup" +/** + * mono_profiler_load: + * @desc: arguments to configure the profiler + * + * Invoke this method to initialize the profiler. This will drive the + * loading of the internal ("default") or any external profilers. + * + * This routine is invoked by Mono's driver, but must be called manually + * if you embed Mono into your application. + */ void mono_profiler_load (const char *desc) { @@ -1342,31 +1571,42 @@ mono_profiler_load (const char *desc) } #endif { - GModule *pmodule; + MonoDl *pmodule; const char* col = strchr (desc, ':'); char* libname; char* path; char *mname; + char *err; + void *iter; if (col != NULL) { - mname = g_memdup (desc, col - desc); + mname = g_memdup (desc, col - desc + 1); mname [col - desc] = 0; } else { mname = g_strdup (desc); } libname = g_strdup_printf ("mono-profiler-%s", mname); - path = g_module_build_path (NULL, libname); - pmodule = g_module_open (path, G_MODULE_BIND_LAZY); - if (pmodule) { - ProfilerInitializer func; - if (!g_module_symbol (pmodule, INITIALIZER_NAME, (gpointer *)&func)) { - g_warning ("Cannot find initializer function %s in profiler module: %s", INITIALIZER_NAME, libname); - } else { - func (desc); + iter = NULL; + err = NULL; + while ((path = mono_dl_build_path (NULL, libname, &iter))) { + g_free (err); + pmodule = mono_dl_open (path, MONO_DL_LAZY, &err); + if (pmodule) { + ProfilerInitializer func; + if ((err = mono_dl_symbol (pmodule, INITIALIZER_NAME, (gpointer *)&func))) { + g_warning ("Cannot find initializer function %s in profiler module: %s (%s)", INITIALIZER_NAME, libname, err); + g_free (err); + err = NULL; + } else { + func (desc); + } + break; } - } else { - g_warning ("Error loading profiler module '%s': %s", libname, g_module_error ()); + g_free (path); + } + if (!pmodule) { + g_warning ("Error loading profiler module '%s': %s", libname, err); + g_free (err); } - g_free (libname); g_free (mname); g_free (path);