mono/mini/trace.c

   1 /*
   2  * trace.c: Tracing facilities for the Mono Runtime.
   3  *
   4  * Author:
   5  *   Paolo Molaro (lupus@ximian.com)
   6  *   Dietmar Maurer (dietmar@ximian.com)
   7  *
   8  * (C) 2002 Ximian, Inc.
   9  * Copyright 2011 Xamarin, Inc (http://www.xamarin.com)
  10  */
  11
  12 #include <config.h>
  13 #include <signal.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 "trace.h"
  26
  27 static MonoTraceSpec trace_spec;
  28
  29 gboolean
  30 mono_trace_eval_exception (MonoClass *klass)
  31 {
  32         int include = 0;
  33         int i;
  34
  35         if (!klass)
  36                 return FALSE;
  37
  38         for (i = 0; i < trace_spec.len; i++) {
  39                 MonoTraceOperation *op = &trace_spec.ops [i];
  40                 int inc = 0;
  41
  42                 switch (op->op){
  43                 case MONO_TRACEOP_EXCEPTION:
  44                         if (strcmp ("", op->data) == 0 && strcmp ("all", op->data2) == 0)
  45                                 inc = 1;
  46                         else if (strcmp ("", op->data) == 0 || strcmp (klass->name_space, op->data) == 0)
  47                                 if (strcmp (klass->name, op->data2) == 0)
  48                                         inc = 1;
  49                         break;
  50                 default:
  51                         break;
  52                 }
  53                 if (op->exclude){
  54                         if (inc)
  55                                 include = 0;
  56                 } else if (inc)
  57                         include = 1;
  58         }
  59
  60         return include;
  61 }
  62
  63 gboolean
  64 mono_trace_eval (MonoMethod *method)
  65 {
  66         int include = 0;
  67         int i;
  68
  69         for (i = 0; i < trace_spec.len; i++){
  70                 MonoTraceOperation *op = &trace_spec.ops [i];
  71                 int inc = 0;
  72
  73                 switch (op->op){
  74                 case MONO_TRACEOP_ALL:
  75                         inc = 1; break;
  76                 case MONO_TRACEOP_PROGRAM:
  77                         if (trace_spec.assembly && (method->klass->image == mono_assembly_get_image (trace_spec.assembly)))
  78                                 inc = 1; break;
  79                 case MONO_TRACEOP_METHOD:
  80                         if (mono_method_desc_full_match ((MonoMethodDesc *) op->data, method))
  81                                 inc = 1; break;
  82                 case MONO_TRACEOP_CLASS:
  83                         if (strcmp (method->klass->name_space, op->data) == 0)
  84                                 if (strcmp (method->klass->name, op->data2) == 0)
  85                                         inc = 1;
  86                         break;
  87                 case MONO_TRACEOP_ASSEMBLY:
  88                         if (strcmp (mono_image_get_name (method->klass->image), op->data) == 0)
  89                                 inc = 1; break;
  90                 case MONO_TRACEOP_NAMESPACE:
  91                         if (strcmp (method->klass->name_space, op->data) == 0)
  92                                 inc = 1;
  93                 case MONO_TRACEOP_EXCEPTION:
  94                         break;
  95                 }
  96                 if (op->exclude){
  97                         if (inc)
  98                                 include = 0;
  99                 } else if (inc)
 100                         include = 1;
 101         }
 102         return include;
 103 }
 104
 105 static int is_filenamechar (char p)
 106 {
 107         if (p >= 'A' && p <= 'Z')
 108                 return TRUE;
 109         if (p >= 'a' && p <= 'z')
 110                 return TRUE;
 111         if (p >= '0' && p <= '9')
 112                 return TRUE;
 113         if (p == '.' || p == ':' || p == '_' || p == '-')
 114                 return TRUE;
 115         return FALSE;
 116 }
 117
 118 static char *input;
 119 static char *value;
 120
 121 static void get_string (void)
 122 {
 123         char *start = input;
 124         while (is_filenamechar (*input)){
 125                 input++;
 126         }
 127         if (value != NULL)
 128                 g_free (value);
 129         value = g_malloc (input - start + 1);
 130         strncpy (value, start, input-start);
 131         value [input-start] = 0;
 132 }
 133
 134 enum Token {
 135         TOKEN_METHOD,
 136         TOKEN_CLASS,
 137         TOKEN_ALL,
 138         TOKEN_PROGRAM,
 139         TOKEN_EXCEPTION,
 140         TOKEN_NAMESPACE,
 141         TOKEN_STRING,
 142         TOKEN_EXCLUDE,
 143         TOKEN_DISABLED,
 144         TOKEN_SEPARATOR,
 145         TOKEN_END,
 146         TOKEN_ERROR
 147 };
 148
 149 static int
 150 get_token (void)
 151 {
 152         while (input [0] == '+')
 153                 input++;
 154
 155         if (input [0] == '\0') {
 156                 return TOKEN_END;
 157         }
 158         if (input [0] == 'M' && input [1] == ':'){
 159                 input += 2;
 160                 get_string ();
 161                 return TOKEN_METHOD;
 162         }
 163         if (input [0] == 'N' && input [1] == ':'){
 164                 input += 2;
 165                 get_string ();
 166                 return TOKEN_NAMESPACE;
 167         }
 168         if (input [0] == 'T' && input [1] == ':'){
 169                 input += 2;
 170                 get_string ();
 171                 return TOKEN_CLASS;
 172         }
 173         if (input [0] == 'E' && input [1] == ':'){
 174                 input += 2;
 175                 get_string ();
 176                 return TOKEN_EXCEPTION;
 177         }
 178         if (*input == '-'){
 179                 input++;
 180                 return TOKEN_EXCLUDE;
 181         }
 182         if (is_filenamechar (*input)){
 183                 get_string ();
 184                 if (strcmp (value, "all") == 0)
 185                         return TOKEN_ALL;
 186                 if (strcmp (value, "program") == 0)
 187                         return TOKEN_PROGRAM;
 188                 if (strcmp (value, "disabled") == 0)
 189                         return TOKEN_DISABLED;
 190                 return TOKEN_STRING;
 191         }
 192         if (*input == ','){
 193                 input++;
 194                 return TOKEN_SEPARATOR;
 195         }
 196
 197         fprintf (stderr, "Syntax error at or around '%s'\n", input);
 198         return TOKEN_ERROR;
 199 }
 200
 201 static void
 202 cleanup (void)
 203 {
 204         if (value != NULL)
 205                 g_free (value);
 206 }
 207
 208 static int
 209 get_spec (int *last)
 210 {
 211         int token = get_token ();
 212         if (token == TOKEN_EXCLUDE){
 213                 token = get_spec (last);
 214                 if (token == TOKEN_EXCLUDE){
 215                         fprintf (stderr, "Expecting an expression");
 216                         return TOKEN_ERROR;
 217                 }
 218                 if (token == TOKEN_ERROR)
 219                         return token;
 220                 trace_spec.ops [(*last)-1].exclude = 1;
 221                 return TOKEN_SEPARATOR;
 222         }
 223         if (token == TOKEN_END || token == TOKEN_SEPARATOR || token == TOKEN_ERROR)
 224                 return token;
 225
 226         if (token == TOKEN_METHOD){
 227                 MonoMethodDesc *desc = mono_method_desc_new (value, TRUE);
 228                 if (desc == NULL){
 229                         fprintf (stderr, "Invalid method name: %s\n", value);
 230                         return TOKEN_ERROR;
 231                 }
 232                 trace_spec.ops [*last].op = MONO_TRACEOP_METHOD;
 233                 trace_spec.ops [*last].data = desc;
 234         } else if (token == TOKEN_ALL)
 235                 trace_spec.ops [*last].op = MONO_TRACEOP_ALL;
 236         else if (token == TOKEN_PROGRAM)
 237                 trace_spec.ops [*last].op = MONO_TRACEOP_PROGRAM;
 238         else if (token == TOKEN_NAMESPACE){
 239                 trace_spec.ops [*last].op = MONO_TRACEOP_NAMESPACE;
 240                 trace_spec.ops [*last].data = g_strdup (value);
 241         } else if (token == TOKEN_CLASS || token == TOKEN_EXCEPTION){
 242                 char *p = strrchr (value, '.');
 243                 if (p) {
 244                         *p++ = 0;
 245                         trace_spec.ops [*last].data = g_strdup (value);
 246                         trace_spec.ops [*last].data2 = g_strdup (p);
 247                 }
 248                 else {
 249                         trace_spec.ops [*last].data = g_strdup ("");
 250                         trace_spec.ops [*last].data2 = g_strdup (value);
 251                 }
 252                 trace_spec.ops [*last].op = token == TOKEN_CLASS ? MONO_TRACEOP_CLASS : MONO_TRACEOP_EXCEPTION;
 253         } else if (token == TOKEN_STRING){
 254                 trace_spec.ops [*last].op = MONO_TRACEOP_ASSEMBLY;
 255                 trace_spec.ops [*last].data = g_strdup (value);
 256         } else if (token == TOKEN_DISABLED) {
 257                 trace_spec.enabled = FALSE;
 258         } else {
 259                 fprintf (stderr, "Syntax error in trace option specification\n");
 260                 return TOKEN_ERROR;
 261         }
 262         (*last)++;
 263         return TOKEN_SEPARATOR;
 264 }
 265
 266 MonoTraceSpec *
 267 mono_trace_parse_options (const char *options)
 268 {
 269         char *p = (char*)options;
 270         int size = 1;
 271         int last_used;
 272         int token;
 273
 274         trace_spec.enabled = TRUE;
 275         if (*p == 0){
 276                 trace_spec.len = 1;
 277                 trace_spec.ops = g_new0 (MonoTraceOperation, 1);
 278                 trace_spec.ops [0].op = MONO_TRACEOP_ALL;
 279                 return &trace_spec;
 280         }
 281
 282         for (p = (char*)options; *p != 0; p++)
 283                 if (*p == ',')
 284                         size++;
 285
 286         trace_spec.ops = g_new0 (MonoTraceOperation, size);
 287
 288         input = (char*)options;
 289         last_used = 0;
 290
 291         while ((token = (get_spec (&last_used))) != TOKEN_END){
 292                 if (token == TOKEN_ERROR)
 293                         return NULL;
 294                 if (token == TOKEN_SEPARATOR)
 295                         continue;
 296         }
 297         trace_spec.len = last_used;
 298         cleanup ();
 299         return &trace_spec;
 300 }
 301
 302 void
 303 mono_trace_set_assembly (MonoAssembly *assembly)
 304 {
 305         trace_spec.assembly = assembly;
 306 }
 307
 308 static
 309 #ifdef HAVE_KW_THREAD
 310 __thread
 311 #endif
 312 int indent_level = 0;
 313 static guint64 start_time = 0;
 314
 315 static double seconds_since_start (void)
 316 {
 317         guint64 diff = mono_100ns_ticks () - start_time;
 318         return diff/10000000.0;
 319 }
 320
 321 static void indent (int diff) {
 322         if (diff < 0)
 323                 indent_level += diff;
 324         if (start_time == 0)
 325                 start_time = mono_100ns_ticks ();
 326         printf ("[%p: %.5f %d] ", (void*)GetCurrentThreadId (), seconds_since_start (), indent_level);
 327         if (diff > 0)
 328                 indent_level += diff;
 329 }
 330
 331 static char *
 332 string_to_utf8 (MonoString *s)
 333 {
 334         char *as;
 335         GError *error = NULL;
 336
 337         g_assert (s);
 338
 339         if (!s->length)
 340                 return g_strdup ("");
 341
 342         as = g_utf16_to_utf8 (mono_string_chars (s), s->length, NULL, NULL, &error);
 343         if (error) {
 344                 /* Happens with StringBuilders */
 345                 g_error_free (error);
 346                 return g_strdup ("<INVALID UTF8>");
 347         }
 348         else
 349                 return as;
 350 }
 351
 352 /*
 353  * cpos (ebp + arg_info[n].offset) points to the beginning of the
 354  * stack slot for this argument.  On little-endian systems, we can
 355  * simply dereference it. On big-endian systems, we need to adjust
 356  * cpos upward first if the datatype we're referencing is smaller than
 357  * a stack slot. Also - one can't assume that gpointer is also the
 358  * size of a stack slot - use SIZEOF_REGISTER instead. The following
 359  * helper macro tries to keep down the mess of all the pointer
 360  * calculations.
 361  */
 362 #if (G_BYTE_ORDER == G_LITTLE_ENDIAN)
 363 #define arg_in_stack_slot(cpos, type) ((type *)(cpos))
 364 #else
 365 #define arg_in_stack_slot(cpos, type) ((type *)((sizeof(type) < SIZEOF_REGISTER) ? (((gssize)(cpos)) + SIZEOF_REGISTER - sizeof(type)) : (gssize)(cpos)))
 366 #endif
 367
 368 void
 369 mono_trace_enter_method (MonoMethod *method, char *ebp)
 370 {
 371         int i, j;
 372         MonoClass *class;
 373         MonoObject *o;
 374         MonoJitArgumentInfo *arg_info;
 375         MonoMethodSignature *sig;
 376         char *fname;
 377
 378         if (!trace_spec.enabled)
 379                 return;
 380
 381         fname = mono_method_full_name (method, TRUE);
 382         indent (1);
 383         printf ("ENTER: %s(", fname);
 384         g_free (fname);
 385
 386         if (!ebp) {
 387                 printf (") ip: %p\n", __builtin_return_address (1));
 388                 return;
 389         }
 390
 391         sig = mono_method_signature (method);
 392
 393         arg_info = alloca (sizeof (MonoJitArgumentInfo) * (sig->param_count + 1));
 394
 395         mono_arch_get_argument_info (NULL, sig, sig->param_count, arg_info);
 396
 397         if (MONO_TYPE_ISSTRUCT (mono_method_signature (method)->ret)) {
 398                 g_assert (!mono_method_signature (method)->ret->byref);
 399
 400                 printf ("VALUERET:%p, ", *((gpointer *)(ebp + 8)));
 401         }
 402
 403         if (mono_method_signature (method)->hasthis) {
 404                 gpointer *this = (gpointer *)(ebp + arg_info [0].offset);
 405                 if (method->klass->valuetype) {
 406                         printf ("value:%p, ", *arg_in_stack_slot(this, gpointer *));
 407                 } else {
 408                         o = *arg_in_stack_slot(this, MonoObject *);
 409
 410                         if (o) {
 411                                 class = o->vtable->klass;
 412
 413                                 if (class == mono_defaults.string_class) {
 414                                         MonoString *s = (MonoString*)o;
 415                                         char *as = string_to_utf8 (s);
 416
 417                                         printf ("this:[STRING:%p:%s], ", o, as);
 418                                         g_free (as);
 419                                 } else {
 420                                         printf ("this:%p[%s.%s %s], ", o, class->name_space, class->name, o->vtable->domain->friendly_name);
 421                                 }
 422                         } else
 423                                 printf ("this:NULL, ");
 424                 }
 425         }
 426
 427         for (i = 0; i < mono_method_signature (method)->param_count; ++i) {
 428                 gpointer *cpos = (gpointer *)(ebp + arg_info [i + 1].offset);
 429                 int size = arg_info [i + 1].size;
 430
 431                 MonoType *type = mono_method_signature (method)->params [i];
 432
 433                 if (type->byref) {
 434                         printf ("[BYREF:%p], ", *arg_in_stack_slot(cpos, gpointer *));
 435                 } else switch (mono_type_get_underlying_type (type)->type) {
 436
 437                 case MONO_TYPE_I:
 438                 case MONO_TYPE_U:
 439                         printf ("%p, ", *arg_in_stack_slot(cpos, gpointer *));
 440                         break;
 441                 case MONO_TYPE_BOOLEAN:
 442                 case MONO_TYPE_CHAR:
 443                 case MONO_TYPE_I1:
 444                 case MONO_TYPE_U1:
 445                         printf ("%d, ", *arg_in_stack_slot(cpos, gint8));
 446                         break;
 447                 case MONO_TYPE_I2:
 448                 case MONO_TYPE_U2:
 449                         printf ("%d, ", *arg_in_stack_slot(cpos, gint16));
 450                         break;
 451                 case MONO_TYPE_I4:
 452                 case MONO_TYPE_U4:
 453                         printf ("%d, ", *arg_in_stack_slot(cpos, int));
 454                         break;
 455                 case MONO_TYPE_STRING: {
 456                         MonoString *s = *arg_in_stack_slot(cpos, MonoString *);
 457                         if (s) {
 458                                 char *as;
 459
 460                                 g_assert (((MonoObject *)s)->vtable->klass == mono_defaults.string_class);
 461                                 as = string_to_utf8 (s);
 462
 463                                 printf ("[STRING:%p:%s], ", s, as);
 464                                 g_free (as);
 465                         } else
 466                                 printf ("[STRING:null], ");
 467                         break;
 468                 }
 469                 case MONO_TYPE_CLASS:
 470                 case MONO_TYPE_OBJECT: {
 471                         o = *arg_in_stack_slot(cpos, MonoObject *);
 472                         if (o) {
 473                                 class = o->vtable->klass;
 474
 475                                 if (class == mono_defaults.string_class) {
 476                                         char *as = string_to_utf8 ((MonoString*)o);
 477
 478                                         printf ("[STRING:%p:%s], ", o, as);
 479                                         g_free (as);
 480                                 } else if (class == mono_defaults.int32_class) {
 481                                         printf ("[INT32:%p:%d], ", o, *(gint32 *)((char *)o + sizeof (MonoObject)));
 482                                 } else if (class == mono_defaults.monotype_class) {
 483                                         printf ("[TYPE:%s], ", mono_type_full_name (((MonoReflectionType*)o)->type));
 484                                 } else
 485                                         printf ("[%s.%s:%p], ", class->name_space, class->name, o);
 486                         } else {
 487                                 printf ("%p, ", *arg_in_stack_slot(cpos, gpointer));
 488                         }
 489                         break;
 490                 }
 491                 case MONO_TYPE_PTR:
 492                 case MONO_TYPE_FNPTR:
 493                 case MONO_TYPE_ARRAY:
 494                 case MONO_TYPE_SZARRAY:
 495                         printf ("%p, ", *arg_in_stack_slot(cpos, gpointer));
 496                         break;
 497                 case MONO_TYPE_I8:
 498                 case MONO_TYPE_U8:
 499                         printf ("0x%016llx, ", (long long)*arg_in_stack_slot(cpos, gint64));
 500                         break;
 501                 case MONO_TYPE_R4:
 502                         printf ("%f, ", *arg_in_stack_slot(cpos, float));
 503                         break;
 504                 case MONO_TYPE_R8:
 505                         printf ("%f, ", *arg_in_stack_slot(cpos, double));
 506                         break;
 507                 case MONO_TYPE_VALUETYPE:
 508                         printf ("[");
 509                         for (j = 0; j < size; j++)
 510                                 printf ("%02x,", *((guint8*)cpos +j));
 511                         printf ("], ");
 512                         break;
 513                 default:
 514                         printf ("XX, ");
 515                 }
 516         }
 517
 518         printf (")\n");
 519         fflush (stdout);
 520 }
 521
 522 void
 523 mono_trace_leave_method (MonoMethod *method, ...)
 524 {
 525         MonoType *type;
 526         char *fname;
 527         va_list ap;
 528
 529         if (!trace_spec.enabled)
 530                 return;
 531
 532         va_start(ap, method);
 533
 534         fname = mono_method_full_name (method, TRUE);
 535         indent (-1);
 536         printf ("LEAVE: %s", fname);
 537         g_free (fname);
 538
 539         type = mono_method_signature (method)->ret;
 540
 541 handle_enum:
 542         switch (type->type) {
 543         case MONO_TYPE_VOID:
 544                 break;
 545         case MONO_TYPE_BOOLEAN: {
 546                 int eax = va_arg (ap, int);
 547                 if (eax)
 548                         printf ("TRUE:%d", eax);
 549                 else
 550                         printf ("FALSE");
 551
 552                 break;
 553         }
 554         case MONO_TYPE_CHAR:
 555         case MONO_TYPE_I1:
 556         case MONO_TYPE_U1:
 557         case MONO_TYPE_I2:
 558         case MONO_TYPE_U2:
 559         case MONO_TYPE_I4:
 560         case MONO_TYPE_U4:
 561         case MONO_TYPE_I:
 562         case MONO_TYPE_U: {
 563                 int eax = va_arg (ap, int);
 564                 printf ("result=%d", eax);
 565                 break;
 566         }
 567         case MONO_TYPE_STRING: {
 568                 MonoString *s = va_arg (ap, MonoString *);
 569 ;
 570                 if (s) {
 571                         char *as;
 572
 573                         g_assert (((MonoObject *)s)->vtable->klass == mono_defaults.string_class);
 574                         as = string_to_utf8 (s);
 575                         printf ("[STRING:%p:%s]", s, as);
 576                         g_free (as);
 577                 } else
 578                         printf ("[STRING:null], ");
 579                 break;
 580         }
 581         case MONO_TYPE_CLASS:
 582         case MONO_TYPE_OBJECT: {
 583                 MonoObject *o = va_arg (ap, MonoObject *);
 584
 585                 if (o) {
 586                         if (o->vtable->klass == mono_defaults.boolean_class) {
 587                                 printf ("[BOOLEAN:%p:%d]", o, *((guint8 *)o + sizeof (MonoObject)));
 588                         } else if  (o->vtable->klass == mono_defaults.int32_class) {
 589                                 printf ("[INT32:%p:%d]", o, *((gint32 *)((char *)o + sizeof (MonoObject))));
 590                         } else if  (o->vtable->klass == mono_defaults.int64_class) {
 591                                 printf ("[INT64:%p:%lld]", o, (long long)*((gint64 *)((char *)o + sizeof (MonoObject))));
 592                         } else
 593                                 printf ("[%s.%s:%p]", o->vtable->klass->name_space, o->vtable->klass->name, o);
 594                 } else
 595                         printf ("[OBJECT:%p]", o);
 596
 597                 break;
 598         }
 599         case MONO_TYPE_PTR:
 600         case MONO_TYPE_FNPTR:
 601         case MONO_TYPE_ARRAY:
 602         case MONO_TYPE_SZARRAY: {
 603                 gpointer p = va_arg (ap, gpointer);
 604                 printf ("result=%p", p);
 605                 break;
 606         }
 607         case MONO_TYPE_I8: {
 608                 gint64 l =  va_arg (ap, gint64);
 609                 printf ("lresult=0x%16llx", (long long)l);
 610                 break;
 611         }
 612         case MONO_TYPE_U8: {
 613                 gint64 l =  va_arg (ap, gint64);
 614                 printf ("lresult=0x%16llx", (long long)l);
 615                 break;
 616         }
 617         case MONO_TYPE_R4:
 618         case MONO_TYPE_R8: {
 619                 double f = va_arg (ap, double);
 620                 printf ("FP=%f\n", f);
 621                 break;
 622         }
 623         case MONO_TYPE_VALUETYPE:
 624                 if (type->data.klass->enumtype) {
 625                         type = mono_class_enum_basetype (type->data.klass);
 626                         goto handle_enum;
 627                 } else {
 628                         guint8 *p = va_arg (ap, gpointer);
 629                         int j, size, align;
 630                         size = mono_type_size (type, &align);
 631                         printf ("[");
 632                         for (j = 0; p && j < size; j++)
 633                                 printf ("%02x,", p [j]);
 634                         printf ("]");
 635                 }
 636                 break;
 637         default:
 638                 printf ("(unknown return type %x)", mono_method_signature (method)->ret->type);
 639         }
 640
 641         //printf (" ip: %p\n", __builtin_return_address (1));
 642         printf ("\n");
 643         fflush (stdout);
 644 }
 645
 646 void
 647 mono_trace_enable (gboolean enable)
 648 {
 649         trace_spec.enabled = enable;
 650 }
 651
 652 gboolean
 653 mono_trace_is_enabled ()
 654 {
 655         return trace_spec.enabled;
 656 }