diff options
| -rw-r--r-- | man/mprof-report.1 | 16 | ||||
| -rw-r--r-- | mono/profiler/Makefile.am | 5 | ||||
| -rw-r--r-- | mono/profiler/decode.c | 50 | ||||
| -rw-r--r-- | mono/profiler/proflog.c | 163 | ||||
| -rw-r--r-- | mono/profiler/utils.c | 426 | ||||
| -rw-r--r-- | mono/profiler/utils.h | 24 |
6 files changed, 204 insertions, 480 deletions
diff --git a/man/mprof-report.1 b/man/mprof-report.1 index c9b756bd990..b96001d2c63 100644 --- a/man/mprof-report.1 +++ b/man/mprof-report.1 @@ -164,13 +164,6 @@ In this case, \f[I]TYPE\f[] can be one of: \f[I]branchmiss\f[]: mispredicted branches .RE .IP \[bu] 2 -\f[I]time=TIMER\f[]: use the TIMER timestamp mode. -TIMER can have the following values: -.RS 2 -.IP \[bu] 2 -\f[I]fast\f[]: a usually faster but possibly more inaccurate timer -.RE -.IP \[bu] 2 \f[I]maxframes=NUM\f[]: when a stack trace needs to be performed, collect \f[I]NUM\f[] frames at the most. The default is 32. @@ -487,15 +480,6 @@ option: especially if the managed heap is big, since every object needs to be inspected. The \f[I]MODE\f[] parameter of the \f[I]heapshot\f[] option can be used to reduce the frequency of the heap shots. -.IP "\f[I]Reduce the timestamp overhead\f[]" 4 -.Sp -On many operating systems or architectures what actually slows down -profiling is the function provided by the system to get timestamp -information. -The \f[I]time=fast\f[] profiler option can be usually used to speed -up this operation, but, depending on the system, time accounting -may have some level of approximation (though statistically the data -should be still fairly valuable). .SS Dealing with the size of the data files .PP When collecting a lot of information about a profiled program, huge diff --git a/mono/profiler/Makefile.am b/mono/profiler/Makefile.am index 3d7eb62e400..86ca6bdfd41 100644 --- a/mono/profiler/Makefile.am +++ b/mono/profiler/Makefile.am @@ -110,6 +110,7 @@ testlog: $(PLOG_TESTS) check-local: $(check_targets) -EXTRA_DIST=utils.c utils.h proflog.h \ - $(PLOG_TESTS_SRC) ptestrunner.pl \ +EXTRA_DIST=proflog.h \ + $(PLOG_TESTS_SRC) \ + ptestrunner.pl \ $(suppression_DATA) diff --git a/mono/profiler/decode.c b/mono/profiler/decode.c index 338150494dd..a80e01e201f 100644 --- a/mono/profiler/decode.c +++ b/mono/profiler/decode.c @@ -54,11 +54,11 @@ * - column: The column on the line */ #include <config.h> -#include "utils.c" #include "proflog.h" #include <string.h> #include <assert.h> #include <stdio.h> +#include <time.h> #if !defined(__APPLE__) && !defined(__FreeBSD__) #include <malloc.h> #endif @@ -1972,6 +1972,54 @@ get_root_name (int rtype) } } +static uint64_t +decode_uleb128 (uint8_t *buf, uint8_t **endbuf) +{ + uint64_t res = 0; + int shift = 0; + + while (1) { + uint8_t b = *buf++; + res |= (((uint64_t) (b & 0x7f)) << shift); + + if (!(b & 0x80)) + break; + + shift += 7; + } + + *endbuf = buf; + + return res; +} + +static intptr_t +decode_sleb128 (uint8_t *buf, uint8_t **endbuf) +{ + uint8_t *p = buf; + intptr_t res = 0; + int shift = 0; + + while (1) { + uint8_t b = *p; + p++; + + res = res | (((intptr_t) (b & 0x7f)) << shift); + shift += 7; + + if (!(b & 0x80)) { + if (shift < sizeof (intptr_t) * 8 && (b & 0x40)) + res |= - ((intptr_t) 1 << shift); + + break; + } + } + + *endbuf = p; + + return res; +} + static MethodDesc** decode_bt (ProfContext *ctx, MethodDesc** sframes, int *size, unsigned char *p, unsigned char **endp, intptr_t ptr_base, intptr_t *method_base) { diff --git a/mono/profiler/proflog.c b/mono/profiler/proflog.c index 6a860e051c6..03e7e093efa 100644 --- a/mono/profiler/proflog.c +++ b/mono/profiler/proflog.c @@ -48,6 +48,13 @@ #endif #include <fcntl.h> #include <errno.h> +#include <time.h> +#ifdef HAVE_SYS_TIME_H +#include <sys/time.h> +#endif +#if defined(__APPLE__) +#include <mach/mach_time.h> +#endif #if defined(HOST_WIN32) || defined(DISABLE_SOCKETS) #define DISABLE_HELPER_THREAD 1 #endif @@ -82,7 +89,6 @@ #include <sys/stat.h> #endif -#include "utils.c" #include "proflog.h" #if defined (HAVE_SYS_ZLIB) @@ -524,6 +530,82 @@ ign_res (int G_GNUC_UNUSED unused, ...) { } +static uintptr_t +thread_id (void) +{ + return (uintptr_t) mono_native_thread_id_get (); +} + +static uintptr_t +process_id (void) +{ +#ifdef HOST_WIN32 + return (uintptr_t) GetCurrentProcessId (); +#else + return (uintptr_t) getpid (); +#endif +} + +#ifdef __APPLE__ +static mach_timebase_info_data_t timebase_info; +#elif defined (HOST_WIN32) +static LARGE_INTEGER pcounter_freq; +#endif + +#define TICKS_PER_SEC 1000000000LL + +static uint64_t +current_time (void) +{ +#ifdef __APPLE__ + uint64_t time = mach_absolute_time (); + + time *= timebase_info.numer; + time /= timebase_info.denom; + + return time; +#elif defined (HOST_WIN32) + LARGE_INTEGER value; + + QueryPerformanceCounter (&value); + + return value.QuadPart * TICKS_PER_SEC / pcounter_freq.QuadPart; +#elif defined (CLOCK_MONOTONIC) + struct timespec tspec; + + clock_gettime (CLOCK_MONOTONIC, &tspec); + + return ((uint64_t) tspec.tv_sec * TICKS_PER_SEC + tspec.tv_nsec); +#else + struct timeval tv; + + gettimeofday (&tv, NULL); + + return ((uint64_t) tv.tv_sec * TICKS_PER_SEC + tv.tv_usec * 1000); +#endif +} + +static int timer_overhead; + +static void +init_time (void) +{ +#ifdef __APPLE__ + mach_timebase_info (&timebase_info); +#elif defined (HOST_WIN32) + QueryPerformanceFrequency (&pcounter_freq); +#endif + + uint64_t time_start = current_time (); + + for (int i = 0; i < 256; ++i) + current_time (); + + uint64_t time_end = current_time (); + + timer_overhead = (time_end - time_start) / 256; +} + /* * These macros create a scope to avoid leaking the buffer returned * from ensure_logbuf () as it may have been invalidated by a GC @@ -713,10 +795,22 @@ pstrdup (const char *s) return p; } +static void * +alloc_buffer (int size) +{ + return mono_valloc (NULL, size, MONO_MMAP_READ | MONO_MMAP_WRITE | MONO_MMAP_ANON | MONO_MMAP_PRIVATE, MONO_MEM_ACCOUNT_PROFILER); +} + +static void +free_buffer (void *buf, int size) +{ + mono_vfree (buf, size, MONO_MEM_ACCOUNT_PROFILER); +} + static LogBuffer* create_buffer (void) { - LogBuffer* buf = (LogBuffer *)alloc_buffer (BUFFER_SIZE); + LogBuffer* buf = (LogBuffer *) alloc_buffer (BUFFER_SIZE); InterlockedIncrement (&buffer_allocations_ctr); @@ -725,6 +819,7 @@ create_buffer (void) buf->last_time = buf->time_base; buf->buf_end = (unsigned char*)buf + buf->size; buf->cursor = buf->buf; + return buf; } @@ -821,6 +916,58 @@ ensure_logbuf_unsafe (int bytes) } static void +encode_uleb128 (uint64_t value, uint8_t *buf, uint8_t **endbuf) +{ + uint8_t *p = buf; + + do { + uint8_t b = value & 0x7f; + value >>= 7; + + if (value != 0) /* more bytes to come */ + b |= 0x80; + + *p ++ = b; + } while (value); + + *endbuf = p; +} + +static void +encode_sleb128 (intptr_t value, uint8_t *buf, uint8_t **endbuf) +{ + int more = 1; + int negative = (value < 0); + unsigned int size = sizeof (intptr_t) * 8; + uint8_t byte; + uint8_t *p = buf; + + while (more) { + byte = value & 0x7f; + value >>= 7; + + /* the following is unnecessary if the + * implementation of >>= uses an arithmetic rather + * than logical shift for a signed left operand + */ + if (negative) + /* sign extend */ + value |= - ((intptr_t) 1 <<(size - 7)); + + /* sign bit of byte is second high order bit (0x40) */ + if ((value == 0 && !(byte & 0x40)) || + (value == -1 && (byte & 0x40))) + more = 0; + else + byte |= 0x80; + + *p ++= byte; + } + + *endbuf = p; +} + +static void emit_byte (LogBuffer *logbuffer, int value) { logbuffer->cursor [0] = value; @@ -1087,7 +1234,7 @@ dump_header (MonoProfiler *profiler) *p++ = LOG_DATA_VERSION; *p++ = sizeof (void *); p = write_int64 (p, ((uint64_t) time (NULL)) * 1000); - p = write_int32 (p, get_timer_overhead ()); + p = write_int32 (p, timer_overhead); p = write_int32 (p, 0); /* flags */ p = write_int32 (p, process_id ()); p = write_int16 (p, profiler->command_port); @@ -4946,7 +5093,6 @@ usage (int do_exit) printf ("\tsample[=TYPE] use statistical sampling mode (by default cycles/100)\n"); printf ("\t TYPE: cycles,instr,cacherefs,cachemiss,branches,branchmiss\n"); printf ("\t TYPE can be followed by /FREQUENCY\n"); - printf ("\ttime=fast use a faster (but more inaccurate) timer\n"); printf ("\tmaxframes=NUM collect up to NUM stack frames\n"); printf ("\tcalldepth=NUM ignore method events for call chain depth bigger than NUM\n"); printf ("\toutput=FILENAME write the data to file FILENAME (-FILENAME to overwrite)\n"); @@ -5112,7 +5258,6 @@ mono_profiler_startup (const char *desc) char *filename = NULL; const char *p; const char *opt; - int fast_time = 0; int calls_enabled = 0; int allocs_enabled = 0; int only_coverage = 0; @@ -5159,11 +5304,7 @@ mono_profiler_startup (const char *desc) continue; } if ((opt = match_option (p, "time", &val)) != p) { - if (strcmp (val, "fast") == 0) - fast_time = 1; - else if (strcmp (val, "null") == 0) - fast_time = 2; - else + if (strcmp (val, "fast") && strcmp (val, "null")) usage (1); g_free (val); continue; @@ -5303,7 +5444,7 @@ mono_profiler_startup (const char *desc) events = MONO_PROFILE_GC | MONO_PROFILE_THREADS | MONO_PROFILE_ENTER_LEAVE | MONO_PROFILE_INS_COVERAGE; } - utils_init (fast_time); + init_time (); PROF_TLS_INIT (); diff --git a/mono/profiler/utils.c b/mono/profiler/utils.c deleted file mode 100644 index cfa7589a6b2..00000000000 --- a/mono/profiler/utils.c +++ /dev/null @@ -1,426 +0,0 @@ -/* - * utils.c: log profiler and reporter utils - * - * We have here the minimal needed portability functions: we can't depend - * on the ones provided by the runtime, since they are internal and, - * especially mprof-report is an external program. - * Note also that we don't take a glib/eglib dependency here for mostly - * the same reason (but also because we need tight control in the profiler - * over memory allocation, which needs to work with the world stopped). - * - * Author: - * Paolo Molaro (lupus@ximian.com) - * - * Copyright 2010 Novell, Inc (http://www.novell.com) - * Licensed under the MIT license. See LICENSE file in the project root for full license information. - */ -#include "utils.h" -#include <stdlib.h> -#include <time.h> -#include <stdio.h> -#include <string.h> -#include <unistd.h> -#ifdef HOST_WIN32 -#include <windows.h> -#else -#include <pthread.h> -#include <sched.h> -#endif -#include <glib.h> - -#ifdef HAVE_SYS_TIME_H -#include <sys/time.h> -#endif -#if HAVE_SYS_MMAN_H -#include <sys/mman.h> -#endif - -#if defined(__APPLE__) -#include <mach/mach_time.h> -#include <stdio.h> - -static mach_timebase_info_data_t timebase_info; -#endif - -#ifndef MAP_ANONYMOUS -#define MAP_ANONYMOUS MAP_ANON -#endif - -#define TICKS_PER_SEC 1000000000LL - -#if (defined(TARGET_X86) || defined(TARGET_AMD64)) && defined(__linux__) && defined(HAVE_SCHED_GETCPU) -#define HAVE_RDTSC 1 -#endif - -typedef struct { - unsigned int timer_count; - int last_cpu; - uint64_t last_rdtsc; - uint64_t last_time; -} TlsData; - -#ifdef HOST_WIN32 -static int tls_data; -#define DECL_TLS_DATA TlsData *tls; tls = (TlsData *) TlsGetValue (tls_data); if (tls == NULL) { tls = (TlsData *) g_calloc (sizeof (TlsData), 1); TlsSetValue (tls_data, tls); } -#define TLS_INIT(x) x = TlsAlloc() -#elif HAVE_KW_THREAD -static __thread TlsData tls_data; -#define DECL_TLS_DATA TlsData *tls = &tls_data -#define TLS_INIT(x) -#else -static pthread_key_t tls_data; -#define DECL_TLS_DATA TlsData *tls; tls = (TlsData *) pthread_getspecific (tls_data); if (tls == NULL) { tls = (TlsData *) g_calloc (sizeof (TlsData), 1); pthread_setspecific (tls_data, tls); } -#define TLS_INIT(x) pthread_key_create(&x, NULL) -#endif - -#ifdef HOST_WIN32 -static CRITICAL_SECTION log_lock; -static LARGE_INTEGER pcounter_freq; -#else -static pthread_mutex_t log_lock = PTHREAD_MUTEX_INITIALIZER; -#endif - -static int timer_overhead = 0; -static uint64_t time_inc = 0; -typedef uint64_t (*TimeFunc)(void); - -static TimeFunc time_func; - -static uint64_t -clock_time (void) -{ -#if defined(__APPLE__) - uint64_t time = mach_absolute_time (); - - time *= timebase_info.numer; - time /= timebase_info.denom; - - return time; -#elif defined(HOST_WIN32) - LARGE_INTEGER value; - QueryPerformanceCounter (&value); - return value.QuadPart * TICKS_PER_SEC / pcounter_freq.QuadPart; -#elif defined(CLOCK_MONOTONIC) - struct timespec tspec; - clock_gettime (CLOCK_MONOTONIC, &tspec); - return ((uint64_t)tspec.tv_sec * TICKS_PER_SEC + tspec.tv_nsec); -#else - struct timeval tv; - gettimeofday (&tv, NULL); - return ((uint64_t)tv.tv_sec * TICKS_PER_SEC + tv.tv_usec * 1000); -#endif -} - -/* must be power of two */ -#define TIME_ADJ 8 - -static uint64_t -fast_current_time (void) -{ - DECL_TLS_DATA; - if (tls->timer_count++ & (TIME_ADJ - 1)) { - tls->last_time += time_inc; - return tls->last_time; - } - tls->last_time = clock_time (); - return tls->last_time; -} - -#if HAVE_RDTSC - -#define rdtsc(low,high) \ - __asm__ __volatile__("rdtsc" : "=a" (low), "=d" (high)) - -static uint64_t -safe_rdtsc (int *cpu) -{ - unsigned int low, high; - int c1 = sched_getcpu (); - int c2; - rdtsc (low, high); - c2 = sched_getcpu (); - if (c1 != c2) { - *cpu = -1; - return 0; - } - *cpu = c1; - return (((uint64_t) high) << 32) + (uint64_t)low; -} - -static double cpu_freq; - -static int -have_rdtsc (void) { - char buf[256]; - int have_freq = 0; - int have_flag = 0; - float val; - FILE *cpuinfo; - int cpu = sched_getcpu (); - - if (cpu < 0) - return 0; - - if (!(cpuinfo = fopen ("/proc/cpuinfo", "r"))) - return 0; - while (fgets (buf, sizeof(buf), cpuinfo)) { - if (sscanf (buf, "cpu MHz : %f", &val) == 1) { - /*printf ("got mh: %f\n", val);*/ - have_freq = 1; - cpu_freq = val * 1000000; - } - if (strncmp (buf, "flags :", 5) == 0) { - if (strstr (buf, "constant_tsc")) { - have_flag = 1; - /*printf ("have tsc\n");*/ - } - } - } - fclose (cpuinfo); - return have_flag? have_freq: 0; -} - -static uint64_t -rdtsc_current_time (void) -{ - DECL_TLS_DATA; - if (tls->timer_count++ & (TIME_ADJ*8 - 1)) { - int cpu; - uint64_t tsc = safe_rdtsc (&cpu); - if (cpu != -1 && cpu == tls->last_cpu) { - int64_t diff = tsc - tls->last_rdtsc; - uint64_t nsecs; - if (diff > 0) { - nsecs = (double)diff/cpu_freq; - //printf ("%llu cycles: %llu nsecs\n", diff, nsecs); - return tls->last_time + nsecs; - } else { - printf ("tsc went backwards\n"); - } - } else { - //printf ("wrong cpu: %d\n", cpu); - } - } - tls->last_time = clock_time (); - tls->last_rdtsc = safe_rdtsc (&tls->last_cpu); - return tls->last_time; -} -#else -#define have_rdtsc() 0 -#define rdtsc_current_time fast_current_time -#endif - -static uint64_t -null_time (void) -{ - static uint64_t timer = 0; - return timer++; -} - -void -utils_init (int fast_time) -{ - int i; - uint64_t time_start, time_end; - TLS_INIT (tls_data); -#ifdef HOST_WIN32 - InitializeCriticalSection (&log_lock); - QueryPerformanceFrequency (&pcounter_freq); -#endif -#if defined (__APPLE__) - mach_timebase_info (&timebase_info); -#endif - - if (fast_time > 1) { - time_func = null_time; - } else if (fast_time) { - uint64_t timea; - uint64_t timeb; - clock_time (); - timea = clock_time (); - timeb = clock_time (); - time_inc = (timeb - timea) / TIME_ADJ; - /*printf ("time inc: %llu, timea: %llu, timeb: %llu, diff: %llu\n", time_inc, timea, timeb, timec-timeb);*/ - if (have_rdtsc ()) - time_func = rdtsc_current_time; - else - time_func = fast_current_time; - } else { - time_func = clock_time; - } - time_start = time_func (); - for (i = 0; i < 256; ++i) - time_func (); - time_end = time_func (); - timer_overhead = (time_end - time_start) / 256; -} - -int -get_timer_overhead (void) -{ - return timer_overhead; -} - -uint64_t -current_time (void) -{ - return time_func (); -} - -void* -alloc_buffer (int size) -{ - void *ptr; -#ifdef HOST_WIN32 - ptr = VirtualAlloc (NULL, size, MEM_COMMIT, PAGE_READWRITE); - return ptr; -#else - ptr = mmap (NULL, size, PROT_READ|PROT_WRITE, MAP_ANONYMOUS|MAP_PRIVATE, -1, 0); - if (ptr == MAP_FAILED) - return NULL; - return ptr; -#endif -} - -void -free_buffer (void *buf, int size) -{ -#ifdef HOST_WIN32 - VirtualFree (buf, 0, MEM_RELEASE); -#else - munmap (buf, size); -#endif -} - -void -take_lock (void) -{ -#ifdef HOST_WIN32 - EnterCriticalSection (&log_lock); -#else - pthread_mutex_lock (&log_lock); -#endif -} - -void -release_lock (void) -{ -#ifdef HOST_WIN32 - LeaveCriticalSection (&log_lock); -#else - pthread_mutex_unlock (&log_lock); -#endif -} - -void -encode_uleb128 (uint64_t value, uint8_t *buf, uint8_t **endbuf) -{ - uint8_t *p = buf; - - do { - uint8_t b = value & 0x7f; - value >>= 7; - if (value != 0) /* more bytes to come */ - b |= 0x80; - *p ++ = b; - } while (value); - - *endbuf = p; -} - -void -encode_sleb128 (intptr_t value, uint8_t *buf, uint8_t **endbuf) -{ - int more = 1; - int negative = (value < 0); - unsigned int size = sizeof (intptr_t) * 8; - uint8_t byte; - uint8_t *p = buf; - - while (more) { - byte = value & 0x7f; - value >>= 7; - /* the following is unnecessary if the - * implementation of >>= uses an arithmetic rather - * than logical shift for a signed left operand - */ - if (negative) - /* sign extend */ - value |= - ((intptr_t)1 <<(size - 7)); - /* sign bit of byte is second high order bit (0x40) */ - if ((value == 0 && !(byte & 0x40)) || - (value == -1 && (byte & 0x40))) - more = 0; - else - byte |= 0x80; - *p ++= byte; - } - - *endbuf = p; -} - -uint64_t -decode_uleb128 (uint8_t *buf, uint8_t **endbuf) -{ - uint64_t res = 0; - int shift = 0; - - while (1) { - uint8_t b = *buf++; - - res |= (((uint64_t)(b & 0x7f)) << shift); - if (!(b & 0x80)) - break; - shift += 7; - } - - *endbuf = buf; - - return res; -} - -intptr_t -decode_sleb128 (uint8_t *buf, uint8_t **endbuf) -{ - uint8_t *p = buf; - intptr_t res = 0; - int shift = 0; - - while (1) { - uint8_t b = *p; - p ++; - - res = res | (((intptr_t)(b & 0x7f)) << shift); - shift += 7; - if (!(b & 0x80)) { - if (shift < sizeof (intptr_t) * 8 && (b & 0x40)) - res |= - ((intptr_t)1 << shift); - break; - } - } - - *endbuf = p; - - return res; -} - -uintptr_t -thread_id (void) -{ -#ifdef HOST_WIN32 - return (uintptr_t)GetCurrentThreadId (); -#else - return (uintptr_t)pthread_self (); -#endif -} - -uintptr_t -process_id (void) -{ -#ifdef HOST_WIN32 - return GetCurrentProcessId (); -#else - return (uintptr_t)getpid (); -#endif -} - diff --git a/mono/profiler/utils.h b/mono/profiler/utils.h deleted file mode 100644 index 3af56d202c6..00000000000 --- a/mono/profiler/utils.h +++ /dev/null @@ -1,24 +0,0 @@ -#ifndef __MONO_MPLOG_UTILS_H__ -#define __MONO_MPLOG_UTILS_H__ - -#include "config.h" -#include "mono/utils/mono-publib.h" - -void utils_init (int fast_time); -int get_timer_overhead (void); -uint64_t current_time (void); -void* alloc_buffer (int size); -void free_buffer (void *buf, int size); -void take_lock (void); -void release_lock (void); -uintptr_t thread_id (void); -uintptr_t process_id (void); - -void encode_uleb128 (uint64_t value, uint8_t *buf, uint8_t **endbuf); -void encode_sleb128 (intptr_t value, uint8_t *buf, uint8_t **endbuf); -uint64_t decode_uleb128 (uint8_t *buf, uint8_t **endbuf); -intptr_t decode_sleb128 (uint8_t *buf, uint8_t **endbuf); - - -#endif /* __MONO_MPLOG_UTILS_H__ */ - |