mono/mini/trace.c

   1 /**
   2  * \file
   3  * Tracing facilities for the Mono Runtime.
   4  *
   5  * Author:
   6  *   Paolo Molaro (lupus@ximian.com)
   7  *   Dietmar Maurer (dietmar@ximian.com)
   8  *
   9  * (C) 2002 Ximian, Inc.
  10  * Copyright 2011 Xamarin, Inc (http://www.xamarin.com)
  11  * Licensed under the MIT license. See LICENSE file in the project root for full license information.
  12  */
  13
  14 #include <config.h>
  15 #ifdef HAVE_ALLOCA_H
  16 #include <alloca.h>
  17 #endif
  18 #ifdef HAVE_UNISTD_H
  19 #include <unistd.h>
  20 #endif
  21 #include <string.h>
  22 #include "mini.h"
  23 #include <mono/metadata/debug-helpers.h>
  24 #include <mono/utils/mono-time.h>
  25 #include <mono/utils/mono-memory-model.h>
  26 #include "trace.h"
  27 #include <mono/metadata/callspec.h>
  28
  29 #if defined (HOST_ANDROID) || (defined (TARGET_IOS) && defined (TARGET_IOS))
  30 #  undef printf
  31 #  define printf(...) g_log("mono", G_LOG_LEVEL_MESSAGE, __VA_ARGS__)
  32 #  undef fprintf
  33 #  define fprintf(__ignore, ...) g_log ("mono-gc", G_LOG_LEVEL_MESSAGE, __VA_ARGS__)
  34 #endif
  35
  36 static MonoCallSpec trace_spec;
  37
  38 static volatile gint32 output_lock = 0;
  39
  40 gboolean mono_trace_eval_exception (MonoClass *klass)
  41 {
  42         return mono_callspec_eval_exception (klass, &trace_spec);
  43 }
  44
  45 gboolean mono_trace_eval (MonoMethod *method)
  46 {
  47         return mono_callspec_eval (method, &trace_spec);
  48 }
  49
  50 MonoCallSpec *mono_trace_set_options (const char *options)
  51 {
  52         char *errstr;
  53         if (!mono_callspec_parse (options, &trace_spec, &errstr)) {
  54                 fprintf (stderr, "%s\n", errstr);
  55                 g_free (errstr);
  56                 return NULL;
  57         }
  58
  59         return &trace_spec;
  60 }
  61
  62 static
  63 #ifdef HAVE_KW_THREAD
  64 __thread
  65 #endif
  66 int indent_level = 0;
  67 static guint64 start_time = 0;
  68
  69 static double seconds_since_start (void)
  70 {
  71         guint64 diff = mono_100ns_ticks () - start_time;
  72         return diff/10000000.0;
  73 }
  74
  75 static void indent (int diff) {
  76         if (diff < 0)
  77                 indent_level += diff;
  78         if (start_time == 0)
  79                 start_time = mono_100ns_ticks ();
  80         printf ("[%p: %.5f %d] ", (void*)mono_native_thread_id_get (), seconds_since_start (), indent_level);
  81         if (diff > 0)
  82                 indent_level += diff;
  83 }
  84
  85 static char *
  86 string_to_utf8 (MonoString *s)
  87 {
  88         char *as;
  89         GError *error = NULL;
  90
  91         g_assert (s);
  92
  93         if (!s->length)
  94                 return g_strdup ("");
  95
  96         as = g_utf16_to_utf8 (mono_string_chars (s), s->length, NULL, NULL, &error);
  97         if (error) {
  98                 /* Happens with StringBuilders */
  99                 g_error_free (error);
 100                 return g_strdup ("<INVALID UTF8>");
 101         }
 102         else
 103                 return as;
 104 }
 105
 106 /*
 107  * cpos (ebp + arg_info[n].offset) points to the beginning of the
 108  * stack slot for this argument.  On little-endian systems, we can
 109  * simply dereference it. On big-endian systems, we need to adjust
 110  * cpos upward first if the datatype we're referencing is smaller than
 111  * a stack slot. Also - one can't assume that gpointer is also the
 112  * size of a stack slot - use SIZEOF_REGISTER instead. The following
 113  * helper macro tries to keep down the mess of all the pointer
 114  * calculations.
 115  */
 116 #if (G_BYTE_ORDER == G_LITTLE_ENDIAN)
 117 #define arg_in_stack_slot(cpos, type) ((type *)(cpos))
 118 #else
 119 #define arg_in_stack_slot(cpos, type) ((type *)((sizeof(type) < SIZEOF_REGISTER) ? (((gssize)(cpos)) + SIZEOF_REGISTER - sizeof(type)) : (gssize)(cpos)))
 120 #endif
 121
 122 void
 123 mono_trace_enter_method (MonoMethod *method, char *ebp)
 124 {
 125         int i, j;
 126         MonoClass *klass;
 127         MonoObject *o;
 128         MonoJitArgumentInfo *arg_info;
 129         MonoMethodSignature *sig;
 130         char *fname;
 131         MonoGenericSharingContext *gsctx = NULL;
 132
 133         if (!trace_spec.enabled)
 134                 return;
 135
 136         while (output_lock != 0 || InterlockedCompareExchange (&output_lock, 1, 0) != 0)
 137                 mono_thread_info_yield ();
 138
 139         fname = mono_method_full_name (method, TRUE);
 140         indent (1);
 141         printf ("ENTER: %s(", fname);
 142         g_free (fname);
 143
 144         if (!ebp) {
 145                 printf (") ip: %p\n", MONO_RETURN_ADDRESS_N (1));
 146                 goto unlock;
 147         }
 148
 149         sig = mono_method_signature (method);
 150
 151         arg_info = (MonoJitArgumentInfo *)alloca (sizeof (MonoJitArgumentInfo) * (sig->param_count + 1));
 152
 153         if (method->is_inflated) {
 154                 /* FIXME: Might be better to pass the ji itself */
 155                 MonoJitInfo *ji = mini_jit_info_table_find (mono_domain_get (), (char *)MONO_RETURN_ADDRESS (), NULL);
 156                 if (ji) {
 157                         gsctx = mono_jit_info_get_generic_sharing_context (ji);
 158                         if (gsctx && gsctx->is_gsharedvt) {
 159                                 /* Needs a ctx to get precise method */
 160                                 printf (") <gsharedvt>\n");
 161                                 goto unlock;
 162                         }
 163                 }
 164         }
 165
 166         mono_arch_get_argument_info (sig, sig->param_count, arg_info);
 167
 168         if (MONO_TYPE_ISSTRUCT (mono_method_signature (method)->ret)) {
 169                 g_assert (!mono_method_signature (method)->ret->byref);
 170
 171                 printf ("VALUERET:%p, ", *((gpointer *)(ebp + 8)));
 172         }
 173
 174         if (mono_method_signature (method)->hasthis) {
 175                 gpointer *this_obj = (gpointer *)(ebp + arg_info [0].offset);
 176                 if (method->klass->valuetype) {
 177                         printf ("value:%p, ", *arg_in_stack_slot(this_obj, gpointer *));
 178                 } else {
 179                         o = *arg_in_stack_slot(this_obj, MonoObject *);
 180
 181                         if (o) {
 182                                 klass = o->vtable->klass;
 183
 184                                 if (klass == mono_defaults.string_class) {
 185                                         MonoString *s = (MonoString*)o;
 186                                         char *as = string_to_utf8 (s);
 187
 188                                         printf ("this:[STRING:%p:%s], ", o, as);
 189                                         g_free (as);
 190                                 } else {
 191                                         printf ("this:%p[%s.%s %s], ", o, klass->name_space, klass->name, o->vtable->domain->friendly_name);
 192                                 }
 193                         } else
 194                                 printf ("this:NULL, ");
 195                 }
 196         }
 197
 198         for (i = 0; i < mono_method_signature (method)->param_count; ++i) {
 199                 gpointer *cpos = (gpointer *)(ebp + arg_info [i + 1].offset);
 200                 int size = arg_info [i + 1].size;
 201
 202                 MonoType *type = mono_method_signature (method)->params [i];
 203
 204                 if (type->byref) {
 205                         printf ("[BYREF:%p], ", *arg_in_stack_slot(cpos, gpointer *));
 206                 } else switch (mini_get_underlying_type (type)->type) {
 207
 208                 case MONO_TYPE_I:
 209                 case MONO_TYPE_U:
 210                         printf ("%p, ", *arg_in_stack_slot(cpos, gpointer *));
 211                         break;
 212                 case MONO_TYPE_BOOLEAN:
 213                 case MONO_TYPE_CHAR:
 214                 case MONO_TYPE_I1:
 215                 case MONO_TYPE_U1:
 216                         printf ("%d, ", *arg_in_stack_slot(cpos, gint8));
 217                         break;
 218                 case MONO_TYPE_I2:
 219                 case MONO_TYPE_U2:
 220                         printf ("%d, ", *arg_in_stack_slot(cpos, gint16));
 221                         break;
 222                 case MONO_TYPE_I4:
 223                 case MONO_TYPE_U4:
 224                         printf ("%d, ", *arg_in_stack_slot(cpos, int));
 225                         break;
 226                 case MONO_TYPE_STRING: {
 227                         MonoString *s = *arg_in_stack_slot(cpos, MonoString *);
 228                         if (s) {
 229                                 char *as;
 230
 231                                 g_assert (((MonoObject *)s)->vtable->klass == mono_defaults.string_class);
 232                                 as = string_to_utf8 (s);
 233
 234                                 printf ("[STRING:%p:%s], ", s, as);
 235                                 g_free (as);
 236                         } else
 237                                 printf ("[STRING:null], ");
 238                         break;
 239                 }
 240                 case MONO_TYPE_CLASS:
 241                 case MONO_TYPE_OBJECT: {
 242                         o = *arg_in_stack_slot(cpos, MonoObject *);
 243                         if (o) {
 244                                 klass = o->vtable->klass;
 245
 246                                 if (klass == mono_defaults.string_class) {
 247                                         char *as = string_to_utf8 ((MonoString*)o);
 248
 249                                         printf ("[STRING:%p:%s], ", o, as);
 250                                         g_free (as);
 251                                 } else if (klass == mono_defaults.int32_class) {
 252                                         printf ("[INT32:%p:%d], ", o, *(gint32 *)((char *)o + sizeof (MonoObject)));
 253                                 } else if (klass == mono_defaults.runtimetype_class) {
 254                                         printf ("[TYPE:%s], ", mono_type_full_name (((MonoReflectionType*)o)->type));
 255                                 } else
 256                                         printf ("[%s.%s:%p], ", klass->name_space, klass->name, o);
 257                         } else {
 258                                 printf ("%p, ", *arg_in_stack_slot(cpos, gpointer));
 259                         }
 260                         break;
 261                 }
 262                 case MONO_TYPE_PTR:
 263                 case MONO_TYPE_FNPTR:
 264                 case MONO_TYPE_ARRAY:
 265                 case MONO_TYPE_SZARRAY:
 266                         printf ("%p, ", *arg_in_stack_slot(cpos, gpointer));
 267                         break;
 268                 case MONO_TYPE_I8:
 269                 case MONO_TYPE_U8:
 270                         printf ("0x%016llx, ", (long long)*arg_in_stack_slot(cpos, gint64));
 271                         break;
 272                 case MONO_TYPE_R4:
 273                         printf ("%f, ", *arg_in_stack_slot(cpos, float));
 274                         break;
 275                 case MONO_TYPE_R8:
 276                         printf ("%f, ", *arg_in_stack_slot(cpos, double));
 277                         break;
 278                 case MONO_TYPE_VALUETYPE:
 279                         printf ("[");
 280                         for (j = 0; j < size; j++)
 281                                 printf ("%02x,", *((guint8*)cpos +j));
 282                         printf ("], ");
 283                         break;
 284                 default:
 285                         printf ("XX, ");
 286                 }
 287         }
 288
 289         printf (")\n");
 290         fflush (stdout);
 291
 292 unlock:
 293         mono_atomic_store_release (&output_lock, 0);
 294 }
 295
 296 void
 297 mono_trace_leave_method (MonoMethod *method, ...)
 298 {
 299         MonoType *type;
 300         char *fname;
 301         va_list ap;
 302         MonoGenericSharingContext *gsctx;
 303
 304         if (!trace_spec.enabled)
 305                 return;
 306
 307         while (output_lock != 0 || InterlockedCompareExchange (&output_lock, 1, 0) != 0)
 308                 mono_thread_info_yield ();
 309
 310         va_start(ap, method);
 311
 312         fname = mono_method_full_name (method, TRUE);
 313         indent (-1);
 314         printf ("LEAVE: %s", fname);
 315         g_free (fname);
 316
 317         if (method->is_inflated) {
 318                 /* FIXME: Might be better to pass the ji itself */
 319                 MonoJitInfo *ji = mini_jit_info_table_find (mono_domain_get (), (char *)MONO_RETURN_ADDRESS (), NULL);
 320                 if (ji) {
 321                         gsctx = mono_jit_info_get_generic_sharing_context (ji);
 322                         if (gsctx && gsctx->is_gsharedvt) {
 323                                 /* Needs a ctx to get precise method */
 324                                 printf (") <gsharedvt>\n");
 325                                 goto unlock;
 326                         }
 327                 }
 328         }
 329
 330         type = mini_get_underlying_type (mono_method_signature (method)->ret);
 331
 332         switch (type->type) {
 333         case MONO_TYPE_VOID:
 334                 break;
 335         case MONO_TYPE_BOOLEAN: {
 336                 int eax = va_arg (ap, int);
 337                 if (eax)
 338                         printf ("TRUE:%d", eax);
 339                 else
 340                         printf ("FALSE");
 341
 342                 break;
 343         }
 344         case MONO_TYPE_CHAR:
 345         case MONO_TYPE_I1:
 346         case MONO_TYPE_U1:
 347         case MONO_TYPE_I2:
 348         case MONO_TYPE_U2:
 349         case MONO_TYPE_I4:
 350         case MONO_TYPE_U4:
 351         case MONO_TYPE_I:
 352         case MONO_TYPE_U: {
 353                 int eax = va_arg (ap, int);
 354                 printf ("result=%d", eax);
 355                 break;
 356         }
 357         case MONO_TYPE_STRING: {
 358                 MonoString *s = va_arg (ap, MonoString *);
 359 ;
 360                 if (s) {
 361                         char *as;
 362
 363                         g_assert (((MonoObject *)s)->vtable->klass == mono_defaults.string_class);
 364                         as = string_to_utf8 (s);
 365                         printf ("[STRING:%p:%s]", s, as);
 366                         g_free (as);
 367                 } else
 368                         printf ("[STRING:null], ");
 369                 break;
 370         }
 371         case MONO_TYPE_CLASS:
 372         case MONO_TYPE_OBJECT: {
 373                 MonoObject *o = va_arg (ap, MonoObject *);
 374
 375                 if (o) {
 376                         if (o->vtable->klass == mono_defaults.boolean_class) {
 377                                 printf ("[BOOLEAN:%p:%d]", o, *((guint8 *)o + sizeof (MonoObject)));
 378                         } else if  (o->vtable->klass == mono_defaults.int32_class) {
 379                                 printf ("[INT32:%p:%d]", o, *((gint32 *)((char *)o + sizeof (MonoObject))));
 380                         } else if  (o->vtable->klass == mono_defaults.int64_class) {
 381                                 printf ("[INT64:%p:%lld]", o, (long long)*((gint64 *)((char *)o + sizeof (MonoObject))));
 382                         } else
 383                                 printf ("[%s.%s:%p]", o->vtable->klass->name_space, o->vtable->klass->name, o);
 384                 } else
 385                         printf ("[OBJECT:%p]", o);
 386
 387                 break;
 388         }
 389         case MONO_TYPE_PTR:
 390         case MONO_TYPE_FNPTR:
 391         case MONO_TYPE_ARRAY:
 392         case MONO_TYPE_SZARRAY: {
 393                 gpointer p = va_arg (ap, gpointer);
 394                 printf ("result=%p", p);
 395                 break;
 396         }
 397         case MONO_TYPE_I8: {
 398                 gint64 l =  va_arg (ap, gint64);
 399                 printf ("lresult=0x%16llx", (long long)l);
 400                 break;
 401         }
 402         case MONO_TYPE_U8: {
 403                 gint64 l =  va_arg (ap, gint64);
 404                 printf ("lresult=0x%16llx", (long long)l);
 405                 break;
 406         }
 407         case MONO_TYPE_R4:
 408         case MONO_TYPE_R8: {
 409                 double f = va_arg (ap, double);
 410                 printf ("FP=%f", f);
 411                 break;
 412         }
 413         case MONO_TYPE_VALUETYPE:  {
 414                 guint8 *p = (guint8 *)va_arg (ap, gpointer);
 415                 int j, size, align;
 416                 size = mono_type_size (type, &align);
 417                 printf ("[");
 418                 for (j = 0; p && j < size; j++)
 419                         printf ("%02x,", p [j]);
 420                 printf ("]");
 421                 break;
 422         }
 423         default:
 424                 printf ("(unknown return type %x)", mono_method_signature (method)->ret->type);
 425         }
 426
 427         //printf (" ip: %p\n", MONO_RETURN_ADDRESS_N (1));
 428         printf ("\n");
 429         fflush (stdout);
 430
 431 unlock:
 432         mono_atomic_store_release (&output_lock, 0);
 433 }
 434
 435 void
 436 mono_trace_enable (gboolean enable)
 437 {
 438         trace_spec.enabled = enable;
 439 }
 440
 441 gboolean
 442 mono_trace_is_enabled ()
 443 {
 444         return trace_spec.enabled;
 445 }