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