[ci] Bump timeout in ms-test-suite
[mono-project.git] / mono / mini / trace.c
blob90f0af81b5a2c2e606f9e4b2d7be094f7be8d357
1 /*
2 * trace.c: Tracing facilities for the Mono Runtime.
4 * Author:
5 * Paolo Molaro (lupus@ximian.com)
6 * Dietmar Maurer (dietmar@ximian.com)
8 * (C) 2002 Ximian, Inc.
9 * Copyright 2011 Xamarin, Inc (http://www.xamarin.com)
10 * Licensed under the MIT license. See LICENSE file in the project root for full license information.
13 #include <config.h>
14 #ifdef HAVE_ALLOCA_H
15 #include <alloca.h>
16 #endif
17 #ifdef HAVE_UNISTD_H
18 #include <unistd.h>
19 #endif
20 #include <string.h>
21 #include "mini.h"
22 #include <mono/metadata/debug-helpers.h>
23 #include <mono/metadata/assembly.h>
24 #include <mono/utils/mono-time.h>
25 #include <mono/utils/mono-memory-model.h>
26 #include "trace.h"
28 #if defined (PLATFORM_ANDROID) || (defined (TARGET_IOS) && defined (TARGET_IOS))
29 # undef printf
30 # define printf(...) g_log("mono", G_LOG_LEVEL_MESSAGE, __VA_ARGS__)
31 # undef fprintf
32 # define fprintf(__ignore, ...) g_log ("mono-gc", G_LOG_LEVEL_MESSAGE, __VA_ARGS__)
33 #endif
35 #ifdef __GNUC__
37 #define RETURN_ADDRESS_N(N) (__builtin_extract_return_addr (__builtin_return_address (N)))
38 #define RETURN_ADDRESS() RETURN_ADDRESS_N(0)
40 #elif defined(_MSC_VER)
42 #include <intrin.h>
43 #pragma intrinsic(_ReturnAddress)
45 #define RETURN_ADDRESS() _ReturnAddress()
46 #define RETURN_ADDRESS_N(N) NULL
48 #else
50 #error "Missing return address intrinsics implementation"
52 #endif
54 static MonoTraceSpec trace_spec;
56 static volatile gint32 output_lock = 0;
58 gboolean
59 mono_trace_eval_exception (MonoClass *klass)
61 int include = 0;
62 int i;
64 if (!klass)
65 return FALSE;
67 for (i = 0; i < trace_spec.len; i++) {
68 MonoTraceOperation *op = &trace_spec.ops [i];
69 int inc = 0;
71 switch (op->op){
72 case MONO_TRACEOP_EXCEPTION:
73 if (strcmp ("", op->data) == 0 && strcmp ("all", op->data2) == 0)
74 inc = 1;
75 else if (strcmp ("", op->data) == 0 || strcmp (klass->name_space, op->data) == 0)
76 if (strcmp (klass->name, op->data2) == 0)
77 inc = 1;
78 break;
79 default:
80 break;
82 if (op->exclude){
83 if (inc)
84 include = 0;
85 } else if (inc)
86 include = 1;
89 return include;
92 gboolean
93 mono_trace_eval (MonoMethod *method)
95 int include = 0;
96 int i;
98 for (i = 0; i < trace_spec.len; i++){
99 MonoTraceOperation *op = &trace_spec.ops [i];
100 int inc = 0;
102 switch (op->op){
103 case MONO_TRACEOP_ALL:
104 inc = 1;
105 break;
106 case MONO_TRACEOP_PROGRAM:
107 if (trace_spec.assembly && (method->klass->image == mono_assembly_get_image (trace_spec.assembly)))
108 inc = 1;
109 break;
110 case MONO_TRACEOP_WRAPPER:
111 if ((method->wrapper_type == MONO_WRAPPER_NATIVE_TO_MANAGED) ||
112 (method->wrapper_type == MONO_WRAPPER_MANAGED_TO_NATIVE))
113 inc = 1;
114 break;
115 case MONO_TRACEOP_METHOD:
116 if (mono_method_desc_full_match ((MonoMethodDesc *) op->data, method))
117 inc = 1;
118 break;
119 case MONO_TRACEOP_CLASS:
120 if (strcmp (method->klass->name_space, op->data) == 0)
121 if (strcmp (method->klass->name, op->data2) == 0)
122 inc = 1;
123 break;
124 case MONO_TRACEOP_ASSEMBLY:
125 if (strcmp (mono_image_get_name (method->klass->image), op->data) == 0)
126 inc = 1;
127 break;
128 case MONO_TRACEOP_NAMESPACE:
129 if (strcmp (method->klass->name_space, op->data) == 0)
130 inc = 1;
131 break;
132 case MONO_TRACEOP_EXCEPTION:
133 break;
135 if (op->exclude) {
136 if (inc)
137 include = 0;
138 } else if (inc) {
139 include = 1;
142 return include;
145 static int is_filenamechar (char p)
147 if (p >= 'A' && p <= 'Z')
148 return TRUE;
149 if (p >= 'a' && p <= 'z')
150 return TRUE;
151 if (p >= '0' && p <= '9')
152 return TRUE;
153 if (p == '.' || p == ':' || p == '_' || p == '-' || p == '`')
154 return TRUE;
155 return FALSE;
158 static char *input;
159 static char *value;
161 static void get_string (void)
163 char *start = input;
164 while (is_filenamechar (*input)){
165 input++;
167 if (value != NULL)
168 g_free (value);
169 value = (char *)g_malloc (input - start + 1);
170 strncpy (value, start, input-start);
171 value [input-start] = 0;
174 enum Token {
175 TOKEN_METHOD,
176 TOKEN_CLASS,
177 TOKEN_ALL,
178 TOKEN_PROGRAM,
179 TOKEN_EXCEPTION,
180 TOKEN_NAMESPACE,
181 TOKEN_WRAPPER,
182 TOKEN_STRING,
183 TOKEN_EXCLUDE,
184 TOKEN_DISABLED,
185 TOKEN_SEPARATOR,
186 TOKEN_END,
187 TOKEN_ERROR
190 static int
191 get_token (void)
193 while (input [0] == '+')
194 input++;
196 if (input [0] == '\0') {
197 return TOKEN_END;
199 if (input [0] == 'M' && input [1] == ':'){
200 input += 2;
201 get_string ();
202 return TOKEN_METHOD;
204 if (input [0] == 'N' && input [1] == ':'){
205 input += 2;
206 get_string ();
207 return TOKEN_NAMESPACE;
209 if (input [0] == 'T' && input [1] == ':'){
210 input += 2;
211 get_string ();
212 return TOKEN_CLASS;
214 if (input [0] == 'E' && input [1] == ':'){
215 input += 2;
216 get_string ();
217 return TOKEN_EXCEPTION;
219 if (*input == '-'){
220 input++;
221 return TOKEN_EXCLUDE;
223 if (is_filenamechar (*input)){
224 get_string ();
225 if (strcmp (value, "all") == 0)
226 return TOKEN_ALL;
227 if (strcmp (value, "program") == 0)
228 return TOKEN_PROGRAM;
229 if (strcmp (value, "wrapper") == 0)
230 return TOKEN_WRAPPER;
231 if (strcmp (value, "disabled") == 0)
232 return TOKEN_DISABLED;
233 return TOKEN_STRING;
235 if (*input == ','){
236 input++;
237 return TOKEN_SEPARATOR;
240 fprintf (stderr, "Syntax error at or around '%s'\n", input);
241 return TOKEN_ERROR;
244 static void
245 cleanup (void)
247 if (value != NULL)
248 g_free (value);
251 static int
252 get_spec (int *last)
254 int token = get_token ();
255 if (token == TOKEN_EXCLUDE){
256 token = get_spec (last);
257 if (token == TOKEN_EXCLUDE){
258 fprintf (stderr, "Expecting an expression");
259 return TOKEN_ERROR;
261 if (token == TOKEN_ERROR)
262 return token;
263 trace_spec.ops [(*last)-1].exclude = 1;
264 return TOKEN_SEPARATOR;
266 if (token == TOKEN_END || token == TOKEN_SEPARATOR || token == TOKEN_ERROR)
267 return token;
269 if (token == TOKEN_METHOD){
270 MonoMethodDesc *desc = mono_method_desc_new (value, TRUE);
271 if (desc == NULL){
272 fprintf (stderr, "Invalid method name: %s\n", value);
273 return TOKEN_ERROR;
275 trace_spec.ops [*last].op = MONO_TRACEOP_METHOD;
276 trace_spec.ops [*last].data = desc;
277 } else if (token == TOKEN_ALL)
278 trace_spec.ops [*last].op = MONO_TRACEOP_ALL;
279 else if (token == TOKEN_PROGRAM)
280 trace_spec.ops [*last].op = MONO_TRACEOP_PROGRAM;
281 else if (token == TOKEN_WRAPPER)
282 trace_spec.ops [*last].op = MONO_TRACEOP_WRAPPER;
283 else if (token == TOKEN_NAMESPACE){
284 trace_spec.ops [*last].op = MONO_TRACEOP_NAMESPACE;
285 trace_spec.ops [*last].data = g_strdup (value);
286 } else if (token == TOKEN_CLASS || token == TOKEN_EXCEPTION){
287 char *p = strrchr (value, '.');
288 if (p) {
289 *p++ = 0;
290 trace_spec.ops [*last].data = g_strdup (value);
291 trace_spec.ops [*last].data2 = g_strdup (p);
293 else {
294 trace_spec.ops [*last].data = g_strdup ("");
295 trace_spec.ops [*last].data2 = g_strdup (value);
297 trace_spec.ops [*last].op = token == TOKEN_CLASS ? MONO_TRACEOP_CLASS : MONO_TRACEOP_EXCEPTION;
298 } else if (token == TOKEN_STRING){
299 trace_spec.ops [*last].op = MONO_TRACEOP_ASSEMBLY;
300 trace_spec.ops [*last].data = g_strdup (value);
301 } else if (token == TOKEN_DISABLED) {
302 trace_spec.enabled = FALSE;
303 } else {
304 fprintf (stderr, "Syntax error in trace option specification\n");
305 return TOKEN_ERROR;
307 (*last)++;
308 return TOKEN_SEPARATOR;
311 MonoTraceSpec *
312 mono_trace_parse_options (const char *options)
314 char *p = (char*)options;
315 int size = 1;
316 int last_used;
317 int token;
319 trace_spec.enabled = TRUE;
320 if (*p == 0){
321 trace_spec.len = 1;
322 trace_spec.ops = g_new0 (MonoTraceOperation, 1);
323 trace_spec.ops [0].op = MONO_TRACEOP_ALL;
324 return &trace_spec;
327 for (p = (char*)options; *p != 0; p++)
328 if (*p == ',')
329 size++;
331 trace_spec.ops = g_new0 (MonoTraceOperation, size);
333 input = (char*)options;
334 last_used = 0;
336 while ((token = (get_spec (&last_used))) != TOKEN_END){
337 if (token == TOKEN_ERROR)
338 return NULL;
339 if (token == TOKEN_SEPARATOR)
340 continue;
342 trace_spec.len = last_used;
343 cleanup ();
344 return &trace_spec;
347 void
348 mono_trace_set_assembly (MonoAssembly *assembly)
350 trace_spec.assembly = assembly;
353 static
354 #ifdef HAVE_KW_THREAD
355 __thread
356 #endif
357 int indent_level = 0;
358 static guint64 start_time = 0;
360 static double seconds_since_start (void)
362 guint64 diff = mono_100ns_ticks () - start_time;
363 return diff/10000000.0;
366 static void indent (int diff) {
367 if (diff < 0)
368 indent_level += diff;
369 if (start_time == 0)
370 start_time = mono_100ns_ticks ();
371 printf ("[%p: %.5f %d] ", (void*)mono_native_thread_id_get (), seconds_since_start (), indent_level);
372 if (diff > 0)
373 indent_level += diff;
376 static char *
377 string_to_utf8 (MonoString *s)
379 char *as;
380 GError *error = NULL;
382 g_assert (s);
384 if (!s->length)
385 return g_strdup ("");
387 as = g_utf16_to_utf8 (mono_string_chars (s), s->length, NULL, NULL, &error);
388 if (error) {
389 /* Happens with StringBuilders */
390 g_error_free (error);
391 return g_strdup ("<INVALID UTF8>");
393 else
394 return as;
398 * cpos (ebp + arg_info[n].offset) points to the beginning of the
399 * stack slot for this argument. On little-endian systems, we can
400 * simply dereference it. On big-endian systems, we need to adjust
401 * cpos upward first if the datatype we're referencing is smaller than
402 * a stack slot. Also - one can't assume that gpointer is also the
403 * size of a stack slot - use SIZEOF_REGISTER instead. The following
404 * helper macro tries to keep down the mess of all the pointer
405 * calculations.
407 #if (G_BYTE_ORDER == G_LITTLE_ENDIAN)
408 #define arg_in_stack_slot(cpos, type) ((type *)(cpos))
409 #else
410 #define arg_in_stack_slot(cpos, type) ((type *)((sizeof(type) < SIZEOF_REGISTER) ? (((gssize)(cpos)) + SIZEOF_REGISTER - sizeof(type)) : (gssize)(cpos)))
411 #endif
413 void
414 mono_trace_enter_method (MonoMethod *method, char *ebp)
416 int i, j;
417 MonoClass *klass;
418 MonoObject *o;
419 MonoJitArgumentInfo *arg_info;
420 MonoMethodSignature *sig;
421 char *fname;
422 MonoGenericSharingContext *gsctx = NULL;
424 if (!trace_spec.enabled)
425 return;
427 while (output_lock != 0 || InterlockedCompareExchange (&output_lock, 1, 0) != 0)
428 mono_thread_info_yield ();
430 fname = mono_method_full_name (method, TRUE);
431 indent (1);
432 printf ("ENTER: %s(", fname);
433 g_free (fname);
435 if (!ebp) {
436 printf (") ip: %p\n", RETURN_ADDRESS_N (1));
437 goto unlock;
440 sig = mono_method_signature (method);
442 arg_info = (MonoJitArgumentInfo *)alloca (sizeof (MonoJitArgumentInfo) * (sig->param_count + 1));
444 if (method->is_inflated) {
445 /* FIXME: Might be better to pass the ji itself */
446 MonoJitInfo *ji = mini_jit_info_table_find (mono_domain_get (), (char *)RETURN_ADDRESS (), NULL);
447 if (ji) {
448 gsctx = mono_jit_info_get_generic_sharing_context (ji);
449 if (gsctx && gsctx->is_gsharedvt) {
450 /* Needs a ctx to get precise method */
451 printf (") <gsharedvt>\n");
452 goto unlock;
457 mono_arch_get_argument_info (sig, sig->param_count, arg_info);
459 if (MONO_TYPE_ISSTRUCT (mono_method_signature (method)->ret)) {
460 g_assert (!mono_method_signature (method)->ret->byref);
462 printf ("VALUERET:%p, ", *((gpointer *)(ebp + 8)));
465 if (mono_method_signature (method)->hasthis) {
466 gpointer *this_obj = (gpointer *)(ebp + arg_info [0].offset);
467 if (method->klass->valuetype) {
468 printf ("value:%p, ", *arg_in_stack_slot(this_obj, gpointer *));
469 } else {
470 o = *arg_in_stack_slot(this_obj, MonoObject *);
472 if (o) {
473 klass = o->vtable->klass;
475 if (klass == mono_defaults.string_class) {
476 MonoString *s = (MonoString*)o;
477 char *as = string_to_utf8 (s);
479 printf ("this:[STRING:%p:%s], ", o, as);
480 g_free (as);
481 } else {
482 printf ("this:%p[%s.%s %s], ", o, klass->name_space, klass->name, o->vtable->domain->friendly_name);
484 } else
485 printf ("this:NULL, ");
489 for (i = 0; i < mono_method_signature (method)->param_count; ++i) {
490 gpointer *cpos = (gpointer *)(ebp + arg_info [i + 1].offset);
491 int size = arg_info [i + 1].size;
493 MonoType *type = mono_method_signature (method)->params [i];
495 if (type->byref) {
496 printf ("[BYREF:%p], ", *arg_in_stack_slot(cpos, gpointer *));
497 } else switch (mini_get_underlying_type (type)->type) {
499 case MONO_TYPE_I:
500 case MONO_TYPE_U:
501 printf ("%p, ", *arg_in_stack_slot(cpos, gpointer *));
502 break;
503 case MONO_TYPE_BOOLEAN:
504 case MONO_TYPE_CHAR:
505 case MONO_TYPE_I1:
506 case MONO_TYPE_U1:
507 printf ("%d, ", *arg_in_stack_slot(cpos, gint8));
508 break;
509 case MONO_TYPE_I2:
510 case MONO_TYPE_U2:
511 printf ("%d, ", *arg_in_stack_slot(cpos, gint16));
512 break;
513 case MONO_TYPE_I4:
514 case MONO_TYPE_U4:
515 printf ("%d, ", *arg_in_stack_slot(cpos, int));
516 break;
517 case MONO_TYPE_STRING: {
518 MonoString *s = *arg_in_stack_slot(cpos, MonoString *);
519 if (s) {
520 char *as;
522 g_assert (((MonoObject *)s)->vtable->klass == mono_defaults.string_class);
523 as = string_to_utf8 (s);
525 printf ("[STRING:%p:%s], ", s, as);
526 g_free (as);
527 } else
528 printf ("[STRING:null], ");
529 break;
531 case MONO_TYPE_CLASS:
532 case MONO_TYPE_OBJECT: {
533 o = *arg_in_stack_slot(cpos, MonoObject *);
534 if (o) {
535 klass = o->vtable->klass;
537 if (klass == mono_defaults.string_class) {
538 char *as = string_to_utf8 ((MonoString*)o);
540 printf ("[STRING:%p:%s], ", o, as);
541 g_free (as);
542 } else if (klass == mono_defaults.int32_class) {
543 printf ("[INT32:%p:%d], ", o, *(gint32 *)((char *)o + sizeof (MonoObject)));
544 } else if (klass == mono_defaults.runtimetype_class) {
545 printf ("[TYPE:%s], ", mono_type_full_name (((MonoReflectionType*)o)->type));
546 } else
547 printf ("[%s.%s:%p], ", klass->name_space, klass->name, o);
548 } else {
549 printf ("%p, ", *arg_in_stack_slot(cpos, gpointer));
551 break;
553 case MONO_TYPE_PTR:
554 case MONO_TYPE_FNPTR:
555 case MONO_TYPE_ARRAY:
556 case MONO_TYPE_SZARRAY:
557 printf ("%p, ", *arg_in_stack_slot(cpos, gpointer));
558 break;
559 case MONO_TYPE_I8:
560 case MONO_TYPE_U8:
561 printf ("0x%016llx, ", (long long)*arg_in_stack_slot(cpos, gint64));
562 break;
563 case MONO_TYPE_R4:
564 printf ("%f, ", *arg_in_stack_slot(cpos, float));
565 break;
566 case MONO_TYPE_R8:
567 printf ("%f, ", *arg_in_stack_slot(cpos, double));
568 break;
569 case MONO_TYPE_VALUETYPE:
570 printf ("[");
571 for (j = 0; j < size; j++)
572 printf ("%02x,", *((guint8*)cpos +j));
573 printf ("], ");
574 break;
575 default:
576 printf ("XX, ");
580 printf (")\n");
581 fflush (stdout);
583 unlock:
584 mono_atomic_store_release (&output_lock, 0);
587 void
588 mono_trace_leave_method (MonoMethod *method, ...)
590 MonoType *type;
591 char *fname;
592 va_list ap;
593 MonoGenericSharingContext *gsctx;
595 if (!trace_spec.enabled)
596 return;
598 while (output_lock != 0 || InterlockedCompareExchange (&output_lock, 1, 0) != 0)
599 mono_thread_info_yield ();
601 va_start(ap, method);
603 fname = mono_method_full_name (method, TRUE);
604 indent (-1);
605 printf ("LEAVE: %s", fname);
606 g_free (fname);
608 if (method->is_inflated) {
609 /* FIXME: Might be better to pass the ji itself */
610 MonoJitInfo *ji = mini_jit_info_table_find (mono_domain_get (), (char *)RETURN_ADDRESS (), NULL);
611 if (ji) {
612 gsctx = mono_jit_info_get_generic_sharing_context (ji);
613 if (gsctx && gsctx->is_gsharedvt) {
614 /* Needs a ctx to get precise method */
615 printf (") <gsharedvt>\n");
616 goto unlock;
621 type = mini_get_underlying_type (mono_method_signature (method)->ret);
623 switch (type->type) {
624 case MONO_TYPE_VOID:
625 break;
626 case MONO_TYPE_BOOLEAN: {
627 int eax = va_arg (ap, int);
628 if (eax)
629 printf ("TRUE:%d", eax);
630 else
631 printf ("FALSE");
633 break;
635 case MONO_TYPE_CHAR:
636 case MONO_TYPE_I1:
637 case MONO_TYPE_U1:
638 case MONO_TYPE_I2:
639 case MONO_TYPE_U2:
640 case MONO_TYPE_I4:
641 case MONO_TYPE_U4:
642 case MONO_TYPE_I:
643 case MONO_TYPE_U: {
644 int eax = va_arg (ap, int);
645 printf ("result=%d", eax);
646 break;
648 case MONO_TYPE_STRING: {
649 MonoString *s = va_arg (ap, MonoString *);
651 if (s) {
652 char *as;
654 g_assert (((MonoObject *)s)->vtable->klass == mono_defaults.string_class);
655 as = string_to_utf8 (s);
656 printf ("[STRING:%p:%s]", s, as);
657 g_free (as);
658 } else
659 printf ("[STRING:null], ");
660 break;
662 case MONO_TYPE_CLASS:
663 case MONO_TYPE_OBJECT: {
664 MonoObject *o = va_arg (ap, MonoObject *);
666 if (o) {
667 if (o->vtable->klass == mono_defaults.boolean_class) {
668 printf ("[BOOLEAN:%p:%d]", o, *((guint8 *)o + sizeof (MonoObject)));
669 } else if (o->vtable->klass == mono_defaults.int32_class) {
670 printf ("[INT32:%p:%d]", o, *((gint32 *)((char *)o + sizeof (MonoObject))));
671 } else if (o->vtable->klass == mono_defaults.int64_class) {
672 printf ("[INT64:%p:%lld]", o, (long long)*((gint64 *)((char *)o + sizeof (MonoObject))));
673 } else
674 printf ("[%s.%s:%p]", o->vtable->klass->name_space, o->vtable->klass->name, o);
675 } else
676 printf ("[OBJECT:%p]", o);
678 break;
680 case MONO_TYPE_PTR:
681 case MONO_TYPE_FNPTR:
682 case MONO_TYPE_ARRAY:
683 case MONO_TYPE_SZARRAY: {
684 gpointer p = va_arg (ap, gpointer);
685 printf ("result=%p", p);
686 break;
688 case MONO_TYPE_I8: {
689 gint64 l = va_arg (ap, gint64);
690 printf ("lresult=0x%16llx", (long long)l);
691 break;
693 case MONO_TYPE_U8: {
694 gint64 l = va_arg (ap, gint64);
695 printf ("lresult=0x%16llx", (long long)l);
696 break;
698 case MONO_TYPE_R4:
699 case MONO_TYPE_R8: {
700 double f = va_arg (ap, double);
701 printf ("FP=%f", f);
702 break;
704 case MONO_TYPE_VALUETYPE: {
705 guint8 *p = (guint8 *)va_arg (ap, gpointer);
706 int j, size, align;
707 size = mono_type_size (type, &align);
708 printf ("[");
709 for (j = 0; p && j < size; j++)
710 printf ("%02x,", p [j]);
711 printf ("]");
712 break;
714 default:
715 printf ("(unknown return type %x)", mono_method_signature (method)->ret->type);
718 //printf (" ip: %p\n", RETURN_ADDRESS_N (1));
719 printf ("\n");
720 fflush (stdout);
722 unlock:
723 mono_atomic_store_release (&output_lock, 0);
726 void
727 mono_trace_enable (gboolean enable)
729 trace_spec.enabled = enable;
732 gboolean
733 mono_trace_is_enabled ()
735 return trace_spec.enabled;