2 * proflog.c: mono log profiler
5 * Paolo Molaro (lupus@ximian.com)
6 * Alex Rønne Petersen (alexrp@xamarin.com)
8 * Copyright 2010 Novell, Inc (http://www.novell.com)
9 * Copyright 2011 Xamarin Inc (http://www.xamarin.com)
13 #include "../mini/jit.h"
14 #include <mono/metadata/profiler.h>
15 #include <mono/metadata/threads.h>
16 #include <mono/metadata/mono-gc.h>
17 #include <mono/metadata/debug-helpers.h>
18 #include <mono/metadata/mono-perfcounters.h>
19 #include <mono/metadata/appdomain.h>
20 #include <mono/metadata/assembly.h>
21 #include <mono/metadata/tokentype.h>
22 #include <mono/metadata/tabledefs.h>
23 #include <mono/utils/atomic.h>
24 #include <mono/utils/mono-membar.h>
25 #include <mono/utils/mono-counters.h>
26 #include <mono/utils/mono-mutex.h>
27 #include <mono/utils/mono-conc-hashtable.h>
28 #include <mono/utils/lock-free-queue.h>
38 #if defined(HOST_WIN32) || defined(DISABLE_SOCKETS)
39 #define DISABLE_HELPER_THREAD 1
48 #ifdef HAVE_EXECINFO_H
55 #ifndef DISABLE_HELPER_THREAD
56 #include <sys/types.h>
57 #include <sys/socket.h>
58 #include <netinet/in.h>
59 #include <sys/select.h>
68 #ifdef HAVE_SYS_STAT_H
75 #if defined (HAVE_SYS_ZLIB)
79 #if defined(__linux__)
82 #include <sys/syscall.h>
83 #include "perf_event.h"
85 #ifdef ENABLE_PERF_EVENTS
86 #define USE_PERF_EVENTS 1
88 static int read_perf_mmap (MonoProfiler* prof, int cpu);
93 #define BUFFER_SIZE (4096 * 16)
95 /* Worst-case size in bytes of a 64-bit value encoded with LEB128. */
96 #define LEB128_SIZE 10
97 /* Size in bytes of the event ID prefix. */
100 static int nocalls = 0;
101 static int notraces = 0;
102 static int use_zip = 0;
103 static int do_report = 0;
104 static int do_heap_shot = 0;
105 static int max_call_depth = 100;
106 static volatile int runtime_inited = 0;
107 static int need_helper_thread = 0;
108 static int command_port = 0;
109 static int heapshot_requested = 0;
110 static int sample_type = 0;
111 static int sample_freq = 0;
112 static int do_mono_sample = 0;
113 static int in_shutdown = 0;
114 static int do_debug = 0;
115 static int do_counters = 0;
116 static int do_coverage = 0;
117 static gboolean debug_coverage = FALSE;
118 static MonoProfileSamplingMode sampling_mode = MONO_PROFILER_STAT_MODE_PROCESS;
120 typedef struct _LogBuffer LogBuffer;
126 * The file is composed by a header followed by 0 or more buffers.
127 * Each buffer contains events that happened on a thread: for a given thread
128 * buffers that appear later in the file are guaranteed to contain events
129 * that happened later in time. Buffers from separate threads could be interleaved,
131 * Buffers are not required to be aligned.
134 * [id: 4 bytes] constant value: LOG_HEADER_ID
135 * [major: 1 byte] [minor: 1 byte] major and minor version of the log profiler
136 * [format: 1 byte] version of the data format for the rest of the file
137 * [ptrsize: 1 byte] size in bytes of a pointer in the profiled program
138 * [startup time: 8 bytes] time in milliseconds since the unix epoch when the program started
139 * [timer overhead: 4 bytes] approximate overhead in nanoseconds of the timer
140 * [flags: 4 bytes] file format flags, should be 0 for now
141 * [pid: 4 bytes] pid of the profiled process
142 * [port: 2 bytes] tcp port for server if != 0
143 * [sysid: 2 bytes] operating system and architecture identifier
145 * The multiple byte integers are in little-endian format.
148 * [buffer header] [event]*
149 * Buffers have a fixed-size header followed by 0 or more bytes of event data.
150 * Timing information and other values in the event data are usually stored
151 * as uleb128 or sleb128 integers. To save space, as noted for each item below,
152 * some data is represented as a difference between the actual value and
153 * either the last value of the same type (like for timing information) or
154 * as the difference from a value stored in a buffer header.
156 * For timing information the data is stored as uleb128, since timing
157 * increases in a monotonic way in each thread: the value is the number of
158 * nanoseconds to add to the last seen timing data in a buffer. The first value
159 * in a buffer will be calculated from the time_base field in the buffer head.
161 * Object or heap sizes are stored as uleb128.
162 * Pointer differences are stored as sleb128, instead.
164 * If an unexpected value is found, the rest of the buffer should be ignored,
165 * as generally the later values need the former to be interpreted correctly.
167 * buffer header format:
168 * [bufid: 4 bytes] constant value: BUF_ID
169 * [len: 4 bytes] size of the data following the buffer header
170 * [time_base: 8 bytes] time base in nanoseconds since an unspecified epoch
171 * [ptr_base: 8 bytes] base value for pointers
172 * [obj_base: 8 bytes] base value for object addresses
173 * [thread id: 8 bytes] system-specific thread ID (pthread_t for example)
174 * [method_base: 8 bytes] base value for MonoMethod pointers
177 * [extended info: upper 4 bits] [type: lower 4 bits] [data]*
178 * The data that follows depends on type and the extended info.
179 * Type is one of the enum values in proflog.h: TYPE_ALLOC, TYPE_GC,
180 * TYPE_METADATA, TYPE_METHOD, TYPE_EXCEPTION, TYPE_MONITOR, TYPE_HEAP.
181 * The extended info bits are interpreted based on type, see
182 * each individual event description below.
183 * strings are represented as a 0-terminated utf8 sequence.
186 * [flags: uleb128] must be 0
187 * [num: uleb128] number of frames following
188 * [frame: sleb128]* num MonoMethod pointers as differences from ptr_base
192 * exinfo: flags: TYPE_ALLOC_BT
193 * [time diff: uleb128] nanoseconds since last timing
194 * [ptr: sleb128] class as a byte difference from ptr_base
195 * [obj: sleb128] object address as a byte difference from obj_base
196 * [size: uleb128] size of the object in the heap
197 * If the TYPE_ALLOC_BT flag is set, a backtrace follows.
201 * exinfo: one of TYPE_GC_EVENT, TYPE_GC_RESIZE, TYPE_GC_MOVE, TYPE_GC_HANDLE_CREATED[_BT],
202 * TYPE_GC_HANDLE_DESTROYED[_BT]
203 * [time diff: uleb128] nanoseconds since last timing
204 * if exinfo == TYPE_GC_RESIZE
205 * [heap_size: uleb128] new heap size
206 * if exinfo == TYPE_GC_EVENT
207 * [event type: uleb128] GC event (MONO_GC_EVENT_* from profiler.h)
208 * [generation: uleb128] GC generation event refers to
209 * if exinfo == TYPE_GC_MOVE
210 * [num_objects: uleb128] number of object moves that follow
211 * [objaddr: sleb128]+ num_objects object pointer differences from obj_base
212 * num is always an even number: the even items are the old
213 * addresses, the odd numbers are the respective new object addresses
214 * if exinfo == TYPE_GC_HANDLE_CREATED[_BT]
215 * [handle_type: uleb128] GC handle type (System.Runtime.InteropServices.GCHandleType)
216 * upper bits reserved as flags
217 * [handle: uleb128] GC handle value
218 * [objaddr: sleb128] object pointer differences from obj_base
219 * If exinfo == TYPE_GC_HANDLE_CREATED_BT, a backtrace follows.
220 * if exinfo == TYPE_GC_HANDLE_DESTROYED[_BT]
221 * [handle_type: uleb128] GC handle type (System.Runtime.InteropServices.GCHandleType)
222 * upper bits reserved as flags
223 * [handle: uleb128] GC handle value
224 * If exinfo == TYPE_GC_HANDLE_DESTROYED_BT, a backtrace follows.
226 * type metadata format:
227 * type: TYPE_METADATA
228 * exinfo: one of: TYPE_END_LOAD, TYPE_END_UNLOAD (optional for TYPE_THREAD and TYPE_DOMAIN)
229 * [time diff: uleb128] nanoseconds since last timing
230 * [mtype: byte] metadata type, one of: TYPE_CLASS, TYPE_IMAGE, TYPE_ASSEMBLY, TYPE_DOMAIN,
231 * TYPE_THREAD, TYPE_CONTEXT
232 * [pointer: sleb128] pointer of the metadata type depending on mtype
233 * if mtype == TYPE_CLASS
234 * [image: sleb128] MonoImage* as a pointer difference from ptr_base
235 * [flags: uleb128] must be 0
236 * [name: string] full class name
237 * if mtype == TYPE_IMAGE
238 * [flags: uleb128] must be 0
239 * [name: string] image file name
240 * if mtype == TYPE_ASSEMBLY
241 * [flags: uleb128] must be 0
242 * [name: string] assembly name
243 * if mtype == TYPE_DOMAIN
244 * [flags: uleb128] must be 0
245 * if mtype == TYPE_DOMAIN && exinfo == 0
246 * [name: string] domain friendly name
247 * if mtype == TYPE_CONTEXT
248 * [flags: uleb128] must be 0
249 * [domain: sleb128] domain id as pointer
250 * if mtype == TYPE_THREAD && (format_version < 11 || (format_version > 10 && exinfo == 0))
251 * [flags: uleb128] must be 0
252 * [name: string] thread name
254 * type method format:
256 * exinfo: one of: TYPE_LEAVE, TYPE_ENTER, TYPE_EXC_LEAVE, TYPE_JIT
257 * [time diff: uleb128] nanoseconds since last timing
258 * [method: sleb128] MonoMethod* as a pointer difference from the last such
259 * pointer or the buffer method_base
260 * if exinfo == TYPE_JIT
261 * [code address: sleb128] pointer to the native code as a diff from ptr_base
262 * [code size: uleb128] size of the generated code
263 * [name: string] full method name
265 * type runtime format:
267 * exinfo: one of: TYPE_JITHELPER
268 * [time diff: uleb128] nanoseconds since last timing
269 * if exinfo == TYPE_JITHELPER
270 * [type: uleb128] MonoProfilerCodeBufferType enum value
271 * [buffer address: sleb128] pointer to the native code as a diff from ptr_base
272 * [buffer size: uleb128] size of the generated code
273 * if type == MONO_PROFILER_CODE_BUFFER_SPECIFIC_TRAMPOLINE
274 * [name: string] buffer description name
276 * type monitor format:
278 * exinfo: TYPE_MONITOR_BT flag and one of: MONO_PROFILER_MONITOR_(CONTENTION|FAIL|DONE)
279 * [time diff: uleb128] nanoseconds since last timing
280 * [object: sleb128] the lock object as a difference from obj_base
281 * if exinfo.low3bits == MONO_PROFILER_MONITOR_CONTENTION
282 * If the TYPE_MONITOR_BT flag is set, a backtrace follows.
286 * exinfo: one of TYPE_HEAP_START, TYPE_HEAP_END, TYPE_HEAP_OBJECT, TYPE_HEAP_ROOT
287 * if exinfo == TYPE_HEAP_START
288 * [time diff: uleb128] nanoseconds since last timing
289 * if exinfo == TYPE_HEAP_END
290 * [time diff: uleb128] nanoseconds since last timing
291 * if exinfo == TYPE_HEAP_OBJECT
292 * [object: sleb128] the object as a difference from obj_base
293 * [class: sleb128] the object MonoClass* as a difference from ptr_base
294 * [size: uleb128] size of the object on the heap
295 * [num_refs: uleb128] number of object references
296 * if (format version > 1) each referenced objref is preceded by a
297 * uleb128 encoded offset: the first offset is from the object address
298 * and each next offset is relative to the previous one
299 * [objrefs: sleb128]+ object referenced as a difference from obj_base
300 * The same object can appear multiple times, but only the first time
301 * with size != 0: in the other cases this data will only be used to
302 * provide additional referenced objects.
303 * if exinfo == TYPE_HEAP_ROOT
304 * [num_roots: uleb128] number of root references
305 * [num_gc: uleb128] number of major gcs
306 * [object: sleb128] the object as a difference from obj_base
307 * [root_type: uleb128] the root_type: MonoProfileGCRootType (profiler.h)
308 * [extra_info: uleb128] the extra_info value
309 * object, root_type and extra_info are repeated num_roots times
313 * exinfo: one of TYPE_SAMPLE_HIT, TYPE_SAMPLE_USYM, TYPE_SAMPLE_UBIN, TYPE_SAMPLE_COUNTERS_DESC, TYPE_SAMPLE_COUNTERS
314 * if exinfo == TYPE_SAMPLE_HIT
315 * [sample_type: uleb128] type of sample (SAMPLE_*)
316 * [timestamp: uleb128] nanoseconds since startup (note: different from other timestamps!)
317 * if (format_version > 10)
318 * [thread: sleb128] thread id as difference from ptr_base
319 * [count: uleb128] number of following instruction addresses
320 * [ip: sleb128]* instruction pointer as difference from ptr_base
321 * if (format_version > 5)
322 * [mbt_count: uleb128] number of managed backtrace info triplets (method + IL offset + native offset)
323 * [method: sleb128]* MonoMethod* as a pointer difference from the last such
324 * pointer or the buffer method_base (the first such method can be also indentified by ip, but this is not neccessarily true)
325 * [il_offset: sleb128]* IL offset inside method where the hit occurred
326 * [native_offset: sleb128]* native offset inside method where the hit occurred
327 * if exinfo == TYPE_SAMPLE_USYM
328 * [address: sleb128] symbol address as a difference from ptr_base
329 * [size: uleb128] symbol size (may be 0 if unknown)
330 * [name: string] symbol name
331 * if exinfo == TYPE_SAMPLE_UBIN
332 * [time diff: uleb128] nanoseconds since last timing
333 * [address: sleb128] address where binary has been loaded
334 * [offset: uleb128] file offset of mapping (the same file can be mapped multiple times)
335 * [size: uleb128] memory size
336 * [name: string] binary name
337 * if exinfo == TYPE_SAMPLE_COUNTERS_DESC
338 * [len: uleb128] number of counters
340 * [section: uleb128] section of counter
341 * if section == MONO_COUNTER_PERFCOUNTERS:
342 * [section_name: string] section name of counter
343 * [name: string] name of counter
344 * [type: uleb128] type of counter
345 * [unit: uleb128] unit of counter
346 * [variance: uleb128] variance of counter
347 * [index: uleb128] unique index of counter
348 * if exinfo == TYPE_SAMPLE_COUNTERS
349 * [timestamp: uleb128] sampling timestamp
351 * [index: uleb128] unique index of counter
354 * [type: uleb128] type of counter value
357 * [0: uleb128] 0 -> value is null
359 * [1: uleb128] 1 -> value is not null
360 * [value: string] counter value
362 * [value: uleb128/sleb128/double] counter value, can be sleb128, uleb128 or double (determined by using type)
364 * type coverage format
365 * type: TYPE_COVERAGE
366 * exinfo: one of TYPE_COVERAGE_METHOD, TYPE_COVERAGE_STATEMENT, TYPE_COVERAGE_ASSEMBLY, TYPE_COVERAGE_CLASS
367 * if exinfo == TYPE_COVERAGE_METHOD
368 * [assembly: string] name of assembly
369 * [class: string] name of the class
370 * [name: string] name of the method
371 * [signature: string] the signature of the method
372 * [filename: string] the file path of the file that contains this method
373 * [token: uleb128] the method token
374 * [method_id: uleb128] an ID for this data to associate with the buffers of TYPE_COVERAGE_STATEMENTS
375 * [len: uleb128] the number of TYPE_COVERAGE_BUFFERS associated with this method
376 * if exinfo == TYPE_COVERAGE_STATEMENTS
377 * [method_id: uleb128] an the TYPE_COVERAGE_METHOD buffer to associate this with
378 * [offset: uleb128] the il offset relative to the previous offset
379 * [counter: uleb128] the counter for this instruction
380 * [line: uleb128] the line of filename containing this instruction
381 * [column: uleb128] the column containing this instruction
382 * if exinfo == TYPE_COVERAGE_ASSEMBLY
383 * [name: string] assembly name
384 * [guid: string] assembly GUID
385 * [filename: string] assembly filename
386 * [number_of_methods: uleb128] the number of methods in this assembly
387 * [fully_covered: uleb128] the number of fully covered methods
388 * [partially_covered: uleb128] the number of partially covered methods
389 * currently partially_covered will always be 0, and fully_covered is the
390 * number of methods that are fully and partially covered.
391 * if exinfo == TYPE_COVERAGE_CLASS
392 * [name: string] assembly name
393 * [class: string] class name
394 * [number_of_methods: uleb128] the number of methods in this class
395 * [fully_covered: uleb128] the number of fully covered methods
396 * [partially_covered: uleb128] the number of partially covered methods
397 * currently partially_covered will always be 0, and fully_covered is the
398 * number of methods that are fully and partially covered.
402 * Format oddities that we ought to fix:
404 * - Methods written in emit_bt () should be based on the buffer's base
405 * method instead of the base pointer.
406 * - The TYPE_SAMPLE_HIT event contains (currently) pointless data like
407 * always-one unmanaged frame count and always-zero IL offsets.
409 * These are mostly small things and are not worth a format change by
410 * themselves. They should be done when some other major change has to
411 * be done to the format.
419 uintptr_t method_base;
420 uintptr_t last_method;
423 unsigned char* data_end;
428 unsigned char buf [1];
432 ign_res (int G_GNUC_UNUSED unused, ...)
436 #define ENTER_LOG(lb,str) if ((lb)->locked) {ign_res (write(2, str, strlen(str))); ign_res (write(2, "\n", 1));return;} else {(lb)->locked++;}
437 #define EXIT_LOG(lb) (lb)->locked--;
439 typedef struct _StatBuffer StatBuffer;
448 typedef struct _BinaryObject BinaryObject;
450 struct _BinaryObject {
456 struct _MonoProfiler {
457 StatBuffer *stat_buffers;
459 #if defined (HAVE_SYS_ZLIB)
462 uint64_t startup_time;
464 int last_gc_gen_started;
469 pthread_t helper_thread;
470 pthread_t writer_thread;
472 volatile gint32 run_writer_thread;
473 MonoLockFreeQueue writer_queue;
474 MonoConcurrentHashTable *method_table;
475 mono_mutex_t method_table_mutex;
476 BinaryObject *binary_objects;
477 GPtrArray *coverage_filters;
478 GPtrArray *sorted_sample_events;
481 typedef struct _WriterQueueEntry WriterQueueEntry;
482 struct _WriterQueueEntry {
483 MonoLockFreeQueueNode node;
488 typedef struct _MethodInfo MethodInfo;
499 #define TLS_SET(x,y) (TlsSetValue (x, y))
500 #define TLS_GET(t,x) ((t *) TlsGetValue (x))
501 #define TLS_INIT(x) (x = TlsAlloc ())
502 static int tlsbuffer;
503 static int tlsmethodlist;
505 #define TLS_SET(x,y) (x = y)
506 #define TLS_GET(t,x) (x)
508 static __thread LogBuffer* tlsbuffer = NULL;
509 static __thread GPtrArray* tlsmethodlist = NULL;
511 #define TLS_SET(x,y) (pthread_setspecific (x, y))
512 #define TLS_GET(t,x) ((t *) pthread_getspecific (x))
513 #define TLS_INIT(x) (pthread_key_create (&x, NULL))
514 static pthread_key_t tlsbuffer;
515 static pthread_key_t tlsmethodlist;
518 static void safe_send (MonoProfiler *profiler, LogBuffer *logbuffer);
521 pstrdup (const char *s)
523 int len = strlen (s) + 1;
524 char *p = malloc (len);
530 create_stat_buffer (void)
532 StatBuffer* buf = alloc_buffer (BUFFER_SIZE);
533 buf->size = BUFFER_SIZE;
534 buf->data_end = (uintptr_t*)((unsigned char*)buf + buf->size);
535 buf->data = buf->buf;
542 LogBuffer* buf = alloc_buffer (BUFFER_SIZE);
543 buf->size = BUFFER_SIZE;
544 buf->time_base = current_time ();
545 buf->last_time = buf->time_base;
546 buf->data_end = (unsigned char*)buf + buf->size;
547 buf->data = buf->buf;
554 if (!TLS_GET (LogBuffer, tlsbuffer)) {
555 LogBuffer *logbuffer = create_buffer ();
556 TLS_SET (tlsbuffer, logbuffer);
557 logbuffer->thread_id = thread_id ();
559 if (!TLS_GET (GPtrArray, tlsmethodlist)) {
560 GPtrArray *methodlist = g_ptr_array_new ();
561 TLS_SET (tlsmethodlist, methodlist);
564 //printf ("thread %p at time %llu\n", (void*)logbuffer->thread_id, logbuffer->time_base);
568 ensure_logbuf_inner (LogBuffer *old, int bytes)
570 if (old && old->data + bytes + 100 < old->data_end)
573 LogBuffer *new = create_buffer ();
574 new->thread_id = thread_id ();
578 new->call_depth = old->call_depth;
584 ensure_logbuf (int bytes)
586 LogBuffer *old = TLS_GET (LogBuffer, tlsbuffer);
587 LogBuffer *new = ensure_logbuf_inner (old, bytes);
590 return old; // Still enough space.
592 TLS_SET (tlsbuffer, new);
599 emit_byte (LogBuffer *logbuffer, int value)
601 logbuffer->data [0] = value;
603 assert (logbuffer->data <= logbuffer->data_end);
607 emit_value (LogBuffer *logbuffer, int value)
609 encode_uleb128 (value, logbuffer->data, &logbuffer->data);
610 assert (logbuffer->data <= logbuffer->data_end);
614 emit_time (LogBuffer *logbuffer, uint64_t value)
616 uint64_t tdiff = value - logbuffer->last_time;
617 if (value < logbuffer->last_time)
618 printf ("time went backwards\n");
619 //if (tdiff > 1000000)
620 // printf ("large time offset: %llu\n", tdiff);
621 encode_uleb128 (tdiff, logbuffer->data, &logbuffer->data);
622 /*if (tdiff != decode_uleb128 (p, &p))
623 printf ("incorrect encoding: %llu\n", tdiff);*/
624 logbuffer->last_time = value;
625 assert (logbuffer->data <= logbuffer->data_end);
629 emit_svalue (LogBuffer *logbuffer, int64_t value)
631 encode_sleb128 (value, logbuffer->data, &logbuffer->data);
632 assert (logbuffer->data <= logbuffer->data_end);
636 emit_uvalue (LogBuffer *logbuffer, uint64_t value)
638 encode_uleb128 (value, logbuffer->data, &logbuffer->data);
639 assert (logbuffer->data <= logbuffer->data_end);
643 emit_ptr (LogBuffer *logbuffer, void *ptr)
645 if (!logbuffer->ptr_base)
646 logbuffer->ptr_base = (uintptr_t)ptr;
647 emit_svalue (logbuffer, (intptr_t)ptr - logbuffer->ptr_base);
648 assert (logbuffer->data <= logbuffer->data_end);
652 emit_method_inner (LogBuffer *logbuffer, void *method)
654 if (!logbuffer->method_base) {
655 logbuffer->method_base = (intptr_t)method;
656 logbuffer->last_method = (intptr_t)method;
658 encode_sleb128 ((intptr_t)((char*)method - (char*)logbuffer->last_method), logbuffer->data, &logbuffer->data);
659 logbuffer->last_method = (intptr_t)method;
660 assert (logbuffer->data <= logbuffer->data_end);
669 find_method (MonoDomain *domain, void *user_data)
671 MethodSearch *search = user_data;
676 MonoJitInfo *ji = mono_get_jit_info_from_method (domain, search->method);
678 // It could be AOT'd, so we need to get it from the AOT runtime's cache.
680 void *ip = mono_aot_get_method (domain, search->method);
682 // Avoid a slow path in mono_jit_info_table_find ().
684 ji = mono_jit_info_table_find (domain, ip);
692 register_method_local (MonoProfiler *prof, MonoMethod *method, MonoJitInfo *ji)
694 if (!mono_conc_hashtable_lookup (prof->method_table, method)) {
696 MethodSearch search = { method, NULL };
698 mono_domain_foreach (find_method, &search);
705 MethodInfo *info = malloc (sizeof (MethodInfo));
707 info->method = method;
710 g_ptr_array_add (TLS_GET (GPtrArray, tlsmethodlist), info);
715 emit_method (MonoProfiler *prof, LogBuffer *logbuffer, MonoMethod *method)
717 register_method_local (prof, method, NULL);
718 emit_method_inner (logbuffer, method);
722 emit_method_as_ptr (MonoProfiler *prof, LogBuffer *logbuffer, MonoMethod *method)
724 register_method_local (prof, method, NULL);
725 emit_ptr (logbuffer, method);
729 emit_obj (LogBuffer *logbuffer, void *ptr)
731 if (!logbuffer->obj_base)
732 logbuffer->obj_base = (uintptr_t)ptr >> 3;
733 emit_svalue (logbuffer, ((uintptr_t)ptr >> 3) - logbuffer->obj_base);
734 assert (logbuffer->data <= logbuffer->data_end);
738 emit_string (LogBuffer *logbuffer, const char *str, size_t size)
742 for (; i < size; i++) {
745 emit_byte (logbuffer, str [i]);
748 emit_byte (logbuffer, '\0');
752 emit_double (LogBuffer *logbuffer, double value)
755 unsigned char buffer[8];
756 memcpy (buffer, &value, 8);
757 #if G_BYTE_ORDER == G_BIG_ENDIAN
758 for (i = 7; i >= 0; i--)
760 for (i = 0; i < 8; i++)
762 emit_byte (logbuffer, buffer[i]);
766 write_int16 (char *buf, int32_t value)
769 for (i = 0; i < 2; ++i) {
777 write_int32 (char *buf, int32_t value)
780 for (i = 0; i < 4; ++i) {
788 write_int64 (char *buf, int64_t value)
791 for (i = 0; i < 8; ++i) {
799 dump_header (MonoProfiler *profiler)
803 p = write_int32 (p, LOG_HEADER_ID);
804 *p++ = LOG_VERSION_MAJOR;
805 *p++ = LOG_VERSION_MINOR;
806 *p++ = LOG_DATA_VERSION;
807 *p++ = sizeof (void*);
808 p = write_int64 (p, ((uint64_t)time (NULL)) * 1000); /* startup time */
809 p = write_int32 (p, get_timer_overhead ()); /* timer overhead */
810 p = write_int32 (p, 0); /* flags */
811 p = write_int32 (p, process_id ()); /* pid */
812 p = write_int16 (p, profiler->command_port); /* port */
813 p = write_int16 (p, 0); /* opsystem */
814 #if defined (HAVE_SYS_ZLIB)
815 if (profiler->gzfile) {
816 gzwrite (profiler->gzfile, hbuf, p - hbuf);
818 fwrite (hbuf, p - hbuf, 1, profiler->file);
821 fwrite (hbuf, p - hbuf, 1, profiler->file);
822 fflush (profiler->file);
827 send_buffer (MonoProfiler *prof, GPtrArray *methods, LogBuffer *buffer)
829 WriterQueueEntry *entry = calloc (1, sizeof (WriterQueueEntry));
830 mono_lock_free_queue_node_init (&entry->node, FALSE);
831 entry->methods = methods;
832 entry->buffer = buffer;
833 mono_lock_free_queue_enqueue (&prof->writer_queue, &entry->node);
837 dump_buffer (MonoProfiler *profiler, LogBuffer *buf)
842 dump_buffer (profiler, buf->next);
843 p = write_int32 (p, BUF_ID);
844 p = write_int32 (p, buf->data - buf->buf);
845 p = write_int64 (p, buf->time_base);
846 p = write_int64 (p, buf->ptr_base);
847 p = write_int64 (p, buf->obj_base);
848 p = write_int64 (p, buf->thread_id);
849 p = write_int64 (p, buf->method_base);
850 #if defined (HAVE_SYS_ZLIB)
851 if (profiler->gzfile) {
852 gzwrite (profiler->gzfile, hbuf, p - hbuf);
853 gzwrite (profiler->gzfile, buf->buf, buf->data - buf->buf);
856 fwrite (hbuf, p - hbuf, 1, profiler->file);
857 fwrite (buf->buf, buf->data - buf->buf, 1, profiler->file);
858 fflush (profiler->file);
859 #if defined (HAVE_SYS_ZLIB)
862 free_buffer (buf, buf->size);
866 process_requests (MonoProfiler *profiler)
868 if (heapshot_requested)
869 mono_gc_collect (mono_gc_max_generation ());
872 static void counters_init (MonoProfiler *profiler);
873 static void counters_sample (MonoProfiler *profiler, uint64_t timestamp);
876 * Can be called only at safe callback locations.
879 safe_send (MonoProfiler *profiler, LogBuffer *logbuffer)
881 /* We need the runtime initialized so that we have threads and hazard
882 * pointers available. Otherwise, the lock free queue will not work and
883 * there won't be a thread to process the data.
885 * While the runtime isn't initialized, we just accumulate data in the
886 * thread local buffer list.
888 if (!InterlockedRead (&runtime_inited))
891 int cd = logbuffer->call_depth;
893 send_buffer (profiler, TLS_GET (GPtrArray, tlsmethodlist), TLS_GET (LogBuffer, tlsbuffer));
895 TLS_SET (tlsbuffer, NULL);
896 TLS_SET (tlsmethodlist, NULL);
900 TLS_GET (LogBuffer, tlsbuffer)->call_depth = cd;
904 gc_reference (MonoObject *obj, MonoClass *klass, uintptr_t size, uintptr_t num, MonoObject **refs, uintptr_t *offsets, void *data)
907 uintptr_t last_offset = 0;
908 //const char *name = mono_class_get_name (klass);
909 LogBuffer *logbuffer = ensure_logbuf (
910 EVENT_SIZE /* event */ +
911 LEB128_SIZE /* obj */ +
912 LEB128_SIZE /* klass */ +
913 LEB128_SIZE /* size */ +
914 LEB128_SIZE /* num */ +
916 LEB128_SIZE /* offset */ +
917 LEB128_SIZE /* ref */
920 emit_byte (logbuffer, TYPE_HEAP_OBJECT | TYPE_HEAP);
921 emit_obj (logbuffer, obj);
922 emit_ptr (logbuffer, klass);
923 /* account for object alignment in the heap */
926 emit_value (logbuffer, size);
927 emit_value (logbuffer, num);
928 for (i = 0; i < num; ++i) {
929 emit_value (logbuffer, offsets [i] - last_offset);
930 last_offset = offsets [i];
931 emit_obj (logbuffer, refs [i]);
934 // printf ("obj: %p, klass: %s, refs: %d, size: %d\n", obj, name, (int)num, (int)size);
938 static unsigned int hs_mode_ms = 0;
939 static unsigned int hs_mode_gc = 0;
940 static unsigned int hs_mode_ondemand = 0;
941 static unsigned int gc_count = 0;
942 static uint64_t last_hs_time = 0;
945 heap_walk (MonoProfiler *profiler)
949 LogBuffer *logbuffer;
952 logbuffer = ensure_logbuf (
953 EVENT_SIZE /* event */ +
954 LEB128_SIZE /* time */
956 now = current_time ();
957 if (hs_mode_ms && (now - last_hs_time)/1000000 >= hs_mode_ms)
959 else if (hs_mode_gc && (gc_count % hs_mode_gc) == 0)
961 else if (hs_mode_ondemand)
962 do_walk = heapshot_requested;
963 else if (!hs_mode_ms && !hs_mode_gc && profiler->last_gc_gen_started == mono_gc_max_generation ())
968 heapshot_requested = 0;
969 emit_byte (logbuffer, TYPE_HEAP_START | TYPE_HEAP);
970 emit_time (logbuffer, now);
971 mono_gc_walk_heap (0, gc_reference, NULL);
972 logbuffer = ensure_logbuf (
973 EVENT_SIZE /* event */ +
974 LEB128_SIZE /* time */
976 now = current_time ();
977 emit_byte (logbuffer, TYPE_HEAP_END | TYPE_HEAP);
978 emit_time (logbuffer, now);
983 gc_event (MonoProfiler *profiler, MonoGCEvent ev, int generation) {
985 LogBuffer *logbuffer = ensure_logbuf (
986 EVENT_SIZE /* event */ +
987 LEB128_SIZE /* time */ +
988 LEB128_SIZE /* gc event */ +
989 LEB128_SIZE /* generation */
991 now = current_time ();
992 ENTER_LOG (logbuffer, "gcevent");
993 emit_byte (logbuffer, TYPE_GC_EVENT | TYPE_GC);
994 emit_time (logbuffer, now);
995 emit_value (logbuffer, ev);
996 emit_value (logbuffer, generation);
997 /* to deal with nested gen1 after gen0 started */
998 if (ev == MONO_GC_EVENT_START) {
999 profiler->last_gc_gen_started = generation;
1000 if (generation == mono_gc_max_generation ())
1003 if (ev == MONO_GC_EVENT_PRE_START_WORLD)
1004 heap_walk (profiler);
1005 EXIT_LOG (logbuffer);
1006 if (ev == MONO_GC_EVENT_POST_START_WORLD)
1007 safe_send (profiler, logbuffer);
1008 //printf ("gc event %d for generation %d\n", ev, generation);
1012 gc_resize (MonoProfiler *profiler, int64_t new_size) {
1014 LogBuffer *logbuffer = ensure_logbuf (
1015 EVENT_SIZE /* event */ +
1016 LEB128_SIZE /* time */ +
1017 LEB128_SIZE /* new size */
1019 now = current_time ();
1020 ENTER_LOG (logbuffer, "gcresize");
1021 emit_byte (logbuffer, TYPE_GC_RESIZE | TYPE_GC);
1022 emit_time (logbuffer, now);
1023 emit_value (logbuffer, new_size);
1024 //printf ("gc resized to %lld\n", new_size);
1025 EXIT_LOG (logbuffer);
1028 #define MAX_FRAMES 32
1031 MonoMethod* methods [MAX_FRAMES];
1032 int32_t il_offsets [MAX_FRAMES];
1033 int32_t native_offsets [MAX_FRAMES];
1035 static int num_frames = MAX_FRAMES;
1038 walk_stack (MonoMethod *method, int32_t native_offset, int32_t il_offset, mono_bool managed, void* data)
1040 FrameData *frame = data;
1041 if (method && frame->count < num_frames) {
1042 frame->il_offsets [frame->count] = il_offset;
1043 frame->native_offsets [frame->count] = native_offset;
1044 frame->methods [frame->count++] = method;
1045 //printf ("In %d %s at %d (native: %d)\n", frame->count, mono_method_get_name (method), il_offset, native_offset);
1047 return frame->count == num_frames;
1051 * a note about stack walks: they can cause more profiler events to fire,
1052 * so we need to make sure they don't happen after we started emitting an
1053 * event, hence the collect_bt/emit_bt split.
1056 collect_bt (FrameData *data)
1059 mono_stack_walk_no_il (walk_stack, data);
1063 emit_bt (MonoProfiler *prof, LogBuffer *logbuffer, FrameData *data)
1065 /* FIXME: this is actually tons of data and we should
1066 * just output it the first time and use an id the next
1068 if (data->count > num_frames)
1069 printf ("bad num frames: %d\n", data->count);
1070 emit_value (logbuffer, 0); /* flags */
1071 emit_value (logbuffer, data->count);
1072 //if (*p != data.count) {
1073 // printf ("bad num frames enc at %d: %d -> %d\n", count, data.count, *p); printf ("frames end: %p->%p\n", p, logbuffer->data); exit(0);}
1074 while (data->count) {
1075 emit_method_as_ptr (prof, logbuffer, data->methods [--data->count]);
1080 gc_alloc (MonoProfiler *prof, MonoObject *obj, MonoClass *klass)
1084 int do_bt = (nocalls && InterlockedRead (&runtime_inited) && !notraces)? TYPE_ALLOC_BT: 0;
1086 LogBuffer *logbuffer;
1087 len = mono_object_get_size (obj);
1088 /* account for object alignment in the heap */
1093 logbuffer = ensure_logbuf (
1094 EVENT_SIZE /* event */ +
1095 LEB128_SIZE /* time */ +
1096 LEB128_SIZE /* klass */ +
1097 LEB128_SIZE /* obj */ +
1098 LEB128_SIZE /* size */ +
1100 LEB128_SIZE /* flags */ +
1101 LEB128_SIZE /* count */ +
1103 LEB128_SIZE /* method */
1107 now = current_time ();
1108 ENTER_LOG (logbuffer, "gcalloc");
1109 emit_byte (logbuffer, do_bt | TYPE_ALLOC);
1110 emit_time (logbuffer, now);
1111 emit_ptr (logbuffer, klass);
1112 emit_obj (logbuffer, obj);
1113 emit_value (logbuffer, len);
1115 emit_bt (prof, logbuffer, &data);
1116 EXIT_LOG (logbuffer);
1117 if (logbuffer->next)
1118 safe_send (prof, logbuffer);
1119 process_requests (prof);
1120 //printf ("gc alloc %s at %p\n", mono_class_get_name (klass), obj);
1124 gc_moves (MonoProfiler *prof, void **objects, int num)
1128 LogBuffer *logbuffer = ensure_logbuf (
1129 EVENT_SIZE /* event */ +
1130 LEB128_SIZE /* time */ +
1131 LEB128_SIZE /* num */ +
1133 LEB128_SIZE /* object */
1136 now = current_time ();
1137 ENTER_LOG (logbuffer, "gcmove");
1138 emit_byte (logbuffer, TYPE_GC_MOVE | TYPE_GC);
1139 emit_time (logbuffer, now);
1140 emit_value (logbuffer, num);
1141 for (i = 0; i < num; ++i)
1142 emit_obj (logbuffer, objects [i]);
1143 //printf ("gc moved %d objects\n", num/2);
1144 EXIT_LOG (logbuffer);
1148 gc_roots (MonoProfiler *prof, int num, void **objects, int *root_types, uintptr_t *extra_info)
1151 LogBuffer *logbuffer = ensure_logbuf (
1152 EVENT_SIZE /* event */ +
1153 LEB128_SIZE /* num */ +
1154 LEB128_SIZE /* collections */ +
1156 LEB128_SIZE /* object */ +
1157 LEB128_SIZE /* root type */ +
1158 LEB128_SIZE /* extra info */
1161 ENTER_LOG (logbuffer, "gcroots");
1162 emit_byte (logbuffer, TYPE_HEAP_ROOT | TYPE_HEAP);
1163 emit_value (logbuffer, num);
1164 emit_value (logbuffer, mono_gc_collection_count (mono_gc_max_generation ()));
1165 for (i = 0; i < num; ++i) {
1166 emit_obj (logbuffer, objects [i]);
1167 emit_value (logbuffer, root_types [i]);
1168 emit_value (logbuffer, extra_info [i]);
1170 EXIT_LOG (logbuffer);
1174 gc_handle (MonoProfiler *prof, int op, int type, uintptr_t handle, MonoObject *obj)
1176 int do_bt = nocalls && InterlockedRead (&runtime_inited) && !notraces;
1183 LogBuffer *logbuffer = ensure_logbuf (
1184 EVENT_SIZE /* event */ +
1185 LEB128_SIZE /* time */ +
1186 LEB128_SIZE /* type */ +
1187 LEB128_SIZE /* handle */ +
1188 (op == MONO_PROFILER_GC_HANDLE_CREATED ? (
1189 LEB128_SIZE /* obj */
1192 LEB128_SIZE /* flags */ +
1193 LEB128_SIZE /* count */ +
1195 LEB128_SIZE /* method */
1200 now = current_time ();
1201 ENTER_LOG (logbuffer, "gchandle");
1203 if (op == MONO_PROFILER_GC_HANDLE_CREATED)
1204 emit_byte (logbuffer, (do_bt ? TYPE_GC_HANDLE_CREATED_BT : TYPE_GC_HANDLE_CREATED) | TYPE_GC);
1205 else if (op == MONO_PROFILER_GC_HANDLE_DESTROYED)
1206 emit_byte (logbuffer, (do_bt ? TYPE_GC_HANDLE_DESTROYED_BT : TYPE_GC_HANDLE_DESTROYED) | TYPE_GC);
1208 g_assert_not_reached ();
1210 emit_time (logbuffer, now);
1211 emit_value (logbuffer, type);
1212 emit_value (logbuffer, handle);
1214 if (op == MONO_PROFILER_GC_HANDLE_CREATED)
1215 emit_obj (logbuffer, obj);
1218 emit_bt (prof, logbuffer, &data);
1220 EXIT_LOG (logbuffer);
1221 process_requests (prof);
1225 push_nesting (char *p, MonoClass *klass)
1230 nesting = mono_class_get_nesting_type (klass);
1232 p = push_nesting (p, nesting);
1236 name = mono_class_get_name (klass);
1237 nspace = mono_class_get_namespace (klass);
1240 p += strlen (nspace);
1250 type_name (MonoClass *klass)
1254 push_nesting (buf, klass);
1255 p = malloc (strlen (buf) + 1);
1261 image_loaded (MonoProfiler *prof, MonoImage *image, int result)
1266 LogBuffer *logbuffer;
1267 if (result != MONO_PROFILE_OK)
1269 name = mono_image_get_filename (image);
1270 nlen = strlen (name) + 1;
1271 logbuffer = ensure_logbuf (
1272 EVENT_SIZE /* event */ +
1273 LEB128_SIZE /* time */ +
1274 EVENT_SIZE /* type */ +
1275 LEB128_SIZE /* image */ +
1276 LEB128_SIZE /* flags */ +
1279 now = current_time ();
1280 ENTER_LOG (logbuffer, "image");
1281 emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1282 emit_time (logbuffer, now);
1283 emit_byte (logbuffer, TYPE_IMAGE);
1284 emit_ptr (logbuffer, image);
1285 emit_value (logbuffer, 0); /* flags */
1286 memcpy (logbuffer->data, name, nlen);
1287 logbuffer->data += nlen;
1288 //printf ("loaded image %p (%s)\n", image, name);
1289 EXIT_LOG (logbuffer);
1290 if (logbuffer->next)
1291 safe_send (prof, logbuffer);
1292 process_requests (prof);
1296 image_unloaded (MonoProfiler *prof, MonoImage *image)
1298 const char *name = mono_image_get_filename (image);
1299 int nlen = strlen (name) + 1;
1300 LogBuffer *logbuffer = ensure_logbuf (
1301 EVENT_SIZE /* event */ +
1302 LEB128_SIZE /* time */ +
1303 EVENT_SIZE /* type */ +
1304 LEB128_SIZE /* image */ +
1305 LEB128_SIZE /* flags */ +
1308 uint64_t now = current_time ();
1310 ENTER_LOG (logbuffer, "image-unload");
1311 emit_byte (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
1312 emit_time (logbuffer, now);
1313 emit_byte (logbuffer, TYPE_IMAGE);
1314 emit_ptr (logbuffer, image);
1315 emit_value (logbuffer, 0); /* flags */
1316 memcpy (logbuffer->data, name, nlen);
1317 logbuffer->data += nlen;
1318 EXIT_LOG (logbuffer);
1320 if (logbuffer->next)
1321 safe_send (prof, logbuffer);
1323 process_requests (prof);
1327 assembly_loaded (MonoProfiler *prof, MonoAssembly *assembly, int result)
1329 if (result != MONO_PROFILE_OK)
1332 char *name = mono_stringify_assembly_name (mono_assembly_get_name (assembly));
1333 int nlen = strlen (name) + 1;
1334 LogBuffer *logbuffer = ensure_logbuf (
1335 EVENT_SIZE /* event */ +
1336 LEB128_SIZE /* time */ +
1337 EVENT_SIZE /* type */ +
1338 LEB128_SIZE /* assembly */ +
1339 LEB128_SIZE /* flags */ +
1342 uint64_t now = current_time ();
1344 ENTER_LOG (logbuffer, "assembly-load");
1345 emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1346 emit_time (logbuffer, now);
1347 emit_byte (logbuffer, TYPE_ASSEMBLY);
1348 emit_ptr (logbuffer, assembly);
1349 emit_value (logbuffer, 0); /* flags */
1350 memcpy (logbuffer->data, name, nlen);
1351 logbuffer->data += nlen;
1352 EXIT_LOG (logbuffer);
1356 if (logbuffer->next)
1357 safe_send (prof, logbuffer);
1359 process_requests (prof);
1363 assembly_unloaded (MonoProfiler *prof, MonoAssembly *assembly)
1365 char *name = mono_stringify_assembly_name (mono_assembly_get_name (assembly));
1366 int nlen = strlen (name) + 1;
1367 LogBuffer *logbuffer = ensure_logbuf (
1368 EVENT_SIZE /* event */ +
1369 LEB128_SIZE /* time */ +
1370 EVENT_SIZE /* type */ +
1371 LEB128_SIZE /* assembly */ +
1372 LEB128_SIZE /* flags */ +
1375 uint64_t now = current_time ();
1377 ENTER_LOG (logbuffer, "assembly-unload");
1378 emit_byte (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
1379 emit_time (logbuffer, now);
1380 emit_byte (logbuffer, TYPE_ASSEMBLY);
1381 emit_ptr (logbuffer, assembly);
1382 emit_value (logbuffer, 0); /* flags */
1383 memcpy (logbuffer->data, name, nlen);
1384 logbuffer->data += nlen;
1385 EXIT_LOG (logbuffer);
1389 if (logbuffer->next)
1390 safe_send (prof, logbuffer);
1392 process_requests (prof);
1396 class_loaded (MonoProfiler *prof, MonoClass *klass, int result)
1402 LogBuffer *logbuffer;
1403 if (result != MONO_PROFILE_OK)
1405 if (InterlockedRead (&runtime_inited))
1406 name = mono_type_get_name (mono_class_get_type (klass));
1408 name = type_name (klass);
1409 nlen = strlen (name) + 1;
1410 image = mono_class_get_image (klass);
1411 logbuffer = ensure_logbuf (
1412 EVENT_SIZE /* event */ +
1413 LEB128_SIZE /* time */ +
1414 EVENT_SIZE /* type */ +
1415 LEB128_SIZE /* klass */ +
1416 LEB128_SIZE /* image */ +
1417 LEB128_SIZE /* flags */ +
1420 now = current_time ();
1421 ENTER_LOG (logbuffer, "class");
1422 emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1423 emit_time (logbuffer, now);
1424 emit_byte (logbuffer, TYPE_CLASS);
1425 emit_ptr (logbuffer, klass);
1426 emit_ptr (logbuffer, image);
1427 emit_value (logbuffer, 0); /* flags */
1428 memcpy (logbuffer->data, name, nlen);
1429 logbuffer->data += nlen;
1430 //printf ("loaded class %p (%s)\n", klass, name);
1435 EXIT_LOG (logbuffer);
1436 if (logbuffer->next)
1437 safe_send (prof, logbuffer);
1438 process_requests (prof);
1442 class_unloaded (MonoProfiler *prof, MonoClass *klass)
1446 if (InterlockedRead (&runtime_inited))
1447 name = mono_type_get_name (mono_class_get_type (klass));
1449 name = type_name (klass);
1451 int nlen = strlen (name) + 1;
1452 MonoImage *image = mono_class_get_image (klass);
1453 LogBuffer *logbuffer = ensure_logbuf (
1454 EVENT_SIZE /* event */ +
1455 LEB128_SIZE /* time */ +
1456 EVENT_SIZE /* type */ +
1457 LEB128_SIZE /* klass */ +
1458 LEB128_SIZE /* image */ +
1459 LEB128_SIZE /* flags */ +
1462 uint64_t now = current_time ();
1464 ENTER_LOG (logbuffer, "class-unload");
1465 emit_byte (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
1466 emit_time (logbuffer, now);
1467 emit_byte (logbuffer, TYPE_CLASS);
1468 emit_ptr (logbuffer, klass);
1469 emit_ptr (logbuffer, image);
1470 emit_value (logbuffer, 0); /* flags */
1471 memcpy (logbuffer->data, name, nlen);
1472 logbuffer->data += nlen;
1473 EXIT_LOG (logbuffer);
1480 if (logbuffer->next)
1481 safe_send (prof, logbuffer);
1483 process_requests (prof);
1486 #ifndef DISABLE_HELPER_THREAD
1487 static void process_method_enter_coverage (MonoProfiler *prof, MonoMethod *method);
1488 #endif /* DISABLE_HELPER_THREAD */
1491 method_enter (MonoProfiler *prof, MonoMethod *method)
1493 uint64_t now = current_time ();
1495 #ifndef DISABLE_HELPER_THREAD
1496 process_method_enter_coverage (prof, method);
1497 #endif /* DISABLE_HELPER_THREAD */
1499 LogBuffer *logbuffer = ensure_logbuf (
1500 EVENT_SIZE /* event */ +
1501 LEB128_SIZE /* time */ +
1502 LEB128_SIZE /* method */
1504 if (logbuffer->call_depth++ > max_call_depth)
1506 ENTER_LOG (logbuffer, "enter");
1507 emit_byte (logbuffer, TYPE_ENTER | TYPE_METHOD);
1508 emit_time (logbuffer, now);
1509 emit_method (prof, logbuffer, method);
1510 EXIT_LOG (logbuffer);
1512 process_requests (prof);
1516 method_leave (MonoProfiler *prof, MonoMethod *method)
1519 LogBuffer *logbuffer = ensure_logbuf (
1520 EVENT_SIZE /* event */ +
1521 LEB128_SIZE /* time */ +
1522 LEB128_SIZE /* method */
1524 if (--logbuffer->call_depth > max_call_depth)
1526 now = current_time ();
1527 ENTER_LOG (logbuffer, "leave");
1528 emit_byte (logbuffer, TYPE_LEAVE | TYPE_METHOD);
1529 emit_time (logbuffer, now);
1530 emit_method (prof, logbuffer, method);
1531 EXIT_LOG (logbuffer);
1532 if (logbuffer->next)
1533 safe_send (prof, logbuffer);
1534 process_requests (prof);
1538 method_exc_leave (MonoProfiler *prof, MonoMethod *method)
1541 LogBuffer *logbuffer;
1544 logbuffer = ensure_logbuf (
1545 EVENT_SIZE /* event */ +
1546 LEB128_SIZE /* time */ +
1547 LEB128_SIZE /* method */
1549 if (--logbuffer->call_depth > max_call_depth)
1551 now = current_time ();
1552 ENTER_LOG (logbuffer, "eleave");
1553 emit_byte (logbuffer, TYPE_EXC_LEAVE | TYPE_METHOD);
1554 emit_time (logbuffer, now);
1555 emit_method (prof, logbuffer, method);
1556 EXIT_LOG (logbuffer);
1557 process_requests (prof);
1561 method_jitted (MonoProfiler *prof, MonoMethod *method, MonoJitInfo *ji, int result)
1563 if (result != MONO_PROFILE_OK)
1566 register_method_local (prof, method, ji);
1568 process_requests (prof);
1572 code_buffer_new (MonoProfiler *prof, void *buffer, int size, MonoProfilerCodeBufferType type, void *data)
1577 LogBuffer *logbuffer;
1578 if (type == MONO_PROFILER_CODE_BUFFER_SPECIFIC_TRAMPOLINE) {
1580 nlen = strlen (name) + 1;
1585 logbuffer = ensure_logbuf (
1586 EVENT_SIZE /* event */ +
1587 LEB128_SIZE /* time */ +
1588 LEB128_SIZE /* type */ +
1589 LEB128_SIZE /* buffer */ +
1590 LEB128_SIZE /* size */ +
1595 now = current_time ();
1596 ENTER_LOG (logbuffer, "code buffer");
1597 emit_byte (logbuffer, TYPE_JITHELPER | TYPE_RUNTIME);
1598 emit_time (logbuffer, now);
1599 emit_value (logbuffer, type);
1600 emit_ptr (logbuffer, buffer);
1601 emit_value (logbuffer, size);
1603 memcpy (logbuffer->data, name, nlen);
1604 logbuffer->data += nlen;
1606 EXIT_LOG (logbuffer);
1607 process_requests (prof);
1611 throw_exc (MonoProfiler *prof, MonoObject *object)
1613 int do_bt = (nocalls && InterlockedRead (&runtime_inited) && !notraces)? TYPE_EXCEPTION_BT: 0;
1616 LogBuffer *logbuffer;
1619 logbuffer = ensure_logbuf (
1620 EVENT_SIZE /* event */ +
1621 LEB128_SIZE /* time */ +
1622 LEB128_SIZE /* object */ +
1624 LEB128_SIZE /* flags */ +
1625 LEB128_SIZE /* count */ +
1627 LEB128_SIZE /* method */
1631 now = current_time ();
1632 ENTER_LOG (logbuffer, "throw");
1633 emit_byte (logbuffer, do_bt | TYPE_EXCEPTION);
1634 emit_time (logbuffer, now);
1635 emit_obj (logbuffer, object);
1637 emit_bt (prof, logbuffer, &data);
1638 EXIT_LOG (logbuffer);
1639 process_requests (prof);
1643 clause_exc (MonoProfiler *prof, MonoMethod *method, int clause_type, int clause_num)
1646 LogBuffer *logbuffer = ensure_logbuf (
1647 EVENT_SIZE /* event */ +
1648 LEB128_SIZE /* time */ +
1649 LEB128_SIZE /* clause type */ +
1650 LEB128_SIZE /* clause num */ +
1651 LEB128_SIZE /* method */
1653 now = current_time ();
1654 ENTER_LOG (logbuffer, "clause");
1655 emit_byte (logbuffer, TYPE_EXCEPTION | TYPE_CLAUSE);
1656 emit_time (logbuffer, now);
1657 emit_value (logbuffer, clause_type);
1658 emit_value (logbuffer, clause_num);
1659 emit_method (prof, logbuffer, method);
1660 EXIT_LOG (logbuffer);
1662 process_requests (prof);
1666 monitor_event (MonoProfiler *profiler, MonoObject *object, MonoProfilerMonitorEvent event)
1668 int do_bt = (nocalls && InterlockedRead (&runtime_inited) && !notraces && event == MONO_PROFILER_MONITOR_CONTENTION)? TYPE_MONITOR_BT: 0;
1671 LogBuffer *logbuffer;
1674 logbuffer = ensure_logbuf (
1675 EVENT_SIZE /* event */ +
1676 LEB128_SIZE /* time */ +
1677 LEB128_SIZE /* object */ +
1679 LEB128_SIZE /* flags */ +
1680 LEB128_SIZE /* count */ +
1682 LEB128_SIZE /* method */
1686 now = current_time ();
1687 ENTER_LOG (logbuffer, "monitor");
1688 emit_byte (logbuffer, (event << 4) | do_bt | TYPE_MONITOR);
1689 emit_time (logbuffer, now);
1690 emit_obj (logbuffer, object);
1692 emit_bt (profiler, logbuffer, &data);
1693 EXIT_LOG (logbuffer);
1694 process_requests (profiler);
1698 thread_start (MonoProfiler *prof, uintptr_t tid)
1700 //printf ("thread start %p\n", (void*)tid);
1703 LogBuffer *logbuffer = ensure_logbuf (
1704 EVENT_SIZE /* event */ +
1705 LEB128_SIZE /* time */ +
1706 EVENT_SIZE /* type */ +
1707 LEB128_SIZE /* tid */ +
1708 LEB128_SIZE /* flags */
1710 uint64_t now = current_time ();
1712 ENTER_LOG (logbuffer, "thread-start");
1713 emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1714 emit_time (logbuffer, now);
1715 emit_byte (logbuffer, TYPE_THREAD);
1716 emit_ptr (logbuffer, (void*) tid);
1717 emit_value (logbuffer, 0); /* flags */
1718 EXIT_LOG (logbuffer);
1720 if (logbuffer->next)
1721 safe_send (prof, logbuffer);
1723 process_requests (prof);
1727 thread_end (MonoProfiler *prof, uintptr_t tid)
1729 if (TLS_GET (LogBuffer, tlsbuffer)) {
1730 LogBuffer *logbuffer = ensure_logbuf (
1731 EVENT_SIZE /* event */ +
1732 LEB128_SIZE /* time */ +
1733 EVENT_SIZE /* type */ +
1734 LEB128_SIZE /* tid */ +
1735 LEB128_SIZE /* flags */
1737 uint64_t now = current_time ();
1739 ENTER_LOG (logbuffer, "thread-end");
1740 emit_byte (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
1741 emit_time (logbuffer, now);
1742 emit_byte (logbuffer, TYPE_THREAD);
1743 emit_ptr (logbuffer, (void*) tid);
1744 emit_value (logbuffer, 0); /* flags */
1745 EXIT_LOG (logbuffer);
1747 send_buffer (prof, TLS_GET (GPtrArray, tlsmethodlist), logbuffer);
1749 /* Don't process requests as the thread is detached from the runtime. */
1752 TLS_SET (tlsbuffer, NULL);
1753 TLS_SET (tlsmethodlist, NULL);
1757 domain_loaded (MonoProfiler *prof, MonoDomain *domain, int result)
1759 if (result != MONO_PROFILE_OK)
1762 LogBuffer *logbuffer = ensure_logbuf (
1763 EVENT_SIZE /* event */ +
1764 LEB128_SIZE /* time */ +
1765 EVENT_SIZE /* type */ +
1766 LEB128_SIZE /* domain id */ +
1767 LEB128_SIZE /* flags */
1769 uint64_t now = current_time ();
1771 ENTER_LOG (logbuffer, "domain-start");
1772 emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1773 emit_time (logbuffer, now);
1774 emit_byte (logbuffer, TYPE_DOMAIN);
1775 emit_ptr (logbuffer, (void*)(uintptr_t) mono_domain_get_id (domain));
1776 emit_value (logbuffer, 0); /* flags */
1777 EXIT_LOG (logbuffer);
1779 if (logbuffer->next)
1780 safe_send (prof, logbuffer);
1782 process_requests (prof);
1786 domain_unloaded (MonoProfiler *prof, MonoDomain *domain)
1788 LogBuffer *logbuffer = ensure_logbuf (
1789 EVENT_SIZE /* event */ +
1790 LEB128_SIZE /* time */ +
1791 EVENT_SIZE /* type */ +
1792 LEB128_SIZE /* domain id */ +
1793 LEB128_SIZE /* flags */
1795 uint64_t now = current_time ();
1797 ENTER_LOG (logbuffer, "domain-end");
1798 emit_byte (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
1799 emit_time (logbuffer, now);
1800 emit_byte (logbuffer, TYPE_DOMAIN);
1801 emit_ptr (logbuffer, (void*)(uintptr_t) mono_domain_get_id (domain));
1802 emit_value (logbuffer, 0); /* flags */
1803 EXIT_LOG (logbuffer);
1805 if (logbuffer->next)
1806 safe_send (prof, logbuffer);
1808 process_requests (prof);
1812 domain_name (MonoProfiler *prof, MonoDomain *domain, const char *name)
1814 int nlen = strlen (name) + 1;
1815 LogBuffer *logbuffer = ensure_logbuf (
1816 EVENT_SIZE /* event */ +
1817 LEB128_SIZE /* time */ +
1818 EVENT_SIZE /* type */ +
1819 LEB128_SIZE /* domain id */ +
1820 LEB128_SIZE /* flags */ +
1823 uint64_t now = current_time ();
1825 ENTER_LOG (logbuffer, "domain-name");
1826 emit_byte (logbuffer, TYPE_METADATA);
1827 emit_time (logbuffer, now);
1828 emit_byte (logbuffer, TYPE_DOMAIN);
1829 emit_ptr (logbuffer, (void*)(uintptr_t) mono_domain_get_id (domain));
1830 emit_value (logbuffer, 0); /* flags */
1831 memcpy (logbuffer->data, name, nlen);
1832 logbuffer->data += nlen;
1833 EXIT_LOG (logbuffer);
1835 if (logbuffer->next)
1836 safe_send (prof, logbuffer);
1838 process_requests (prof);
1842 context_loaded (MonoProfiler *prof, MonoAppContext *context)
1844 LogBuffer *logbuffer = ensure_logbuf (
1845 EVENT_SIZE /* event */ +
1846 LEB128_SIZE /* time */ +
1847 EVENT_SIZE /* type */ +
1848 LEB128_SIZE /* context id */ +
1849 LEB128_SIZE /* flags */ +
1850 LEB128_SIZE /* domain id */
1852 uint64_t now = current_time ();
1854 ENTER_LOG (logbuffer, "context-start");
1855 emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1856 emit_time (logbuffer, now);
1857 emit_byte (logbuffer, TYPE_CONTEXT);
1858 emit_ptr (logbuffer, (void*)(uintptr_t) mono_context_get_id (context));
1859 emit_value (logbuffer, 0); /* flags */
1860 emit_ptr (logbuffer, (void*)(uintptr_t) mono_context_get_domain_id (context));
1861 EXIT_LOG (logbuffer);
1863 if (logbuffer->next)
1864 safe_send (prof, logbuffer);
1866 process_requests (prof);
1870 context_unloaded (MonoProfiler *prof, MonoAppContext *context)
1872 LogBuffer *logbuffer = ensure_logbuf (
1873 EVENT_SIZE /* event */ +
1874 LEB128_SIZE /* time */ +
1875 EVENT_SIZE /* type */ +
1876 LEB128_SIZE /* context id */ +
1877 LEB128_SIZE /* flags */ +
1878 LEB128_SIZE /* domain id */
1880 uint64_t now = current_time ();
1882 ENTER_LOG (logbuffer, "context-end");
1883 emit_byte (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
1884 emit_time (logbuffer, now);
1885 emit_byte (logbuffer, TYPE_CONTEXT);
1886 emit_ptr (logbuffer, (void*)(uintptr_t) mono_context_get_id (context));
1887 emit_value (logbuffer, 0); /* flags */
1888 emit_ptr (logbuffer, (void*)(uintptr_t) mono_context_get_domain_id (context));
1889 EXIT_LOG (logbuffer);
1891 if (logbuffer->next)
1892 safe_send (prof, logbuffer);
1894 process_requests (prof);
1898 thread_name (MonoProfiler *prof, uintptr_t tid, const char *name)
1900 int len = strlen (name) + 1;
1902 LogBuffer *logbuffer;
1903 logbuffer = ensure_logbuf (
1904 EVENT_SIZE /* event */ +
1905 LEB128_SIZE /* time */ +
1906 EVENT_SIZE /* type */ +
1907 LEB128_SIZE /* tid */ +
1908 LEB128_SIZE /* flags */ +
1911 now = current_time ();
1912 ENTER_LOG (logbuffer, "tname");
1913 emit_byte (logbuffer, TYPE_METADATA);
1914 emit_time (logbuffer, now);
1915 emit_byte (logbuffer, TYPE_THREAD);
1916 emit_ptr (logbuffer, (void*)tid);
1917 emit_value (logbuffer, 0); /* flags */
1918 memcpy (logbuffer->data, name, len);
1919 logbuffer->data += len;
1920 EXIT_LOG (logbuffer);
1922 if (logbuffer->next)
1923 safe_send (prof, logbuffer);
1925 process_requests (prof);
1937 AsyncFrameInfo *data;
1941 async_walk_stack (MonoMethod *method, MonoDomain *domain, void *base_address, int offset, void *data)
1943 AsyncFrameData *frame = data;
1944 if (frame->count < num_frames) {
1945 frame->data [frame->count].method = method;
1946 frame->data [frame->count].domain = domain;
1947 frame->data [frame->count].base_address = base_address;
1948 frame->data [frame->count].offset = offset;
1949 // printf ("In %d at %p (dom %p) (native: %p)\n", frame->count, method, domain, base_address);
1952 return frame->count == num_frames;
1956 (type | frame count), tid, time, ip, [method, domain, base address, offset] * frames
1958 #define SAMPLE_EVENT_SIZE_IN_SLOTS(FRAMES) (4 + (FRAMES) * 4)
1961 mono_sample_hit (MonoProfiler *profiler, unsigned char *ip, void *context)
1964 AsyncFrameInfo frames [num_frames];
1965 AsyncFrameData bt_data = { 0, &frames [0]};
1967 uintptr_t *data, *new_data, *old_data;
1973 now = current_time ();
1975 mono_stack_walk_async_safe (&async_walk_stack, context, &bt_data);
1977 elapsed = (now - profiler->startup_time) / 10000;
1981 snprintf (buf, sizeof (buf), "hit at %p in thread %p after %llu ms\n", ip, (void*)thread_id (), (unsigned long long int)elapsed/100);
1983 ign_res (write (2, buf, len));
1985 sbuf = profiler->stat_buffers;
1988 /* flush the buffer at 1 second intervals */
1989 if (sbuf->data > sbuf->buf && (elapsed - sbuf->buf [2]) > 100000) {
1992 /* overflow: 400 slots is a big enough number to reduce the chance of losing this event if many
1993 * threads hit this same spot at the same time
1995 if (timedout || (sbuf->data + 400 >= sbuf->data_end)) {
1996 StatBuffer *oldsb, *foundsb;
1997 sbuf = create_stat_buffer ();
1999 oldsb = profiler->stat_buffers;
2001 foundsb = InterlockedCompareExchangePointer ((void * volatile*)&profiler->stat_buffers, sbuf, oldsb);
2002 } while (foundsb != oldsb);
2004 ign_res (write (2, "overflow\n", 9));
2005 /* notify the helper thread */
2006 if (sbuf->next->next) {
2008 ign_res (write (profiler->pipes [1], &c, 1));
2010 ign_res (write (2, "notify\n", 7));
2014 old_data = sbuf->data;
2015 new_data = old_data + SAMPLE_EVENT_SIZE_IN_SLOTS (bt_data.count);
2016 data = InterlockedCompareExchangePointer ((void * volatile*)&sbuf->data, new_data, old_data);
2017 } while (data != old_data);
2018 if (old_data >= sbuf->data_end)
2019 return; /* lost event */
2020 old_data [0] = 1 | (sample_type << 16) | (bt_data.count << 8);
2021 old_data [1] = thread_id ();
2022 old_data [2] = elapsed;
2023 old_data [3] = (uintptr_t)ip;
2024 for (i = 0; i < bt_data.count; ++i) {
2025 old_data [4 + 4 * i + 0] = (uintptr_t)frames [i].method;
2026 old_data [4 + 4 * i + 1] = (uintptr_t)frames [i].domain;
2027 old_data [4 + 4 * i + 2] = (uintptr_t)frames [i].base_address;
2028 old_data [4 + 4 * i + 3] = (uintptr_t)frames [i].offset;
2032 static uintptr_t *code_pages = 0;
2033 static int num_code_pages = 0;
2034 static int size_code_pages = 0;
2035 #define CPAGE_SHIFT (9)
2036 #define CPAGE_SIZE (1 << CPAGE_SHIFT)
2037 #define CPAGE_MASK (~(CPAGE_SIZE - 1))
2038 #define CPAGE_ADDR(p) ((p) & CPAGE_MASK)
2041 add_code_page (uintptr_t *hash, uintptr_t hsize, uintptr_t page)
2044 uintptr_t start_pos;
2045 start_pos = (page >> CPAGE_SHIFT) % hsize;
2048 if (hash [i] && CPAGE_ADDR (hash [i]) == CPAGE_ADDR (page)) {
2050 } else if (!hash [i]) {
2057 } while (i != start_pos);
2058 /* should not happen */
2059 printf ("failed code page store\n");
2064 add_code_pointer (uintptr_t ip)
2067 if (num_code_pages * 2 >= size_code_pages) {
2069 uintptr_t old_size = size_code_pages;
2070 size_code_pages *= 2;
2071 if (size_code_pages == 0)
2072 size_code_pages = 16;
2073 n = calloc (sizeof (uintptr_t) * size_code_pages, 1);
2074 for (i = 0; i < old_size; ++i) {
2076 add_code_page (n, size_code_pages, code_pages [i]);
2082 num_code_pages += add_code_page (code_pages, size_code_pages, ip & CPAGE_MASK);
2085 /* ELF code crashes on some systems. */
2086 //#if defined(HAVE_DL_ITERATE_PHDR) && defined(ELFMAG0)
2089 dump_ubin (const char *filename, uintptr_t load_addr, uint64_t offset, uintptr_t size)
2092 LogBuffer *logbuffer;
2094 len = strlen (filename) + 1;
2095 now = current_time ();
2096 logbuffer = ensure_logbuf (
2097 EVENT_SIZE /* event */ +
2098 LEB128_SIZE /* time */ +
2099 LEB128_SIZE /* load address */ +
2100 LEB128_SIZE /* offset */ +
2101 LEB128_SIZE /* size */ +
2102 nlen /* file name */
2104 emit_byte (logbuffer, TYPE_SAMPLE | TYPE_SAMPLE_UBIN);
2105 emit_time (logbuffer, now);
2106 emit_svalue (logbuffer, load_addr);
2107 emit_uvalue (logbuffer, offset);
2108 emit_uvalue (logbuffer, size);
2109 memcpy (logbuffer->data, filename, len);
2110 logbuffer->data += len;
2115 dump_usym (const char *name, uintptr_t value, uintptr_t size)
2117 LogBuffer *logbuffer;
2119 len = strlen (name) + 1;
2120 logbuffer = ensure_logbuf (
2121 EVENT_SIZE /* event */ +
2122 LEB128_SIZE /* value */ +
2123 LEB128_SIZE /* size */ +
2126 emit_byte (logbuffer, TYPE_SAMPLE | TYPE_SAMPLE_USYM);
2127 emit_ptr (logbuffer, (void*)value);
2128 emit_value (logbuffer, size);
2129 memcpy (logbuffer->data, name, len);
2130 logbuffer->data += len;
2133 /* ELF code crashes on some systems. */
2134 //#if defined(ELFMAG0)
2137 #if SIZEOF_VOID_P == 4
2138 #define ELF_WSIZE 32
2140 #define ELF_WSIZE 64
2143 #define ElfW(type) _ElfW (Elf, ELF_WSIZE, type)
2144 #define _ElfW(e,w,t) _ElfW_1 (e, w, _##t)
2145 #define _ElfW_1(e,w,t) e##w##t
2149 dump_elf_symbols (ElfW(Sym) *symbols, int num_symbols, const char *strtab, void *load_addr)
2152 for (i = 0; i < num_symbols; ++i) {
2154 sym = strtab + symbols [i].st_name;
2155 if (!symbols [i].st_name || !symbols [i].st_size || (symbols [i].st_info & 0xf) != STT_FUNC)
2157 //printf ("symbol %s at %d\n", sym, symbols [i].st_value);
2158 dump_usym (sym, (uintptr_t)load_addr + symbols [i].st_value, symbols [i].st_size);
2163 read_elf_symbols (MonoProfiler *prof, const char *filename, void *load_addr)
2170 ElfW(Shdr) *sheader;
2171 ElfW(Shdr) *shstrtabh;
2172 ElfW(Shdr) *symtabh = NULL;
2173 ElfW(Shdr) *strtabh = NULL;
2174 ElfW(Sym) *symbols = NULL;
2178 fd = open (filename, O_RDONLY);
2181 if (fstat (fd, &statb) != 0) {
2185 file_size = statb.st_size;
2186 data = mmap (NULL, file_size, PROT_READ, MAP_PRIVATE, fd, 0);
2188 if (data == MAP_FAILED)
2191 if (header->e_ident [EI_MAG0] != ELFMAG0 ||
2192 header->e_ident [EI_MAG1] != ELFMAG1 ||
2193 header->e_ident [EI_MAG2] != ELFMAG2 ||
2194 header->e_ident [EI_MAG3] != ELFMAG3 ) {
2195 munmap (data, file_size);
2198 sheader = (void*)((char*)data + header->e_shoff);
2199 shstrtabh = (void*)((char*)sheader + (header->e_shentsize * header->e_shstrndx));
2200 strtab = (const char*)data + shstrtabh->sh_offset;
2201 for (i = 0; i < header->e_shnum; ++i) {
2202 //printf ("section header: %d\n", sheader->sh_type);
2203 if (sheader->sh_type == SHT_SYMTAB) {
2205 strtabh = (void*)((char*)data + header->e_shoff + sheader->sh_link * header->e_shentsize);
2206 /*printf ("symtab section header: %d, .strstr: %d\n", i, sheader->sh_link);*/
2209 sheader = (void*)((char*)sheader + header->e_shentsize);
2211 if (!symtabh || !strtabh) {
2212 munmap (data, file_size);
2215 strtab = (const char*)data + strtabh->sh_offset;
2216 num_symbols = symtabh->sh_size / symtabh->sh_entsize;
2217 symbols = (void*)((char*)data + symtabh->sh_offset);
2218 dump_elf_symbols (symbols, num_symbols, strtab, load_addr);
2219 munmap (data, file_size);
2224 /* ELF code crashes on some systems. */
2225 //#if defined(HAVE_DL_ITERATE_PHDR) && defined(ELFMAG0)
2228 elf_dl_callback (struct dl_phdr_info *info, size_t size, void *data)
2230 MonoProfiler *prof = data;
2232 const char *filename;
2234 char *a = (void*)info->dlpi_addr;
2236 ElfW(Dyn) *dyn = NULL;
2237 ElfW(Sym) *symtab = NULL;
2238 ElfW(Word) *hash_table = NULL;
2239 ElfW(Ehdr) *header = NULL;
2240 const char* strtab = NULL;
2241 for (obj = prof->binary_objects; obj; obj = obj->next) {
2245 filename = info->dlpi_name;
2248 if (!info->dlpi_addr && !filename [0]) {
2249 int l = readlink ("/proc/self/exe", buf, sizeof (buf) - 1);
2255 obj = calloc (sizeof (BinaryObject), 1);
2256 obj->addr = (void*)info->dlpi_addr;
2257 obj->name = pstrdup (filename);
2258 obj->next = prof->binary_objects;
2259 prof->binary_objects = obj;
2260 //printf ("loaded file: %s at %p, segments: %d\n", filename, (void*)info->dlpi_addr, info->dlpi_phnum);
2262 for (i = 0; i < info->dlpi_phnum; ++i) {
2263 //printf ("segment type %d file offset: %d, size: %d\n", info->dlpi_phdr[i].p_type, info->dlpi_phdr[i].p_offset, info->dlpi_phdr[i].p_memsz);
2264 if (info->dlpi_phdr[i].p_type == PT_LOAD && !header) {
2265 header = (ElfW(Ehdr)*)(info->dlpi_addr + info->dlpi_phdr[i].p_vaddr);
2266 if (header->e_ident [EI_MAG0] != ELFMAG0 ||
2267 header->e_ident [EI_MAG1] != ELFMAG1 ||
2268 header->e_ident [EI_MAG2] != ELFMAG2 ||
2269 header->e_ident [EI_MAG3] != ELFMAG3 ) {
2272 dump_ubin (filename, info->dlpi_addr + info->dlpi_phdr[i].p_vaddr, info->dlpi_phdr[i].p_offset, info->dlpi_phdr[i].p_memsz);
2273 } else if (info->dlpi_phdr[i].p_type == PT_DYNAMIC) {
2274 dyn = (ElfW(Dyn) *)(info->dlpi_addr + info->dlpi_phdr[i].p_vaddr);
2277 if (read_elf_symbols (prof, filename, (void*)info->dlpi_addr))
2279 if (!info->dlpi_name || !info->dlpi_name[0])
2283 for (i = 0; dyn [i].d_tag != DT_NULL; ++i) {
2284 if (dyn [i].d_tag == DT_SYMTAB) {
2285 if (symtab && do_debug)
2286 printf ("multiple symtabs: %d\n", i);
2287 symtab = (ElfW(Sym) *)(a + dyn [i].d_un.d_ptr);
2288 } else if (dyn [i].d_tag == DT_HASH) {
2289 hash_table = (ElfW(Word) *)(a + dyn [i].d_un.d_ptr);
2290 } else if (dyn [i].d_tag == DT_STRTAB) {
2291 strtab = (const char*)(a + dyn [i].d_un.d_ptr);
2296 num_sym = hash_table [1];
2297 dump_elf_symbols (symtab, num_sym, strtab, (void*)info->dlpi_addr);
2302 load_binaries (MonoProfiler *prof)
2304 dl_iterate_phdr (elf_dl_callback, prof);
2309 load_binaries (MonoProfiler *prof)
2316 symbol_for (uintptr_t code)
2319 void *ip = (void*)code;
2321 if (dladdr (ip, &di)) {
2323 return di.dli_sname;
2326 names = backtrace_symbols (&ip, 1);
2328 const char* p = names [0];
2339 dump_unmanaged_coderefs (MonoProfiler *prof)
2342 const char* last_symbol;
2343 uintptr_t addr, page_end;
2345 if (load_binaries (prof))
2347 for (i = 0; i < size_code_pages; ++i) {
2349 if (!code_pages [i] || code_pages [i] & 1)
2352 addr = CPAGE_ADDR (code_pages [i]);
2353 page_end = addr + CPAGE_SIZE;
2354 code_pages [i] |= 1;
2355 /* we dump the symbols for the whole page */
2356 for (; addr < page_end; addr += 16) {
2357 sym = symbol_for (addr);
2358 if (sym && sym == last_symbol)
2363 dump_usym (sym, addr, 0); /* let's not guess the size */
2364 //printf ("found symbol at %p: %s\n", (void*)addr, sym);
2370 compare_sample_events (gconstpointer a, gconstpointer b)
2372 uintptr_t tid1 = (*(uintptr_t **) a) [1];
2373 uintptr_t tid2 = (*(uintptr_t **) b) [1];
2375 return tid1 > tid2 ? 1 :
2381 dump_sample_hits (MonoProfiler *prof, StatBuffer *sbuf)
2383 LogBuffer *logbuffer;
2387 dump_sample_hits (prof, sbuf->next);
2388 free_buffer (sbuf->next, sbuf->next->size);
2392 g_ptr_array_set_size (prof->sorted_sample_events, 0);
2394 for (uintptr_t *sample = sbuf->buf; sample < sbuf->data;) {
2395 int count = sample [0] & 0xff;
2396 int mbt_count = (sample [0] & 0xff00) >> 8;
2398 if (sample + SAMPLE_EVENT_SIZE_IN_SLOTS (mbt_count) > sbuf->data)
2401 g_ptr_array_add (prof->sorted_sample_events, sample);
2403 sample += count + 3 + 4 * mbt_count;
2406 g_ptr_array_sort (prof->sorted_sample_events, compare_sample_events);
2408 for (guint sidx = 0; sidx < prof->sorted_sample_events->len; sidx++) {
2409 uintptr_t *sample = g_ptr_array_index (prof->sorted_sample_events, sidx);
2410 int count = sample [0] & 0xff;
2411 int mbt_count = (sample [0] & 0xff00) >> 8;
2412 int type = sample [0] >> 16;
2413 uintptr_t *managed_sample_base = sample + count + 3;
2414 uintptr_t thread_id = sample [1];
2416 for (int i = 0; i < mbt_count; ++i) {
2417 MonoMethod *method = (MonoMethod*)managed_sample_base [i * 4 + 0];
2418 MonoDomain *domain = (MonoDomain*)managed_sample_base [i * 4 + 1];
2419 void *address = (void*)managed_sample_base [i * 4 + 2];
2422 MonoJitInfo *ji = mono_jit_info_table_find (domain, address);
2425 managed_sample_base [i * 4 + 0] = (uintptr_t)mono_jit_info_get_method (ji);
2429 logbuffer = ensure_logbuf (
2430 EVENT_SIZE /* event */ +
2431 LEB128_SIZE /* type */ +
2432 LEB128_SIZE /* time */ +
2433 LEB128_SIZE /* tid */ +
2434 LEB128_SIZE /* count */ +
2436 LEB128_SIZE /* ip */
2438 LEB128_SIZE /* managed count */ +
2440 LEB128_SIZE /* method */ +
2441 LEB128_SIZE /* il offset */ +
2442 LEB128_SIZE /* native offset */
2445 emit_byte (logbuffer, TYPE_SAMPLE | TYPE_SAMPLE_HIT);
2446 emit_value (logbuffer, type);
2447 emit_uvalue (logbuffer, prof->startup_time + (uint64_t)sample [2] * (uint64_t)10000);
2448 emit_ptr (logbuffer, (void *) thread_id);
2449 emit_value (logbuffer, count);
2450 for (int i = 0; i < count; ++i) {
2451 emit_ptr (logbuffer, (void*)sample [i + 3]);
2452 add_code_pointer (sample [i + 3]);
2455 sample += count + 3;
2456 /* new in data version 6 */
2457 emit_uvalue (logbuffer, mbt_count);
2458 for (int i = 0; i < mbt_count; ++i) {
2459 MonoMethod *method = (MonoMethod *) sample [i * 4 + 0];
2460 uintptr_t native_offset = sample [i * 4 + 3];
2462 emit_method (prof, logbuffer, method);
2463 emit_svalue (logbuffer, 0); /* il offset will always be 0 from now on */
2464 emit_svalue (logbuffer, native_offset);
2468 dump_unmanaged_coderefs (prof);
2474 mono_cpu_count (void)
2477 #ifdef PLATFORM_ANDROID
2478 /* Android tries really hard to save power by powering off CPUs on SMP phones which
2479 * means the normal way to query cpu count returns a wrong value with userspace API.
2480 * Instead we use /sys entries to query the actual hardware CPU count.
2482 char buffer[8] = {'\0'};
2483 int present = open ("/sys/devices/system/cpu/present", O_RDONLY);
2484 /* Format of the /sys entry is a cpulist of indexes which in the case
2485 * of present is always of the form "0-(n-1)" when there is more than
2486 * 1 core, n being the number of CPU cores in the system. Otherwise
2487 * the value is simply 0
2489 if (present != -1 && read (present, (char*)buffer, sizeof (buffer)) > 3)
2490 count = strtol (((char*)buffer) + 2, NULL, 10);
2496 #ifdef _SC_NPROCESSORS_ONLN
2497 count = sysconf (_SC_NPROCESSORS_ONLN);
2504 size_t len = sizeof (int);
2507 if (sysctl (mib, 2, &count, &len, NULL, 0) == 0)
2514 GetSystemInfo (&info);
2515 return info.dwNumberOfProcessors;
2524 unsigned int prev_pos;
2526 struct perf_event_mmap_page *page_desc;
2529 static PerfData *perf_data = NULL;
2530 static int num_perf;
2531 #define PERF_PAGES_SHIFT 4
2532 static int num_pages = 1 << PERF_PAGES_SHIFT;
2533 static unsigned int mmap_mask;
2536 struct perf_event_header h;
2546 perf_event_syscall (struct perf_event_attr *attr, pid_t pid, int cpu, int group_fd, unsigned long flags)
2548 attr->size = PERF_ATTR_SIZE_VER0;
2549 //printf ("perf attr size: %d\n", attr->size);
2550 #if defined(__x86_64__)
2551 return syscall(/*__NR_perf_event_open*/ 298, attr, pid, cpu, group_fd, flags);
2552 #elif defined(__i386__)
2553 return syscall(/*__NR_perf_event_open*/ 336, attr, pid, cpu, group_fd, flags);
2554 #elif defined(__arm__) || defined (__aarch64__)
2555 return syscall(/*__NR_perf_event_open*/ 364, attr, pid, cpu, group_fd, flags);
2562 setup_perf_map (PerfData *perf)
2564 perf->mmap_base = mmap (NULL, (num_pages + 1) * getpagesize (), PROT_READ|PROT_WRITE, MAP_SHARED, perf->perf_fd, 0);
2565 if (perf->mmap_base == MAP_FAILED) {
2567 printf ("failed mmap\n");
2570 perf->page_desc = perf->mmap_base;
2572 printf ("mmap version: %d\n", perf->page_desc->version);
2577 dump_perf_hits (MonoProfiler *prof, void *buf, int size)
2579 LogBuffer *logbuffer;
2582 void *end = (char*)buf + size;
2584 int pid = getpid ();
2590 if (pid != s->pid) {
2592 printf ("event for different pid: %d\n", s->pid);
2593 buf = (char*)buf + s->h.size;
2596 /*ip = (void*)s->ip;
2597 printf ("sample: %d, size: %d, ip: %p (%s), timestamp: %llu, nframes: %llu\n",
2598 s->h.type, s->h.size, ip, symbol_for (ip), s->timestamp, s->nframes);*/
2599 logbuffer = ensure_logbuf (
2600 EVENT_SIZE /* event */ +
2601 LEB128_SIZE /* type */ +
2602 LEB128_SIZE /* time */ +
2603 LEB128_SIZE /* tid */ +
2604 LEB128_SIZE /* count */ +
2606 LEB128_SIZE /* ip */
2608 LEB128_SIZE /* managed count */ +
2610 LEB128_SIZE /* method */ +
2611 LEB128_SIZE /* il offset */ +
2612 LEB128_SIZE /* native offset */
2615 emit_byte (logbuffer, TYPE_SAMPLE | TYPE_SAMPLE_HIT);
2616 emit_value (logbuffer, sample_type);
2617 emit_uvalue (logbuffer, s->timestamp - prof->startup_time);
2619 * No useful thread ID to write here, since throughout the
2620 * profiler we use pthread_self () but the ID we get from
2621 * perf is the kernel's thread ID.
2623 emit_ptr (logbuffer, 0);
2624 emit_value (logbuffer, count);
2625 emit_ptr (logbuffer, (void*)(uintptr_t)s->ip);
2626 add_code_pointer (s->ip);
2627 /* no support here yet for the managed backtrace */
2628 emit_uvalue (logbuffer, mbt_count);
2629 buf = (char*)buf + s->h.size;
2633 printf ("dumped %d samples\n", samples);
2634 dump_unmanaged_coderefs (prof);
2637 /* read events from the ring buffer */
2639 read_perf_mmap (MonoProfiler* prof, int cpu)
2641 PerfData *perf = perf_data + cpu;
2643 unsigned char *data = (unsigned char*)perf->mmap_base + getpagesize ();
2644 unsigned int head = perf->page_desc->data_head;
2648 mono_memory_read_barrier ();
2650 old = perf->prev_pos;
2654 printf ("lost mmap events: old: %d, head: %d\n", old, head);
2658 if ((old & mmap_mask) + size != (head & mmap_mask)) {
2659 buf = data + (old & mmap_mask);
2660 size = mmap_mask + 1 - (old & mmap_mask);
2662 /* size bytes at buf */
2664 printf ("found1 bytes of events: %d\n", size);
2665 dump_perf_hits (prof, buf, size);
2667 buf = data + (old & mmap_mask);
2669 /* size bytes at buf */
2671 printf ("found bytes of events: %d\n", size);
2672 dump_perf_hits (prof, buf, size);
2674 perf->prev_pos = old;
2675 perf->page_desc->data_tail = old;
2680 setup_perf_event_for_cpu (PerfData *perf, int cpu)
2682 struct perf_event_attr attr;
2683 memset (&attr, 0, sizeof (attr));
2684 attr.type = PERF_TYPE_HARDWARE;
2685 switch (sample_type) {
2686 case SAMPLE_CYCLES: attr.config = PERF_COUNT_HW_CPU_CYCLES; break;
2687 case SAMPLE_INSTRUCTIONS: attr.config = PERF_COUNT_HW_INSTRUCTIONS; break;
2688 case SAMPLE_CACHE_MISSES: attr.config = PERF_COUNT_HW_CACHE_MISSES; break;
2689 case SAMPLE_CACHE_REFS: attr.config = PERF_COUNT_HW_CACHE_REFERENCES; break;
2690 case SAMPLE_BRANCHES: attr.config = PERF_COUNT_HW_BRANCH_INSTRUCTIONS; break;
2691 case SAMPLE_BRANCH_MISSES: attr.config = PERF_COUNT_HW_BRANCH_MISSES; break;
2692 default: attr.config = PERF_COUNT_HW_CPU_CYCLES; break;
2694 attr.sample_type = PERF_SAMPLE_IP | PERF_SAMPLE_TID | PERF_SAMPLE_PERIOD | PERF_SAMPLE_TIME;
2695 // attr.sample_type |= PERF_SAMPLE_CALLCHAIN;
2696 attr.read_format = PERF_FORMAT_TOTAL_TIME_ENABLED | PERF_FORMAT_TOTAL_TIME_RUNNING | PERF_FORMAT_ID;
2699 attr.sample_freq = sample_freq;
2701 perf->perf_fd = perf_event_syscall (&attr, getpid (), cpu, -1, 0);
2703 printf ("perf fd: %d, freq: %d, event: %llu\n", perf->perf_fd, sample_freq, attr.config);
2704 if (perf->perf_fd < 0) {
2705 if (perf->perf_fd == -EPERM) {
2706 fprintf (stderr, "Perf syscall denied, do \"echo 1 > /proc/sys/kernel/perf_event_paranoid\" as root to enable.\n");
2709 perror ("open perf event");
2713 if (!setup_perf_map (perf)) {
2714 close (perf->perf_fd);
2722 setup_perf_event (void)
2725 mmap_mask = num_pages * getpagesize () - 1;
2726 num_perf = mono_cpu_count ();
2727 perf_data = calloc (num_perf, sizeof (PerfData));
2728 for (i = 0; i < num_perf; ++i) {
2729 count += setup_perf_event_for_cpu (perf_data + i, i);
2738 #endif /* USE_PERF_EVENTS */
2740 #ifndef DISABLE_HELPER_THREAD
2742 typedef struct MonoCounterAgent {
2743 MonoCounter *counter;
2744 // MonoCounterAgent specific data :
2749 struct MonoCounterAgent *next;
2752 static MonoCounterAgent* counters;
2753 static gboolean counters_initialized = FALSE;
2754 static int counters_index = 1;
2755 static mono_mutex_t counters_mutex;
2758 counters_add_agent (MonoCounter *counter)
2760 MonoCounterAgent *agent, *item;
2762 if (!counters_initialized)
2765 mono_mutex_lock (&counters_mutex);
2767 for (agent = counters; agent; agent = agent->next) {
2768 if (agent->counter == counter) {
2769 agent->value_size = 0;
2771 free (agent->value);
2772 agent->value = NULL;
2774 mono_mutex_unlock (&counters_mutex);
2779 agent = malloc (sizeof (MonoCounterAgent));
2780 agent->counter = counter;
2781 agent->value = NULL;
2782 agent->value_size = 0;
2783 agent->index = counters_index++;
2796 mono_mutex_unlock (&counters_mutex);
2800 counters_init_foreach_callback (MonoCounter *counter, gpointer data)
2802 counters_add_agent (counter);
2807 counters_init (MonoProfiler *profiler)
2809 assert (!counters_initialized);
2811 mono_mutex_init (&counters_mutex);
2813 counters_initialized = TRUE;
2815 mono_counters_on_register (&counters_add_agent);
2816 mono_counters_foreach (counters_init_foreach_callback, NULL);
2820 counters_emit (MonoProfiler *profiler)
2822 MonoCounterAgent *agent;
2823 LogBuffer *logbuffer;
2826 EVENT_SIZE /* event */ +
2827 LEB128_SIZE /* len */
2830 if (!counters_initialized)
2833 mono_mutex_lock (&counters_mutex);
2835 for (agent = counters; agent; agent = agent->next) {
2840 LEB128_SIZE /* section */ +
2841 strlen (mono_counter_get_name (agent->counter)) + 1 /* name */ +
2842 LEB128_SIZE /* type */ +
2843 LEB128_SIZE /* unit */ +
2844 LEB128_SIZE /* variance */ +
2845 LEB128_SIZE /* index */
2852 mono_mutex_unlock (&counters_mutex);
2856 logbuffer = ensure_logbuf (size);
2858 ENTER_LOG (logbuffer, "counters");
2859 emit_byte (logbuffer, TYPE_SAMPLE_COUNTERS_DESC | TYPE_SAMPLE);
2860 emit_value (logbuffer, len);
2861 for (agent = counters; agent; agent = agent->next) {
2867 name = mono_counter_get_name (agent->counter);
2868 emit_value (logbuffer, mono_counter_get_section (agent->counter));
2869 emit_string (logbuffer, name, strlen (name) + 1);
2870 emit_value (logbuffer, mono_counter_get_type (agent->counter));
2871 emit_value (logbuffer, mono_counter_get_unit (agent->counter));
2872 emit_value (logbuffer, mono_counter_get_variance (agent->counter));
2873 emit_value (logbuffer, agent->index);
2877 EXIT_LOG (logbuffer);
2879 safe_send (profiler, logbuffer);
2881 mono_mutex_unlock (&counters_mutex);
2885 counters_sample (MonoProfiler *profiler, uint64_t timestamp)
2887 MonoCounterAgent *agent;
2888 MonoCounter *counter;
2889 LogBuffer *logbuffer;
2895 if (!counters_initialized)
2898 counters_emit (profiler);
2901 buffer = calloc (1, buffer_size);
2903 mono_mutex_lock (&counters_mutex);
2906 EVENT_SIZE /* event */ +
2907 LEB128_SIZE /* time */
2910 for (agent = counters; agent; agent = agent->next) {
2912 LEB128_SIZE /* index */ +
2913 LEB128_SIZE /* type */ +
2914 mono_counter_get_size (agent->counter) /* value */
2919 LEB128_SIZE /* stop marker */
2922 logbuffer = ensure_logbuf (size);
2924 ENTER_LOG (logbuffer, "counters");
2925 emit_byte (logbuffer, TYPE_SAMPLE_COUNTERS | TYPE_SAMPLE);
2926 emit_uvalue (logbuffer, timestamp);
2927 for (agent = counters; agent; agent = agent->next) {
2930 counter = agent->counter;
2932 size = mono_counter_get_size (counter);
2934 continue; // FIXME error
2935 } else if (size > buffer_size) {
2937 buffer = realloc (buffer, buffer_size);
2940 memset (buffer, 0, buffer_size);
2942 if (mono_counters_sample (counter, buffer, size) < 0)
2943 continue; // FIXME error
2945 type = mono_counter_get_type (counter);
2947 if (!agent->value) {
2948 agent->value = calloc (1, size);
2949 agent->value_size = size;
2951 if (type == MONO_COUNTER_STRING) {
2952 if (strcmp (agent->value, buffer) == 0)
2955 if (agent->value_size == size && memcmp (agent->value, buffer, size) == 0)
2960 emit_uvalue (logbuffer, agent->index);
2961 emit_uvalue (logbuffer, type);
2963 case MONO_COUNTER_INT:
2964 #if SIZEOF_VOID_P == 4
2965 case MONO_COUNTER_WORD:
2967 emit_svalue (logbuffer, *(int*)buffer - *(int*)agent->value);
2969 case MONO_COUNTER_UINT:
2970 emit_uvalue (logbuffer, *(guint*)buffer - *(guint*)agent->value);
2972 case MONO_COUNTER_TIME_INTERVAL:
2973 case MONO_COUNTER_LONG:
2974 #if SIZEOF_VOID_P == 8
2975 case MONO_COUNTER_WORD:
2977 emit_svalue (logbuffer, *(gint64*)buffer - *(gint64*)agent->value);
2979 case MONO_COUNTER_ULONG:
2980 emit_uvalue (logbuffer, *(guint64*)buffer - *(guint64*)agent->value);
2982 case MONO_COUNTER_DOUBLE:
2983 emit_double (logbuffer, *(double*)buffer);
2985 case MONO_COUNTER_STRING:
2987 emit_byte (logbuffer, 0);
2989 emit_byte (logbuffer, 1);
2990 emit_string (logbuffer, (char*)buffer, size);
2997 if (type == MONO_COUNTER_STRING && size > agent->value_size) {
2998 agent->value = realloc (agent->value, size);
2999 agent->value_size = size;
3003 memcpy (agent->value, buffer, size);
3007 emit_value (logbuffer, 0);
3008 EXIT_LOG (logbuffer);
3010 safe_send (profiler, logbuffer);
3012 mono_mutex_unlock (&counters_mutex);
3015 typedef struct _PerfCounterAgent PerfCounterAgent;
3016 struct _PerfCounterAgent {
3017 PerfCounterAgent *next;
3019 char *category_name;
3028 static PerfCounterAgent *perfcounters = NULL;
3031 perfcounters_emit (MonoProfiler *profiler)
3033 PerfCounterAgent *pcagent;
3034 LogBuffer *logbuffer;
3037 EVENT_SIZE /* event */ +
3038 LEB128_SIZE /* len */
3041 for (pcagent = perfcounters; pcagent; pcagent = pcagent->next) {
3042 if (pcagent->emitted)
3046 LEB128_SIZE /* section */ +
3047 strlen (pcagent->category_name) + 1 /* category name */ +
3048 strlen (pcagent->name) + 1 /* name */ +
3049 LEB128_SIZE /* type */ +
3050 LEB128_SIZE /* unit */ +
3051 LEB128_SIZE /* variance */ +
3052 LEB128_SIZE /* index */
3061 logbuffer = ensure_logbuf (size);
3063 ENTER_LOG (logbuffer, "perfcounters");
3064 emit_byte (logbuffer, TYPE_SAMPLE_COUNTERS_DESC | TYPE_SAMPLE);
3065 emit_value (logbuffer, len);
3066 for (pcagent = perfcounters; pcagent; pcagent = pcagent->next) {
3067 if (pcagent->emitted)
3070 emit_value (logbuffer, MONO_COUNTER_PERFCOUNTERS);
3071 emit_string (logbuffer, pcagent->category_name, strlen (pcagent->category_name) + 1);
3072 emit_string (logbuffer, pcagent->name, strlen (pcagent->name) + 1);
3073 emit_value (logbuffer, MONO_COUNTER_LONG);
3074 emit_value (logbuffer, MONO_COUNTER_RAW);
3075 emit_value (logbuffer, MONO_COUNTER_VARIABLE);
3076 emit_value (logbuffer, pcagent->index);
3078 pcagent->emitted = 1;
3080 EXIT_LOG (logbuffer);
3082 safe_send (profiler, logbuffer);
3086 perfcounters_foreach (char *category_name, char *name, unsigned char type, gint64 value, gpointer user_data)
3088 PerfCounterAgent *pcagent;
3090 for (pcagent = perfcounters; pcagent; pcagent = pcagent->next) {
3091 if (strcmp (pcagent->category_name, category_name) != 0 || strcmp (pcagent->name, name) != 0)
3093 if (pcagent->value == value)
3096 pcagent->value = value;
3097 pcagent->updated = 1;
3098 pcagent->deleted = 0;
3102 pcagent = g_new0 (PerfCounterAgent, 1);
3103 pcagent->next = perfcounters;
3104 pcagent->index = counters_index++;
3105 pcagent->category_name = g_strdup (category_name);
3106 pcagent->name = g_strdup (name);
3107 pcagent->type = (int) type;
3108 pcagent->value = value;
3109 pcagent->emitted = 0;
3110 pcagent->updated = 1;
3111 pcagent->deleted = 0;
3113 perfcounters = pcagent;
3119 perfcounters_sample (MonoProfiler *profiler, uint64_t timestamp)
3121 PerfCounterAgent *pcagent;
3122 LogBuffer *logbuffer;
3125 if (!counters_initialized)
3128 mono_mutex_lock (&counters_mutex);
3130 /* mark all perfcounters as deleted, foreach will unmark them as necessary */
3131 for (pcagent = perfcounters; pcagent; pcagent = pcagent->next)
3132 pcagent->deleted = 1;
3134 mono_perfcounter_foreach (perfcounters_foreach, perfcounters);
3136 perfcounters_emit (profiler);
3139 EVENT_SIZE /* event */ +
3140 LEB128_SIZE /* time */
3143 for (pcagent = perfcounters; pcagent; pcagent = pcagent->next) {
3144 if (pcagent->deleted || !pcagent->updated)
3148 LEB128_SIZE /* index */ +
3149 LEB128_SIZE /* type */ +
3150 LEB128_SIZE /* value */
3155 LEB128_SIZE /* stop marker */
3158 logbuffer = ensure_logbuf (size);
3160 ENTER_LOG (logbuffer, "perfcounters");
3161 emit_byte (logbuffer, TYPE_SAMPLE_COUNTERS | TYPE_SAMPLE);
3162 emit_uvalue (logbuffer, timestamp);
3163 for (pcagent = perfcounters; pcagent; pcagent = pcagent->next) {
3164 if (pcagent->deleted || !pcagent->updated)
3166 emit_uvalue (logbuffer, pcagent->index);
3167 emit_uvalue (logbuffer, MONO_COUNTER_LONG);
3168 emit_svalue (logbuffer, pcagent->value);
3170 pcagent->updated = 0;
3173 emit_value (logbuffer, 0);
3174 EXIT_LOG (logbuffer);
3176 safe_send (profiler, logbuffer);
3178 mono_mutex_unlock (&counters_mutex);
3182 counters_and_perfcounters_sample (MonoProfiler *prof)
3184 static uint64_t start = -1;
3188 start = current_time ();
3190 now = current_time ();
3191 counters_sample (prof, (now - start) / 1000/ 1000);
3192 perfcounters_sample (prof, (now - start) / 1000/ 1000);
3195 #define COVERAGE_DEBUG(x) if (debug_coverage) {x}
3196 static mono_mutex_t coverage_mutex;
3197 static MonoConcurrentHashTable *coverage_methods = NULL;
3198 static MonoConcurrentHashTable *coverage_assemblies = NULL;
3199 static MonoConcurrentHashTable *coverage_classes = NULL;
3201 static MonoConcurrentHashTable *filtered_classes = NULL;
3202 static MonoConcurrentHashTable *entered_methods = NULL;
3203 static MonoConcurrentHashTable *image_to_methods = NULL;
3204 static MonoConcurrentHashTable *suppressed_assemblies = NULL;
3205 static gboolean coverage_initialized = FALSE;
3207 static GPtrArray *coverage_data = NULL;
3208 static int previous_offset = 0;
3210 typedef struct _MethodNode MethodNode;
3211 struct _MethodNode {
3212 MonoLockFreeQueueNode node;
3216 typedef struct _CoverageEntry CoverageEntry;
3217 struct _CoverageEntry {
3226 free_coverage_entry (gpointer data, gpointer userdata)
3228 CoverageEntry *entry = (CoverageEntry *)data;
3229 g_free (entry->filename);
3234 obtain_coverage_for_method (MonoProfiler *prof, const MonoProfileCoverageEntry *entry)
3236 int offset = entry->iloffset - previous_offset;
3237 CoverageEntry *e = g_new (CoverageEntry, 1);
3239 previous_offset = entry->iloffset;
3242 e->counter = entry->counter;
3243 e->filename = g_strdup(entry->filename ? entry->filename : "");
3244 e->line = entry->line;
3245 e->column = entry->col;
3247 g_ptr_array_add (coverage_data, e);
3251 parse_generic_type_names(char *name)
3253 char *new_name, *ret;
3254 int within_generic_declaration = 0, generic_members = 1;
3256 if (name == NULL || *name == '\0')
3257 return g_strdup ("");
3259 if (!(ret = new_name = calloc (strlen (name) * 4 + 1, sizeof (char))))
3265 within_generic_declaration = 1;
3269 within_generic_declaration = 0;
3271 if (*(name - 1) != '<') {
3273 *new_name++ = '0' + generic_members;
3275 memcpy (new_name, "<>", 8);
3279 generic_members = 0;
3287 if (!within_generic_declaration)
3288 *new_name++ = *name;
3297 static int method_id;
3299 build_method_buffer (gpointer key, gpointer value, gpointer userdata)
3301 MonoMethod *method = (MonoMethod *)value;
3302 MonoProfiler *prof = (MonoProfiler *)userdata;
3306 const char *image_name, *method_name, *sig, *first_filename;
3307 LogBuffer *logbuffer;
3310 previous_offset = 0;
3311 coverage_data = g_ptr_array_new ();
3313 mono_profiler_coverage_get (prof, method, obtain_coverage_for_method);
3315 klass = mono_method_get_class (method);
3316 image = mono_class_get_image (klass);
3317 image_name = mono_image_get_name (image);
3319 sig = mono_signature_get_desc (mono_method_signature (method), TRUE);
3320 class_name = parse_generic_type_names (mono_type_get_name (mono_class_get_type (klass)));
3321 method_name = mono_method_get_name (method);
3323 if (coverage_data->len != 0) {
3324 CoverageEntry *entry = coverage_data->pdata[0];
3325 first_filename = entry->filename ? entry->filename : "";
3327 first_filename = "";
3329 image_name = image_name ? image_name : "";
3330 sig = sig ? sig : "";
3331 method_name = method_name ? method_name : "";
3333 logbuffer = ensure_logbuf (
3334 EVENT_SIZE /* event */ +
3335 strlen (image_name) + 1 /* image name */ +
3336 strlen (class_name) + 1 /* class name */ +
3337 strlen (method_name) + 1 /* method name */ +
3338 strlen (sig) + 1 /* signature */ +
3339 strlen (first_filename) + 1 /* first file name */ +
3340 LEB128_SIZE /* token */ +
3341 LEB128_SIZE /* method id */ +
3342 LEB128_SIZE /* entries */
3344 ENTER_LOG (logbuffer, "coverage-methods");
3346 emit_byte (logbuffer, TYPE_COVERAGE_METHOD | TYPE_COVERAGE);
3347 emit_string (logbuffer, image_name, strlen (image_name) + 1);
3348 emit_string (logbuffer, class_name, strlen (class_name) + 1);
3349 emit_string (logbuffer, method_name, strlen (method_name) + 1);
3350 emit_string (logbuffer, sig, strlen (sig) + 1);
3351 emit_string (logbuffer, first_filename, strlen (first_filename) + 1);
3353 emit_uvalue (logbuffer, mono_method_get_token (method));
3354 emit_uvalue (logbuffer, method_id);
3355 emit_value (logbuffer, coverage_data->len);
3357 EXIT_LOG (logbuffer);
3358 safe_send (prof, logbuffer);
3360 for (i = 0; i < coverage_data->len; i++) {
3361 CoverageEntry *entry = coverage_data->pdata[i];
3363 logbuffer = ensure_logbuf (
3364 EVENT_SIZE /* event */ +
3365 LEB128_SIZE /* method id */ +
3366 LEB128_SIZE /* offset */ +
3367 LEB128_SIZE /* counter */ +
3368 LEB128_SIZE /* line */ +
3369 LEB128_SIZE /* column */
3371 ENTER_LOG (logbuffer, "coverage-statement");
3373 emit_byte (logbuffer, TYPE_COVERAGE_STATEMENT | TYPE_COVERAGE);
3374 emit_uvalue (logbuffer, method_id);
3375 emit_uvalue (logbuffer, entry->offset);
3376 emit_uvalue (logbuffer, entry->counter);
3377 emit_uvalue (logbuffer, entry->line);
3378 emit_uvalue (logbuffer, entry->column);
3380 EXIT_LOG (logbuffer);
3381 safe_send (prof, logbuffer);
3386 g_free (class_name);
3388 g_ptr_array_foreach (coverage_data, free_coverage_entry, NULL);
3389 g_ptr_array_free (coverage_data, TRUE);
3390 coverage_data = NULL;
3393 /* This empties the queue */
3395 count_queue (MonoLockFreeQueue *queue)
3397 MonoLockFreeQueueNode *node;
3400 while ((node = mono_lock_free_queue_dequeue (queue))) {
3402 mono_lock_free_queue_node_free (node);
3409 build_class_buffer (gpointer key, gpointer value, gpointer userdata)
3411 MonoClass *klass = (MonoClass *)key;
3412 MonoLockFreeQueue *class_methods = (MonoLockFreeQueue *)value;
3413 MonoProfiler *prof = (MonoProfiler *)userdata;
3416 const char *assembly_name;
3417 int number_of_methods, partially_covered;
3418 guint fully_covered;
3419 LogBuffer *logbuffer;
3421 image = mono_class_get_image (klass);
3422 assembly_name = mono_image_get_name (image);
3423 class_name = mono_type_get_name (mono_class_get_type (klass));
3425 assembly_name = assembly_name ? assembly_name : "";
3426 number_of_methods = mono_class_num_methods (klass);
3427 fully_covered = count_queue (class_methods);
3428 /* We don't handle partial covered yet */
3429 partially_covered = 0;
3431 logbuffer = ensure_logbuf (
3432 EVENT_SIZE /* event */ +
3433 strlen (assembly_name) + 1 /* assembly name */ +
3434 strlen (class_name) + 1 /* class name */ +
3435 LEB128_SIZE /* no. methods */ +
3436 LEB128_SIZE /* fully covered */ +
3437 LEB128_SIZE /* partially covered */
3440 ENTER_LOG (logbuffer, "coverage-class");
3441 emit_byte (logbuffer, TYPE_COVERAGE_CLASS | TYPE_COVERAGE);
3442 emit_string (logbuffer, assembly_name, strlen (assembly_name) + 1);
3443 emit_string (logbuffer, class_name, strlen (class_name) + 1);
3444 emit_uvalue (logbuffer, number_of_methods);
3445 emit_uvalue (logbuffer, fully_covered);
3446 emit_uvalue (logbuffer, partially_covered);
3447 EXIT_LOG (logbuffer);
3449 safe_send (prof, logbuffer);
3451 g_free (class_name);
3455 get_coverage_for_image (MonoImage *image, int *number_of_methods, guint *fully_covered, int *partially_covered)
3457 MonoLockFreeQueue *image_methods = mono_conc_hashtable_lookup (image_to_methods, image);
3459 *number_of_methods = mono_image_get_table_rows (image, MONO_TABLE_METHOD);
3461 *fully_covered = count_queue (image_methods);
3465 // FIXME: We don't handle partially covered yet.
3466 *partially_covered = 0;
3470 build_assembly_buffer (gpointer key, gpointer value, gpointer userdata)
3472 MonoAssembly *assembly = (MonoAssembly *)value;
3473 MonoProfiler *prof = (MonoProfiler *)userdata;
3474 MonoImage *image = mono_assembly_get_image (assembly);
3475 LogBuffer *logbuffer;
3476 const char *name, *guid, *filename;
3477 int number_of_methods = 0, partially_covered = 0;
3478 guint fully_covered = 0;
3480 name = mono_image_get_name (image);
3481 guid = mono_image_get_guid (image);
3482 filename = mono_image_get_filename (image);
3484 name = name ? name : "";
3485 guid = guid ? guid : "";
3486 filename = filename ? filename : "";
3488 get_coverage_for_image (image, &number_of_methods, &fully_covered, &partially_covered);
3490 logbuffer = ensure_logbuf (
3491 EVENT_SIZE /* event */ +
3492 strlen (name) + 1 /* name */ +
3493 strlen (guid) + 1 /* guid */ +
3494 strlen (filename) + 1 /* file name */ +
3495 LEB128_SIZE /* no. methods */ +
3496 LEB128_SIZE /* fully covered */ +
3497 LEB128_SIZE /* partially covered */
3500 ENTER_LOG (logbuffer, "coverage-assemblies");
3501 emit_byte (logbuffer, TYPE_COVERAGE_ASSEMBLY | TYPE_COVERAGE);
3502 emit_string (logbuffer, name, strlen (name) + 1);
3503 emit_string (logbuffer, guid, strlen (guid) + 1);
3504 emit_string (logbuffer, filename, strlen (filename) + 1);
3505 emit_uvalue (logbuffer, number_of_methods);
3506 emit_uvalue (logbuffer, fully_covered);
3507 emit_uvalue (logbuffer, partially_covered);
3508 EXIT_LOG (logbuffer);
3510 safe_send (prof, logbuffer);
3514 dump_coverage (MonoProfiler *prof)
3516 if (!coverage_initialized)
3519 COVERAGE_DEBUG(fprintf (stderr, "Coverage: Started dump\n");)
3522 mono_mutex_lock (&coverage_mutex);
3523 mono_conc_hashtable_foreach (coverage_assemblies, build_assembly_buffer, prof);
3524 mono_conc_hashtable_foreach (coverage_classes, build_class_buffer, prof);
3525 mono_conc_hashtable_foreach (coverage_methods, build_method_buffer, prof);
3526 mono_mutex_unlock (&coverage_mutex);
3528 COVERAGE_DEBUG(fprintf (stderr, "Coverage: Finished dump\n");)
3532 process_method_enter_coverage (MonoProfiler *prof, MonoMethod *method)
3537 if (!coverage_initialized)
3540 klass = mono_method_get_class (method);
3541 image = mono_class_get_image (klass);
3543 if (mono_conc_hashtable_lookup (suppressed_assemblies, (gpointer) mono_image_get_name (image)))
3546 mono_mutex_lock (&coverage_mutex);
3547 mono_conc_hashtable_insert (entered_methods, method, method);
3548 mono_mutex_unlock (&coverage_mutex);
3551 static MonoLockFreeQueueNode *
3552 create_method_node (MonoMethod *method)
3554 MethodNode *node = g_malloc (sizeof (MethodNode));
3555 mono_lock_free_queue_node_init ((MonoLockFreeQueueNode *) node, FALSE);
3556 node->method = method;
3558 return (MonoLockFreeQueueNode *) node;
3562 coverage_filter (MonoProfiler *prof, MonoMethod *method)
3566 MonoAssembly *assembly;
3567 MonoMethodHeader *header;
3568 guint32 iflags, flags, code_size;
3569 char *fqn, *classname;
3570 gboolean has_positive, found;
3571 MonoLockFreeQueue *image_methods, *class_methods;
3572 MonoLockFreeQueueNode *node;
3574 if (!coverage_initialized)
3577 COVERAGE_DEBUG(fprintf (stderr, "Coverage filter for %s\n", mono_method_get_name (method));)
3579 flags = mono_method_get_flags (method, &iflags);
3580 if ((iflags & 0x1000 /*METHOD_IMPL_ATTRIBUTE_INTERNAL_CALL*/) ||
3581 (flags & 0x2000 /*METHOD_ATTRIBUTE_PINVOKE_IMPL*/)) {
3582 COVERAGE_DEBUG(fprintf (stderr, " Internal call or pinvoke - ignoring\n");)
3586 // Don't need to do anything else if we're already tracking this method
3587 if (mono_conc_hashtable_lookup (coverage_methods, method)) {
3588 COVERAGE_DEBUG(fprintf (stderr, " Already tracking\n");)
3592 klass = mono_method_get_class (method);
3593 image = mono_class_get_image (klass);
3595 // Don't handle coverage for the core assemblies
3596 if (mono_conc_hashtable_lookup (suppressed_assemblies, (gpointer) mono_image_get_name (image)) != NULL)
3599 if (prof->coverage_filters) {
3600 /* Check already filtered classes first */
3601 if (mono_conc_hashtable_lookup (filtered_classes, klass)) {
3602 COVERAGE_DEBUG(fprintf (stderr, " Already filtered\n");)
3606 classname = mono_type_get_name (mono_class_get_type (klass));
3608 fqn = g_strdup_printf ("[%s]%s", mono_image_get_name (image), classname);
3610 COVERAGE_DEBUG(fprintf (stderr, " Looking for %s in filter\n", fqn);)
3611 // Check positive filters first
3612 has_positive = FALSE;
3614 for (guint i = 0; i < prof->coverage_filters->len; ++i) {
3615 char *filter = g_ptr_array_index (prof->coverage_filters, i);
3617 if (filter [0] == '+') {
3618 filter = &filter [1];
3620 COVERAGE_DEBUG(fprintf (stderr, " Checking against +%s ...", filter);)
3622 if (strstr (fqn, filter) != NULL) {
3623 COVERAGE_DEBUG(fprintf (stderr, "matched\n");)
3626 COVERAGE_DEBUG(fprintf (stderr, "no match\n");)
3628 has_positive = TRUE;
3632 if (has_positive && !found) {
3633 COVERAGE_DEBUG(fprintf (stderr, " Positive match was not found\n");)
3635 mono_mutex_lock (&coverage_mutex);
3636 mono_conc_hashtable_insert (filtered_classes, klass, klass);
3637 mono_mutex_unlock (&coverage_mutex);
3644 for (guint i = 0; i < prof->coverage_filters->len; ++i) {
3645 // FIXME: Is substring search sufficient?
3646 char *filter = g_ptr_array_index (prof->coverage_filters, i);
3647 if (filter [0] == '+')
3651 filter = &filter [1];
3652 COVERAGE_DEBUG(fprintf (stderr, " Checking against -%s ...", filter);)
3654 if (strstr (fqn, filter) != NULL) {
3655 COVERAGE_DEBUG(fprintf (stderr, "matched\n");)
3657 mono_mutex_lock (&coverage_mutex);
3658 mono_conc_hashtable_insert (filtered_classes, klass, klass);
3659 mono_mutex_unlock (&coverage_mutex);
3665 COVERAGE_DEBUG(fprintf (stderr, "no match\n");)
3673 COVERAGE_DEBUG(fprintf (stderr, " Handling coverage for %s\n", mono_method_get_name (method));)
3674 header = mono_method_get_header (method);
3676 mono_method_header_get_code (header, &code_size, NULL);
3678 assembly = mono_image_get_assembly (image);
3680 mono_mutex_lock (&coverage_mutex);
3681 mono_conc_hashtable_insert (coverage_methods, method, method);
3682 mono_conc_hashtable_insert (coverage_assemblies, assembly, assembly);
3683 mono_mutex_unlock (&coverage_mutex);
3685 image_methods = mono_conc_hashtable_lookup (image_to_methods, image);
3687 if (image_methods == NULL) {
3688 image_methods = g_malloc (sizeof (MonoLockFreeQueue));
3689 mono_lock_free_queue_init (image_methods);
3690 mono_mutex_lock (&coverage_mutex);
3691 mono_conc_hashtable_insert (image_to_methods, image, image_methods);
3692 mono_mutex_unlock (&coverage_mutex);
3695 node = create_method_node (method);
3696 mono_lock_free_queue_enqueue (image_methods, node);
3698 class_methods = mono_conc_hashtable_lookup (coverage_classes, klass);
3700 if (class_methods == NULL) {
3701 class_methods = g_malloc (sizeof (MonoLockFreeQueue));
3702 mono_lock_free_queue_init (class_methods);
3703 mono_mutex_lock (&coverage_mutex);
3704 mono_conc_hashtable_insert (coverage_classes, klass, class_methods);
3705 mono_mutex_unlock (&coverage_mutex);
3708 node = create_method_node (method);
3709 mono_lock_free_queue_enqueue (class_methods, node);
3714 #define LINE_BUFFER_SIZE 4096
3715 /* Max file limit of 128KB */
3716 #define MAX_FILE_SIZE 128 * 1024
3718 get_file_content (FILE *stream)
3723 int res, offset = 0;
3725 res = fseek (stream, 0, SEEK_END);
3729 filesize = ftell (stream);
3733 res = fseek (stream, 0, SEEK_SET);
3737 if (filesize > MAX_FILE_SIZE)
3740 buffer = g_malloc ((filesize + 1) * sizeof (char));
3741 while ((bytes_read = fread (buffer + offset, 1, LINE_BUFFER_SIZE, stream)) > 0)
3742 offset += bytes_read;
3744 /* NULL terminate our buffer */
3745 buffer[filesize] = '\0';
3750 get_next_line (char *contents, char **next_start)
3754 if (p == NULL || *p == '\0') {
3759 while (*p != '\n' && *p != '\0')
3764 *next_start = p + 1;
3772 init_suppressed_assemblies (void)
3778 suppressed_assemblies = mono_conc_hashtable_new (g_str_hash, g_str_equal);
3779 sa_file = fopen (SUPPRESSION_DIR "/mono-profiler-log.suppression", "r");
3780 if (sa_file == NULL)
3783 /* Don't need to free @content as it is referred to by the lines stored in @suppressed_assemblies */
3784 content = get_file_content (sa_file);
3785 if (content == NULL) {
3786 g_error ("mono-profiler-log.suppression is greater than 128kb - aborting\n");
3789 while ((line = get_next_line (content, &content))) {
3790 line = g_strchomp (g_strchug (line));
3791 /* No locking needed as we're doing initialization */
3792 mono_conc_hashtable_insert (suppressed_assemblies, line, line);
3798 #endif /* DISABLE_HELPER_THREAD */
3801 coverage_init (MonoProfiler *prof)
3803 #ifndef DISABLE_HELPER_THREAD
3804 assert (!coverage_initialized);
3806 COVERAGE_DEBUG(fprintf (stderr, "Coverage initialized\n");)
3808 mono_mutex_init (&coverage_mutex);
3809 coverage_methods = mono_conc_hashtable_new (NULL, NULL);
3810 coverage_assemblies = mono_conc_hashtable_new (NULL, NULL);
3811 coverage_classes = mono_conc_hashtable_new (NULL, NULL);
3812 filtered_classes = mono_conc_hashtable_new (NULL, NULL);
3813 entered_methods = mono_conc_hashtable_new (NULL, NULL);
3814 image_to_methods = mono_conc_hashtable_new (NULL, NULL);
3815 init_suppressed_assemblies ();
3817 coverage_initialized = TRUE;
3818 #endif /* DISABLE_HELPER_THREAD */
3822 log_shutdown (MonoProfiler *prof)
3827 #ifndef DISABLE_HELPER_THREAD
3828 counters_and_perfcounters_sample (prof);
3830 dump_coverage (prof);
3832 if (prof->command_port) {
3834 ign_res (write (prof->pipes [1], &c, 1));
3835 pthread_join (prof->helper_thread, &res);
3841 for (i = 0; i < num_perf; ++i)
3842 read_perf_mmap (prof, i);
3846 g_ptr_array_free (prof->sorted_sample_events, TRUE);
3848 if (TLS_GET (LogBuffer, tlsbuffer))
3849 send_buffer (prof, TLS_GET (GPtrArray, tlsmethodlist), TLS_GET (LogBuffer, tlsbuffer));
3851 TLS_SET (tlsbuffer, NULL);
3852 TLS_SET (tlsmethodlist, NULL);
3854 InterlockedWrite (&prof->run_writer_thread, 0);
3855 pthread_join (prof->writer_thread, &res);
3857 #if defined (HAVE_SYS_ZLIB)
3859 gzclose (prof->gzfile);
3861 if (prof->pipe_output)
3862 pclose (prof->file);
3864 fclose (prof->file);
3866 mono_conc_hashtable_destroy (prof->method_table);
3867 mono_mutex_destroy (&prof->method_table_mutex);
3869 if (coverage_initialized) {
3870 mono_conc_hashtable_destroy (coverage_methods);
3871 mono_conc_hashtable_destroy (coverage_assemblies);
3872 mono_conc_hashtable_destroy (coverage_classes);
3873 mono_conc_hashtable_destroy (filtered_classes);
3875 mono_conc_hashtable_destroy (entered_methods);
3876 mono_conc_hashtable_destroy (image_to_methods);
3877 mono_conc_hashtable_destroy (suppressed_assemblies);
3878 mono_mutex_destroy (&coverage_mutex);
3885 new_filename (const char* filename)
3887 time_t t = time (NULL);
3888 int pid = process_id ();
3893 int count_dates = 0;
3897 for (p = filename; *p; p++) {
3908 if (!count_dates && !count_pids)
3909 return pstrdup (filename);
3910 snprintf (pid_buf, sizeof (pid_buf), "%d", pid);
3912 snprintf (time_buf, sizeof (time_buf), "%d%02d%02d%02d%02d%02d",
3913 1900 + ts->tm_year, 1 + ts->tm_mon, ts->tm_mday, ts->tm_hour, ts->tm_min, ts->tm_sec);
3914 s_date = strlen (time_buf);
3915 s_pid = strlen (pid_buf);
3916 d = res = malloc (strlen (filename) + s_date * count_dates + s_pid * count_pids);
3917 for (p = filename; *p; p++) {
3924 strcpy (d, time_buf);
3927 } else if (*p == 'p') {
3928 strcpy (d, pid_buf);
3931 } else if (*p == '%') {
3943 //this is exposed by the JIT, but it's not meant to be a supported API for now.
3944 extern void mono_threads_attach_tools_thread (void);
3946 #ifndef DISABLE_HELPER_THREAD
3949 helper_thread (void* arg)
3951 MonoProfiler* prof = arg;
3955 MonoThread *thread = NULL;
3957 mono_threads_attach_tools_thread ();
3958 //fprintf (stderr, "Server listening\n");
3959 command_socket = -1;
3965 FD_SET (prof->server_socket, &rfds);
3966 max_fd = prof->server_socket;
3967 FD_SET (prof->pipes [0], &rfds);
3968 if (max_fd < prof->pipes [0])
3969 max_fd = prof->pipes [0];
3970 if (command_socket >= 0) {
3971 FD_SET (command_socket, &rfds);
3972 if (max_fd < command_socket)
3973 max_fd = command_socket;
3978 for ( i = 0; i < num_perf; ++i) {
3979 if (perf_data [i].perf_fd < 0)
3981 FD_SET (perf_data [i].perf_fd, &rfds);
3982 if (max_fd < perf_data [i].perf_fd)
3983 max_fd = perf_data [i].perf_fd;
3988 counters_and_perfcounters_sample (prof);
3992 len = select (max_fd + 1, &rfds, NULL, NULL, &tv);
3998 g_warning ("Error in proflog server: %s", strerror (errno));
4002 if (FD_ISSET (prof->pipes [0], &rfds)) {
4004 int r = read (prof->pipes [0], &c, 1);
4005 if (r == 1 && c == 0) {
4006 StatBuffer *sbufbase = prof->stat_buffers;
4008 if (!sbufbase->next)
4010 sbuf = sbufbase->next->next;
4011 sbufbase->next->next = NULL;
4013 fprintf (stderr, "stat buffer dump\n");
4015 dump_sample_hits (prof, sbuf);
4016 free_buffer (sbuf, sbuf->size);
4017 safe_send (prof, ensure_logbuf (0));
4021 /* time to shut down */
4022 dump_sample_hits (prof, prof->stat_buffers);
4024 mono_thread_detach (thread);
4026 fprintf (stderr, "helper shutdown\n");
4030 for ( i = 0; i < num_perf; ++i) {
4031 if (perf_data [i].perf_fd < 0)
4033 if (FD_ISSET (perf_data [i].perf_fd, &rfds))
4034 read_perf_mmap (prof, i);
4038 safe_send (prof, ensure_logbuf (0));
4044 for ( i = 0; i < num_perf; ++i) {
4045 if (perf_data [i].perf_fd < 0)
4047 if (FD_ISSET (perf_data [i].perf_fd, &rfds)) {
4048 read_perf_mmap (prof, i);
4049 safe_send (prof, ensure_logbuf (0));
4054 if (command_socket >= 0 && FD_ISSET (command_socket, &rfds)) {
4055 len = read (command_socket, buf, sizeof (buf) - 1);
4059 close (command_socket);
4060 command_socket = -1;
4064 if (strcmp (buf, "heapshot\n") == 0) {
4065 heapshot_requested = 1;
4066 //fprintf (stderr, "perform heapshot\n");
4067 if (InterlockedRead (&runtime_inited) && !thread) {
4068 thread = mono_thread_attach (mono_get_root_domain ());
4069 /*fprintf (stderr, "attached\n");*/
4072 process_requests (prof);
4073 mono_thread_detach (thread);
4079 if (!FD_ISSET (prof->server_socket, &rfds)) {
4082 command_socket = accept (prof->server_socket, NULL, NULL);
4083 if (command_socket < 0)
4085 //fprintf (stderr, "Accepted connection\n");
4091 start_helper_thread (MonoProfiler* prof)
4093 struct sockaddr_in server_address;
4096 if (pipe (prof->pipes) < 0) {
4097 fprintf (stderr, "Cannot create pipe\n");
4100 prof->server_socket = socket (PF_INET, SOCK_STREAM, 0);
4101 if (prof->server_socket < 0) {
4102 fprintf (stderr, "Cannot create server socket\n");
4105 memset (&server_address, 0, sizeof (server_address));
4106 server_address.sin_family = AF_INET;
4107 server_address.sin_addr.s_addr = INADDR_ANY;
4108 server_address.sin_port = htons (prof->command_port);
4109 if (bind (prof->server_socket, (struct sockaddr *) &server_address, sizeof (server_address)) < 0) {
4110 fprintf (stderr, "Cannot bind server socket, port: %d: %s\n", prof->command_port, strerror (errno));
4111 close (prof->server_socket);
4114 if (listen (prof->server_socket, 1) < 0) {
4115 fprintf (stderr, "Cannot listen server socket\n");
4116 close (prof->server_socket);
4119 slen = sizeof (server_address);
4120 if (getsockname (prof->server_socket, (struct sockaddr *)&server_address, &slen) == 0) {
4121 prof->command_port = ntohs (server_address.sin_port);
4122 /*fprintf (stderr, "Assigned server port: %d\n", prof->command_port);*/
4125 r = pthread_create (&prof->helper_thread, NULL, helper_thread, prof);
4127 close (prof->server_socket);
4135 writer_thread (void *arg)
4137 MonoProfiler *prof = arg;
4139 mono_threads_attach_tools_thread ();
4143 while (InterlockedRead (&prof->run_writer_thread)) {
4144 WriterQueueEntry *entry;
4146 while ((entry = (WriterQueueEntry *) mono_lock_free_queue_dequeue (&prof->writer_queue))) {
4147 LogBuffer *method_buffer = NULL;
4148 gboolean new_methods = FALSE;
4150 if (entry->methods->len)
4151 method_buffer = create_buffer ();
4154 * Encode the method events in a temporary log buffer that we
4155 * flush to disk before the main buffer, ensuring that all
4156 * methods have metadata emitted before they're referenced.
4158 for (guint i = 0; i < entry->methods->len; i++) {
4159 MethodInfo *info = g_ptr_array_index (entry->methods, i);
4161 if (mono_conc_hashtable_lookup (prof->method_table, info->method))
4167 * Other threads use this hash table to get a general
4168 * idea of whether a method has already been emitted to
4169 * the stream. Due to the way we add to this table, it
4170 * can easily happen that multiple threads queue up the
4171 * same methods, but that's OK since eventually all
4172 * methods will be in this table and the thread-local
4173 * method lists will just be empty for the rest of the
4176 mono_mutex_lock (&prof->method_table_mutex);
4177 mono_conc_hashtable_insert (prof->method_table, info->method, info->method);
4178 mono_mutex_unlock (&prof->method_table_mutex);
4180 char *name = mono_method_full_name (info->method, 1);
4181 int nlen = strlen (name) + 1;
4182 uint64_t now = current_time ();
4184 method_buffer = ensure_logbuf_inner (method_buffer,
4185 EVENT_SIZE /* event */ +
4186 LEB128_SIZE /* time */ +
4187 LEB128_SIZE /* method */ +
4188 LEB128_SIZE /* start */ +
4189 LEB128_SIZE /* size */ +
4193 emit_byte (method_buffer, TYPE_JIT | TYPE_METHOD);
4194 emit_time (method_buffer, now);
4195 emit_method_inner (method_buffer, info->method);
4196 emit_ptr (method_buffer, mono_jit_info_get_code_start (info->ji));
4197 emit_value (method_buffer, mono_jit_info_get_code_size (info->ji));
4199 memcpy (method_buffer->data, name, nlen);
4200 method_buffer->data += nlen;
4206 g_ptr_array_free (entry->methods, TRUE);
4209 dump_buffer (prof, method_buffer);
4210 else if (method_buffer)
4211 free_buffer (method_buffer, method_buffer->size);
4213 dump_buffer (prof, entry->buffer);
4223 start_writer_thread (MonoProfiler* prof)
4225 InterlockedWrite (&prof->run_writer_thread, 1);
4227 return !pthread_create (&prof->writer_thread, NULL, writer_thread, prof);
4231 runtime_initialized (MonoProfiler *profiler)
4233 #ifndef DISABLE_HELPER_THREAD
4234 if (hs_mode_ondemand || need_helper_thread) {
4235 if (!start_helper_thread (profiler))
4236 profiler->command_port = 0;
4240 start_writer_thread (profiler);
4242 InterlockedWrite (&runtime_inited, 1);
4243 #ifndef DISABLE_HELPER_THREAD
4244 counters_init (profiler);
4245 counters_sample (profiler, 0);
4247 /* ensure the main thread data and startup are available soon */
4248 safe_send (profiler, ensure_logbuf (0));
4251 static MonoProfiler*
4252 create_profiler (const char *filename, GPtrArray *filters)
4256 int force_delete = 0;
4257 prof = calloc (1, sizeof (MonoProfiler));
4259 prof->command_port = command_port;
4260 if (filename && *filename == '-') {
4266 filename = "|mprof-report -";
4268 filename = "output.mlpd";
4269 nf = (char*)filename;
4271 nf = new_filename (filename);
4273 int s = strlen (nf) + 32;
4274 char *p = malloc (s);
4275 snprintf (p, s, "|mprof-report '--out=%s' -", nf);
4281 prof->file = popen (nf + 1, "w");
4282 prof->pipe_output = 1;
4283 } else if (*nf == '#') {
4284 int fd = strtol (nf + 1, NULL, 10);
4285 prof->file = fdopen (fd, "a");
4289 prof->file = fopen (nf, "wb");
4292 fprintf (stderr, "Cannot create profiler output: %s\n", nf);
4295 #if defined (HAVE_SYS_ZLIB)
4297 prof->gzfile = gzdopen (fileno (prof->file), "wb");
4300 if (sample_type && !do_mono_sample)
4301 need_helper_thread = setup_perf_event ();
4303 /* FIXME: warn if different freq or sample type */
4307 if (do_mono_sample) {
4308 prof->stat_buffers = create_stat_buffer ();
4309 need_helper_thread = 1;
4311 if (do_counters && !need_helper_thread) {
4312 need_helper_thread = 1;
4315 prof->sorted_sample_events = g_ptr_array_sized_new (BUFFER_SIZE / SAMPLE_EVENT_SIZE_IN_SLOTS (0));
4317 #ifdef DISABLE_HELPER_THREAD
4318 if (hs_mode_ondemand)
4319 fprintf (stderr, "Ondemand heapshot unavailable on this arch.\n");
4322 fprintf (stderr, "Coverage unavailable on this arch.\n");
4326 mono_lock_free_queue_init (&prof->writer_queue);
4327 mono_mutex_init (&prof->method_table_mutex);
4328 prof->method_table = mono_conc_hashtable_new (NULL, NULL);
4331 coverage_init (prof);
4332 prof->coverage_filters = filters;
4334 prof->startup_time = current_time ();
4341 printf ("Log profiler version %d.%d (format: %d)\n", LOG_VERSION_MAJOR, LOG_VERSION_MINOR, LOG_DATA_VERSION);
4342 printf ("Usage: mono --profile=log[:OPTION1[,OPTION2...]] program.exe\n");
4343 printf ("Options:\n");
4344 printf ("\thelp show this usage info\n");
4345 printf ("\t[no]alloc enable/disable recording allocation info\n");
4346 printf ("\t[no]calls enable/disable recording enter/leave method events\n");
4347 printf ("\theapshot[=MODE] record heap shot info (by default at each major collection)\n");
4348 printf ("\t MODE: every XXms milliseconds, every YYgc collections, ondemand\n");
4349 printf ("\tcounters sample counters every 1s\n");
4350 printf ("\tsample[=TYPE] use statistical sampling mode (by default cycles/1000)\n");
4351 printf ("\t TYPE: cycles,instr,cacherefs,cachemiss,branches,branchmiss\n");
4352 printf ("\t TYPE can be followed by /FREQUENCY\n");
4353 printf ("\ttime=fast use a faster (but more inaccurate) timer\n");
4354 printf ("\tmaxframes=NUM collect up to NUM stack frames\n");
4355 printf ("\tcalldepth=NUM ignore method events for call chain depth bigger than NUM\n");
4356 printf ("\toutput=FILENAME write the data to file FILENAME (-FILENAME to overwrite)\n");
4357 printf ("\toutput=|PROGRAM write the data to the stdin of PROGRAM\n");
4358 printf ("\t %%t is subtituted with date and time, %%p with the pid\n");
4359 printf ("\treport create a report instead of writing the raw data to a file\n");
4360 printf ("\tzip compress the output data\n");
4361 printf ("\tport=PORTNUM use PORTNUM for the listening command server\n");
4362 printf ("\tcoverage enable collection of code coverage data\n");
4363 printf ("\tcovfilter=ASSEMBLY add an assembly to the code coverage filters\n");
4364 printf ("\t add a + to include the assembly or a - to exclude it\n");
4365 printf ("\t filter=-mscorlib\n");
4366 printf ("\tcovfilter-file=FILE use FILE to generate the list of assemblies to be filtered\n");
4372 match_option (const char* p, const char *opt, char **rval)
4374 int len = strlen (opt);
4375 if (strncmp (p, opt, len) == 0) {
4377 if (p [len] == '=' && p [len + 1]) {
4378 const char *opt = p + len + 1;
4379 const char *end = strchr (opt, ',');
4387 val = malloc (l + 1);
4388 memcpy (val, opt, l);
4393 if (p [len] == 0 || p [len] == ',') {
4395 return p + len + (p [len] == ',');
4413 static const SampleMode sample_modes [] = {
4414 {"cycles", SAMPLE_CYCLES},
4415 {"instr", SAMPLE_INSTRUCTIONS},
4416 {"cachemiss", SAMPLE_CACHE_MISSES},
4417 {"cacherefs", SAMPLE_CACHE_REFS},
4418 {"branches", SAMPLE_BRANCHES},
4419 {"branchmiss", SAMPLE_BRANCH_MISSES},
4424 set_sample_mode (char* val, int allow_empty)
4427 char *maybe_freq = NULL;
4429 const SampleMode *smode = sample_modes;
4430 #ifndef USE_PERF_EVENTS
4433 if (allow_empty && !val) {
4434 sample_type = SAMPLE_CYCLES;
4438 if (strcmp (val, "mono") == 0) {
4440 sample_type = SAMPLE_CYCLES;
4444 for (smode = sample_modes; smode->name; smode++) {
4445 int l = strlen (smode->name);
4446 if (strncmp (val, smode->name, l) == 0) {
4447 sample_type = smode->sample_mode;
4448 maybe_freq = val + l;
4454 if (*maybe_freq == '/') {
4455 count = strtoul (maybe_freq + 1, &end, 10);
4456 if (maybe_freq + 1 == end)
4458 sample_freq = count;
4459 } else if (*maybe_freq != 0) {
4468 set_hsmode (char* val, int allow_empty)
4472 if (allow_empty && !val)
4474 if (strcmp (val, "ondemand") == 0) {
4475 hs_mode_ondemand = 1;
4479 count = strtoul (val, &end, 10);
4482 if (strcmp (end, "ms") == 0)
4484 else if (strcmp (end, "gc") == 0)
4492 * declaration to silence the compiler: this is the entry point that
4493 * mono will load from the shared library and call.
4496 mono_profiler_startup (const char *desc);
4499 mono_profiler_startup_log (const char *desc);
4502 * this is the entry point that will be used when the profiler
4503 * is embedded inside the main executable.
4506 mono_profiler_startup_log (const char *desc)
4508 mono_profiler_startup (desc);
4512 mono_profiler_startup (const char *desc)
4515 GPtrArray *filters = NULL;
4516 char *filename = NULL;
4520 int calls_enabled = 0;
4521 int allocs_enabled = 0;
4522 int only_counters = 0;
4523 int only_coverage = 0;
4524 int events = MONO_PROFILE_GC|MONO_PROFILE_ALLOCATIONS|
4525 MONO_PROFILE_GC_MOVES|MONO_PROFILE_CLASS_EVENTS|MONO_PROFILE_THREADS|
4526 MONO_PROFILE_ENTER_LEAVE|MONO_PROFILE_JIT_COMPILATION|MONO_PROFILE_EXCEPTIONS|
4527 MONO_PROFILE_MONITOR_EVENTS|MONO_PROFILE_MODULE_EVENTS|MONO_PROFILE_GC_ROOTS|
4528 MONO_PROFILE_INS_COVERAGE|MONO_PROFILE_APPDOMAIN_EVENTS|MONO_PROFILE_CONTEXT_EVENTS|
4529 MONO_PROFILE_ASSEMBLY_EVENTS;
4532 if (strncmp (p, "log", 3))
4537 for (; *p; p = opt) {
4543 if ((opt = match_option (p, "help", NULL)) != p) {
4547 if ((opt = match_option (p, "calls", NULL)) != p) {
4551 if ((opt = match_option (p, "nocalls", NULL)) != p) {
4552 events &= ~MONO_PROFILE_ENTER_LEAVE;
4556 if ((opt = match_option (p, "alloc", NULL)) != p) {
4560 if ((opt = match_option (p, "noalloc", NULL)) != p) {
4561 events &= ~MONO_PROFILE_ALLOCATIONS;
4564 if ((opt = match_option (p, "time", &val)) != p) {
4565 if (strcmp (val, "fast") == 0)
4567 else if (strcmp (val, "null") == 0)
4574 if ((opt = match_option (p, "report", NULL)) != p) {
4578 if ((opt = match_option (p, "debug", NULL)) != p) {
4582 if ((opt = match_option (p, "sampling-real", NULL)) != p) {
4583 sampling_mode = MONO_PROFILER_STAT_MODE_REAL;
4586 if ((opt = match_option (p, "sampling-process", NULL)) != p) {
4587 sampling_mode = MONO_PROFILER_STAT_MODE_PROCESS;
4590 if ((opt = match_option (p, "heapshot", &val)) != p) {
4591 events &= ~MONO_PROFILE_ALLOCATIONS;
4592 events &= ~MONO_PROFILE_ENTER_LEAVE;
4595 set_hsmode (val, 1);
4598 if ((opt = match_option (p, "sample", &val)) != p) {
4599 events &= ~MONO_PROFILE_ALLOCATIONS;
4600 events &= ~MONO_PROFILE_ENTER_LEAVE;
4602 set_sample_mode (val, 1);
4605 if ((opt = match_option (p, "hsmode", &val)) != p) {
4606 fprintf (stderr, "The hsmode profiler option is obsolete, use heapshot=MODE.\n");
4607 set_hsmode (val, 0);
4610 if ((opt = match_option (p, "zip", NULL)) != p) {
4614 if ((opt = match_option (p, "output", &val)) != p) {
4618 if ((opt = match_option (p, "port", &val)) != p) {
4620 command_port = strtoul (val, &end, 10);
4624 if ((opt = match_option (p, "maxframes", &val)) != p) {
4626 num_frames = strtoul (val, &end, 10);
4627 if (num_frames > MAX_FRAMES)
4628 num_frames = MAX_FRAMES;
4630 notraces = num_frames == 0;
4633 if ((opt = match_option (p, "calldepth", &val)) != p) {
4635 max_call_depth = strtoul (val, &end, 10);
4639 if ((opt = match_option (p, "counters", NULL)) != p) {
4643 if ((opt = match_option (p, "countersonly", NULL)) != p) {
4647 if ((opt = match_option (p, "coverage", NULL)) != p) {
4649 events |= MONO_PROFILE_ENTER_LEAVE;
4650 debug_coverage = (g_getenv ("MONO_PROFILER_DEBUG_COVERAGE") != NULL);
4653 if ((opt = match_option (p, "onlycoverage", NULL)) != p) {
4657 if ((opt = match_option (p, "covfilter-file", &val)) != p) {
4659 char *line, *content;
4661 if (filters == NULL)
4662 filters = g_ptr_array_new ();
4664 filter_file = fopen (val, "r");
4665 if (filter_file == NULL) {
4666 fprintf (stderr, "Unable to open %s\n", val);
4670 /* Don't need to free content as it is referred to by the lines stored in @filters */
4671 content = get_file_content (filter_file);
4672 if (content == NULL)
4673 fprintf (stderr, "WARNING: %s is greater than 128kb - ignoring\n", val);
4675 while ((line = get_next_line (content, &content)))
4676 g_ptr_array_add (filters, g_strchug (g_strchomp (line)));
4678 fclose (filter_file);
4681 if ((opt = match_option (p, "covfilter", &val)) != p) {
4682 if (filters == NULL)
4683 filters = g_ptr_array_new ();
4685 g_ptr_array_add (filters, val);
4693 if (calls_enabled) {
4694 events |= MONO_PROFILE_ENTER_LEAVE;
4698 events |= MONO_PROFILE_ALLOCATIONS;
4702 events = MONO_PROFILE_ENTER_LEAVE | MONO_PROFILE_INS_COVERAGE;
4704 utils_init (fast_time);
4706 prof = create_profiler (filename, filters);
4711 mono_profiler_install (prof, log_shutdown);
4712 mono_profiler_install_gc (gc_event, gc_resize);
4713 mono_profiler_install_allocation (gc_alloc);
4714 mono_profiler_install_gc_moves (gc_moves);
4715 mono_profiler_install_gc_roots (gc_handle, gc_roots);
4716 mono_profiler_install_appdomain (NULL, domain_loaded, NULL, domain_unloaded);
4717 mono_profiler_install_appdomain_name (domain_name);
4718 mono_profiler_install_context (context_loaded, context_unloaded);
4719 mono_profiler_install_class (NULL, class_loaded, NULL, class_unloaded);
4720 mono_profiler_install_module (NULL, image_loaded, NULL, image_unloaded);
4721 mono_profiler_install_assembly (NULL, assembly_loaded, NULL, assembly_unloaded);
4722 mono_profiler_install_thread (thread_start, thread_end);
4723 mono_profiler_install_thread_name (thread_name);
4724 mono_profiler_install_enter_leave (method_enter, method_leave);
4725 mono_profiler_install_jit_end (method_jitted);
4726 mono_profiler_install_code_buffer_new (code_buffer_new);
4727 mono_profiler_install_exception (throw_exc, method_exc_leave, clause_exc);
4728 mono_profiler_install_monitor (monitor_event);
4729 mono_profiler_install_runtime_initialized (runtime_initialized);
4731 mono_profiler_install_coverage_filter (coverage_filter);
4733 if (do_mono_sample && sample_type == SAMPLE_CYCLES && !only_counters) {
4734 events |= MONO_PROFILE_STATISTICAL;
4735 mono_profiler_set_statistical_mode (sampling_mode, 1000000 / sample_freq);
4736 mono_profiler_install_statistical (mono_sample_hit);
4739 mono_profiler_set_events (events);
4741 TLS_INIT (tlsbuffer);
4742 TLS_INIT (tlsmethodlist);