mono/metadata/profiler.c

   1
   2 #include "mono/metadata/profiler-private.h"
   3 #include "mono/metadata/debug-helpers.h"
   4 #include "mono/metadata/mono-debug.h"
   5 #include <string.h>
   6 #include <gmodule.h>
   7
   8 static MonoProfiler * current_profiler = NULL;
   9
  10 static MonoProfileAppDomainFunc   domain_start_load;
  11 static MonoProfileAppDomainResult domain_end_load;
  12 static MonoProfileAppDomainFunc   domain_start_unload;
  13 static MonoProfileAppDomainFunc   domain_end_unload;
  14
  15 static MonoProfileAssemblyFunc   assembly_start_load;
  16 static MonoProfileAssemblyResult assembly_end_load;
  17 static MonoProfileAssemblyFunc   assembly_start_unload;
  18 static MonoProfileAssemblyFunc   assembly_end_unload;
  19
  20 static MonoProfileModuleFunc   module_start_load;
  21 static MonoProfileModuleResult module_end_load;
  22 static MonoProfileModuleFunc   module_start_unload;
  23 static MonoProfileModuleFunc   module_end_unload;
  24
  25 static MonoProfileClassFunc   class_start_load;
  26 static MonoProfileClassResult class_end_load;
  27 static MonoProfileClassFunc   class_start_unload;
  28 static MonoProfileClassFunc   class_end_unload;
  29
  30 static MonoProfileMethodFunc   jit_start;
  31 static MonoProfileMethodResult jit_end;
  32 static MonoProfileMethodResult man_unman_transition;
  33 static MonoProfileAllocFunc    allocation_cb;
  34 static MonoProfileMethodFunc   method_enter;
  35 static MonoProfileMethodFunc   method_leave;
  36
  37 static MonoProfileThreadFunc   thread_start;
  38 static MonoProfileThreadFunc   thread_end;
  39
  40 static MonoProfileCoverageFilterFunc coverage_filter_cb;
  41
  42 static MonoProfileFunc shutdown_callback;
  43
  44 static MonoProfileCoverageLevel coverage_level = MONO_COVERAGE_BASIC_BLOCK;
  45
  46 /* this is directly accessible to other mono libs. */
  47 MonoProfileFlags mono_profiler_events;
  48
  49 void
  50 mono_profiler_install (MonoProfiler *prof, MonoProfileFunc callback)
  51 {
  52         if (current_profiler)
  53                 g_error ("profiler already setup");
  54         current_profiler = prof;
  55         shutdown_callback = callback;
  56 }
  57
  58 void
  59 mono_profiler_set_events (MonoProfileFlags events)
  60 {
  61         mono_profiler_events = events;
  62 }
  63
  64 MonoProfileFlags
  65 mono_profiler_get_events (void)
  66 {
  67         return mono_profiler_events;
  68 }
  69
  70 void
  71 mono_profiler_install_enter_leave (MonoProfileMethodFunc enter, MonoProfileMethodFunc fleave)
  72 {
  73         method_enter = enter;
  74         method_leave = fleave;
  75 }
  76
  77 void
  78 mono_profiler_install_jit_compile (MonoProfileMethodFunc start, MonoProfileMethodResult end)
  79 {
  80         jit_start = start;
  81         jit_end = end;
  82 }
  83
  84 void
  85 mono_profiler_install_thread (MonoProfileThreadFunc start, MonoProfileThreadFunc end)
  86 {
  87         thread_start = start;
  88         thread_end = end;
  89 }
  90
  91 void
  92 mono_profiler_install_transition (MonoProfileMethodResult callback)
  93 {
  94         man_unman_transition = callback;
  95 }
  96
  97 void
  98 mono_profiler_install_allocation (MonoProfileAllocFunc callback)
  99 {
 100         allocation_cb = callback;
 101 }
 102
 103 void
 104 mono_profiler_install_coverage_filter (MonoProfileCoverageFilterFunc callback)
 105 {
 106         coverage_filter_cb = callback;
 107 }
 108
 109 void
 110 mono_profiler_set_coverage_level (MonoProfileCoverageLevel level)
 111 {
 112         coverage_level = level;
 113 }
 114
 115 MonoProfileCoverageLevel
 116 mono_profiler_get_coverage_level ()
 117 {
 118         return coverage_level;
 119 }
 120
 121 void
 122 mono_profiler_install_appdomain   (MonoProfileAppDomainFunc start_load, MonoProfileAppDomainResult end_load,
 123                                    MonoProfileAppDomainFunc start_unload, MonoProfileAppDomainFunc end_unload)
 124
 125 {
 126         domain_start_load = start_load;
 127         domain_end_load = end_load;
 128         domain_start_unload = start_unload;
 129         domain_end_unload = end_unload;
 130 }
 131
 132 void
 133 mono_profiler_install_assembly    (MonoProfileAssemblyFunc start_load, MonoProfileAssemblyResult end_load,
 134                                    MonoProfileAssemblyFunc start_unload, MonoProfileAssemblyFunc end_unload)
 135 {
 136         assembly_start_load = start_load;
 137         assembly_end_load = end_load;
 138         assembly_start_unload = start_unload;
 139         assembly_end_unload = end_unload;
 140 }
 141
 142 void
 143 mono_profiler_install_module      (MonoProfileModuleFunc start_load, MonoProfileModuleResult end_load,
 144                                    MonoProfileModuleFunc start_unload, MonoProfileModuleFunc end_unload)
 145 {
 146         module_start_load = start_load;
 147         module_end_load = end_load;
 148         module_start_unload = start_unload;
 149         module_end_unload = end_unload;
 150 }
 151
 152 void
 153 mono_profiler_install_class       (MonoProfileClassFunc start_load, MonoProfileClassResult end_load,
 154                                    MonoProfileClassFunc start_unload, MonoProfileClassFunc end_unload)
 155 {
 156         class_start_load = start_load;
 157         class_end_load = end_load;
 158         class_start_unload = start_unload;
 159         class_end_unload = end_unload;
 160 }
 161
 162 void
 163 mono_profiler_method_enter (MonoMethod *method)
 164 {
 165         if ((mono_profiler_events & MONO_PROFILE_ENTER_LEAVE) && method_enter)
 166                 method_enter (current_profiler, method);
 167 }
 168
 169 void
 170 mono_profiler_method_leave (MonoMethod *method)
 171 {
 172         if ((mono_profiler_events & MONO_PROFILE_ENTER_LEAVE) && method_leave)
 173                 method_leave (current_profiler, method);
 174 }
 175
 176 void
 177 mono_profiler_method_jit (MonoMethod *method)
 178 {
 179         if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION) && jit_start)
 180                 jit_start (current_profiler, method);
 181 }
 182
 183 void
 184 mono_profiler_method_end_jit (MonoMethod *method, int result)
 185 {
 186         if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION) && jit_end)
 187                 jit_end (current_profiler, method, result);
 188 }
 189
 190 void
 191 mono_profiler_code_transition (MonoMethod *method, int result)
 192 {
 193         if ((mono_profiler_events & MONO_PROFILE_TRANSITIONS) && man_unman_transition)
 194                 man_unman_transition (current_profiler, method, result);
 195 }
 196
 197 void
 198 mono_profiler_allocation (MonoObject *obj, MonoClass *klass)
 199 {
 200         if ((mono_profiler_events & MONO_PROFILE_ALLOCATIONS) && allocation_cb)
 201                 allocation_cb (current_profiler, obj, klass);
 202 }
 203
 204 void
 205 mono_profiler_thread_start (guint32 tid)
 206 {
 207         if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_start)
 208                 thread_start (current_profiler, tid);
 209 }
 210
 211 void
 212 mono_profiler_thread_end (guint32 tid)
 213 {
 214         if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_end)
 215                 thread_end (current_profiler, tid);
 216 }
 217
 218 void
 219 mono_profiler_assembly_event  (MonoAssembly *assembly, int code)
 220 {
 221         if (!(mono_profiler_events & MONO_PROFILE_ASSEMBLY_EVENTS))
 222                 return;
 223
 224         switch (code) {
 225         case MONO_PROFILE_START_LOAD:
 226                 if (assembly_start_load)
 227                         assembly_start_load (current_profiler, assembly);
 228                 break;
 229         case MONO_PROFILE_START_UNLOAD:
 230                 if (assembly_start_unload)
 231                         assembly_start_unload (current_profiler, assembly);
 232                 break;
 233         case MONO_PROFILE_END_UNLOAD:
 234                 if (assembly_end_unload)
 235                         assembly_end_unload (current_profiler, assembly);
 236                 break;
 237         default:
 238                 g_assert_not_reached ();
 239         }
 240 }
 241
 242 void
 243 mono_profiler_assembly_loaded (MonoAssembly *assembly, int result)
 244 {
 245         if ((mono_profiler_events & MONO_PROFILE_ASSEMBLY_EVENTS) && assembly_end_load)
 246                 assembly_end_load (current_profiler, assembly, result);
 247 }
 248
 249 void
 250 mono_profiler_module_event  (MonoImage *module, int code)
 251 {
 252         if (!(mono_profiler_events & MONO_PROFILE_MODULE_EVENTS))
 253                 return;
 254
 255         switch (code) {
 256         case MONO_PROFILE_START_LOAD:
 257                 if (module_start_load)
 258                         module_start_load (current_profiler, module);
 259                 break;
 260         case MONO_PROFILE_START_UNLOAD:
 261                 if (module_start_unload)
 262                         module_start_unload (current_profiler, module);
 263                 break;
 264         case MONO_PROFILE_END_UNLOAD:
 265                 if (module_end_unload)
 266                         module_end_unload (current_profiler, module);
 267                 break;
 268         default:
 269                 g_assert_not_reached ();
 270         }
 271 }
 272
 273 void
 274 mono_profiler_module_loaded (MonoImage *module, int result)
 275 {
 276         if ((mono_profiler_events & MONO_PROFILE_MODULE_EVENTS) && module_end_load)
 277                 module_end_load (current_profiler, module, result);
 278 }
 279
 280 void
 281 mono_profiler_class_event  (MonoClass *klass, int code)
 282 {
 283         if (!(mono_profiler_events & MONO_PROFILE_CLASS_EVENTS))
 284                 return;
 285
 286         switch (code) {
 287         case MONO_PROFILE_START_LOAD:
 288                 if (class_start_load)
 289                         class_start_load (current_profiler, klass);
 290                 break;
 291         case MONO_PROFILE_START_UNLOAD:
 292                 if (class_start_unload)
 293                         class_start_unload (current_profiler, klass);
 294                 break;
 295         case MONO_PROFILE_END_UNLOAD:
 296                 if (class_end_unload)
 297                         class_end_unload (current_profiler, klass);
 298                 break;
 299         default:
 300                 g_assert_not_reached ();
 301         }
 302 }
 303
 304 void
 305 mono_profiler_class_loaded (MonoClass *klass, int result)
 306 {
 307         if ((mono_profiler_events & MONO_PROFILE_CLASS_EVENTS) && class_end_load)
 308                 class_end_load (current_profiler, klass, result);
 309 }
 310
 311 void
 312 mono_profiler_appdomain_event  (MonoDomain *domain, int code)
 313 {
 314         if (!(mono_profiler_events & MONO_PROFILE_APPDOMAIN_EVENTS))
 315                 return;
 316
 317         switch (code) {
 318         case MONO_PROFILE_START_LOAD:
 319                 if (domain_start_load)
 320                         domain_start_load (current_profiler, domain);
 321                 break;
 322         case MONO_PROFILE_START_UNLOAD:
 323                 if (domain_start_unload)
 324                         domain_start_unload (current_profiler, domain);
 325                 break;
 326         case MONO_PROFILE_END_UNLOAD:
 327                 if (domain_end_unload)
 328                         domain_end_unload (current_profiler, domain);
 329                 break;
 330         default:
 331                 g_assert_not_reached ();
 332         }
 333 }
 334
 335 void
 336 mono_profiler_appdomain_loaded (MonoDomain *domain, int result)
 337 {
 338         if ((mono_profiler_events & MONO_PROFILE_APPDOMAIN_EVENTS) && domain_end_load)
 339                 domain_end_load (current_profiler, domain, result);
 340 }
 341
 342 void
 343 mono_profiler_shutdown (void)
 344 {
 345         if (current_profiler && shutdown_callback)
 346                 shutdown_callback (current_profiler);
 347 }
 348
 349 static GHashTable *coverage_hash = NULL;
 350
 351 MonoProfileCoverageInfo*
 352 mono_profiler_coverage_alloc (MonoMethod *method, int entries)
 353 {
 354         MonoProfileCoverageInfo *res;
 355
 356         if (coverage_filter_cb)
 357                 if (! (*coverage_filter_cb) (current_profiler, method))
 358                         return NULL;
 359
 360         if (!coverage_hash)
 361                 coverage_hash = g_hash_table_new (NULL, NULL);
 362
 363         res = g_malloc0 (sizeof (MonoProfileCoverageInfo) + sizeof (void*) * 2 * entries);
 364
 365         res->entries = entries;
 366
 367         g_hash_table_insert (coverage_hash, method, res);
 368
 369         return res;
 370 }
 371
 372 /* safe only when the method antive code has been unloaded */
 373 void
 374 mono_profiler_coverage_free (MonoMethod *method)
 375 {
 376         MonoProfileCoverageInfo* info;
 377         if (!coverage_hash)
 378                 return;
 379         info = g_hash_table_lookup (coverage_hash, method);
 380         if (!info)
 381                 return;
 382         g_free (info);
 383         g_hash_table_remove (coverage_hash, method);
 384 }
 385
 386 void
 387 mono_profiler_coverage_get (MonoProfiler *prof, MonoMethod *method, MonoProfileCoverageFunc func)
 388 {
 389         MonoProfileCoverageInfo* info;
 390         int i, offset;
 391         guint32 line, col;
 392         unsigned char *start, *end, *cil_code;
 393         MonoMethodHeader *header;
 394         MonoProfileCoverageEntry entry;
 395
 396         info = g_hash_table_lookup (coverage_hash, method);
 397         if (!info)
 398                 return;
 399
 400         header = ((MonoMethodNormal *)method)->header;
 401         start = (unsigned char*)header->code;
 402         end = start + header->code_size;
 403         for (i = 0; i < info->entries; ++i) {
 404                 cil_code = info->data [i].cil_code;
 405                 if (cil_code && cil_code >= start && cil_code < end) {
 406                         offset = cil_code - start;
 407                         entry.iloffset = offset;
 408                         entry.method = method;
 409                         entry.counter = info->data [i].count;
 410                         /* the debug interface doesn't support column info, sigh */
 411                         col = line = 1;
 412                         entry.filename = mono_debug_source_location_from_il_offset (method, offset, &line);
 413                         entry.line = line;
 414                         entry.col = col;
 415                         func (prof, &entry);
 416                 }
 417         }
 418 }
 419
 420 /*
 421  * Small profiler extracted from mint: we should move it in a loadable module
 422  * and improve it to do graphs and more accurate timestamping with rdtsc.
 423  */
 424
 425 #define USE_X86TSC 0
 426 #define USE_WIN32COUNTER 0
 427 #if USE_X86TSC
 428
 429 typedef struct {
 430         unsigned int lows, highs, lowe, highe;
 431 } MonoRdtscTimer;
 432
 433 #define rdtsc(low,high) \
 434         __asm__ __volatile__("rdtsc" : "=a" (low), "=d" (high))
 435
 436 static int freq;
 437
 438 static double
 439 rdtsc_elapsed (MonoRdtscTimer *t)
 440 {
 441         unsigned long long diff;
 442         unsigned int highe = t->highe;
 443         if (t->lowe < t->lows)
 444                 highe--;
 445         diff = (((unsigned long long) highe - t->highs) << 32) + (t->lowe - t->lows);
 446         return ((double)diff / freq) / 1000000; /* have to return the result in seconds */
 447 }
 448
 449 static int
 450 have_rdtsc (void) {
 451         char buf[256];
 452         int have_freq = 0;
 453         int have_flag = 0;
 454         float val;
 455         FILE *cpuinfo;
 456
 457         if (!(cpuinfo = fopen ("/proc/cpuinfo", "r")))
 458                 return 0;
 459         while (fgets (buf, sizeof(buf), cpuinfo)) {
 460                 if (sscanf (buf, "cpu MHz : %f", &val) == 1) {
 461                         /*printf ("got mh: %f\n", val);*/
 462                         have_freq = val;
 463                 }
 464                 if (strncmp (buf, "flags", 5) == 0) {
 465                         if (strstr (buf, "tsc")) {
 466                                 have_flag = 1;
 467                                 /*printf ("have tsc\n");*/
 468                         }
 469                 }
 470         }
 471         fclose (cpuinfo);
 472         return have_flag? have_freq: 0;
 473 }
 474
 475 #define MONO_TIMER_STARTUP      \
 476         if (!(freq = have_rdtsc ())) g_error ("Compiled with TSC support, but none found");
 477 #define MONO_TIMER_TYPE  MonoRdtscTimer
 478 #define MONO_TIMER_INIT(t)
 479 #define MONO_TIMER_DESTROY(t)
 480 #define MONO_TIMER_START(t) rdtsc ((t).lows, (t).highs);
 481 #define MONO_TIMER_STOP(t) rdtsc ((t).lowe, (t).highe);
 482 #define MONO_TIMER_ELAPSED(t) rdtsc_elapsed (&(t))
 483
 484 #elif USE_WIN32COUNTER
 485 #include <windows.h>
 486
 487 typedef struct {
 488         LARGE_INTEGER start, stop;
 489 } MonoWin32Timer;
 490
 491 static int freq;
 492
 493 static double
 494 win32_elapsed (MonoWin32Timer *t)
 495 {
 496         LONGLONG diff = t->stop.QuadPart - t->start.QuadPart;
 497         return ((double)diff / freq) / 1000000; /* have to return the result in seconds */
 498 }
 499
 500 static int
 501 have_win32counter (void) {
 502         LARGE_INTEGER f;
 503
 504         if (!QueryPerformanceFrequency (&f))
 505                 return 0;
 506         return f.LowPart;
 507 }
 508
 509 #define MONO_TIMER_STARTUP      \
 510         if (!(freq = have_win32counter ())) g_error ("Compiled with Win32 counter support, but none found");
 511 #define MONO_TIMER_TYPE  MonoWin32Timer
 512 #define MONO_TIMER_INIT(t)
 513 #define MONO_TIMER_DESTROY(t)
 514 #define MONO_TIMER_START(t) QueryPerformanceCounter (&(t).start)
 515 #define MONO_TIMER_STOP(t) QueryPerformanceCounter (&(t).stop)
 516 #define MONO_TIMER_ELAPSED(t) win32_elapsed (&(t))
 517
 518 #else
 519
 520 typedef struct {
 521         GTimeVal start, stop;
 522 } MonoGLibTimer;
 523
 524 static double
 525 timeval_elapsed (MonoGLibTimer *t)
 526 {
 527         if (t->start.tv_usec > t->stop.tv_usec) {
 528                 t->stop.tv_usec += G_USEC_PER_SEC;
 529                 t->stop.tv_sec--;
 530         }
 531         return (t->stop.tv_sec - t->start.tv_sec)
 532                 + ((double)(t->stop.tv_usec - t->start.tv_usec))/ G_USEC_PER_SEC;
 533 }
 534
 535 #define MONO_TIMER_STARTUP
 536 #define MONO_TIMER_TYPE MonoGLibTimer
 537 #define MONO_TIMER_INIT(t)
 538 #define MONO_TIMER_DESTROY(t)
 539 #define MONO_TIMER_START(t) g_get_current_time (&(t).start)
 540 #define MONO_TIMER_STOP(t) g_get_current_time (&(t).stop)
 541 #define MONO_TIMER_ELAPSED(t) timeval_elapsed (&(t))
 542 #endif
 543
 544 typedef struct _AllocInfo AllocInfo;
 545 typedef struct _CallerInfo CallerInfo;
 546 typedef struct _LastCallerInfo LastCallerInfo;
 547
 548 struct _MonoProfiler {
 549         GHashTable *methods;
 550         MonoMemPool *mempool;
 551         /* info about JIT time */
 552         MONO_TIMER_TYPE jit_timer;
 553         double      jit_time;
 554         double      max_jit_time;
 555         MonoMethod *max_jit_method;
 556         int         methods_jitted;
 557
 558         /* tls_id is the id for the TLS slot where MonoProfiler is stored */
 559         int         tls_id;
 560         GSList     *per_thread;
 561
 562         /* chain of callers for the current thread */
 563         LastCallerInfo *callers;
 564         /* LastCallerInfo nodes for faster allocation */
 565         LastCallerInfo *cstorage;
 566 };
 567
 568 typedef struct {
 569         MonoMethod *method;
 570         guint64 count;
 571         double total;
 572         AllocInfo *alloc_info;
 573         CallerInfo *caller_info;
 574 } MethodProfile;
 575
 576 typedef struct _MethodCallProfile MethodCallProfile;
 577
 578 struct _MethodCallProfile {
 579         MethodCallProfile *next;
 580         MONO_TIMER_TYPE timer;
 581         MonoMethod *method;
 582 };
 583
 584 struct _AllocInfo {
 585         AllocInfo *next;
 586         MonoClass *klass;
 587         guint count;
 588         guint mem;
 589 };
 590
 591 struct _CallerInfo {
 592         CallerInfo *next;
 593         MonoMethod *caller;
 594         guint count;
 595 };
 596
 597 struct _LastCallerInfo {
 598         LastCallerInfo *next;
 599         MonoMethod *method;
 600         MONO_TIMER_TYPE timer;
 601 };
 602
 603 static MonoProfiler*
 604 create_profiler (void)
 605 {
 606         MonoProfiler *prof = g_new0 (MonoProfiler, 1);
 607
 608         prof->methods = g_hash_table_new (g_direct_hash, g_direct_equal);
 609         MONO_TIMER_INIT (prof->jit_timer);
 610         prof->mempool = mono_mempool_new ();
 611         return prof;
 612 }
 613 #if 1
 614 #define GET_THREAD_PROF(prof) do {\
 615                 MonoProfiler *_tprofiler = TlsGetValue ((prof)->tls_id);        \
 616                 if (!_tprofiler) {      \
 617                         _tprofiler = create_profiler ();        \
 618                         prof->per_thread = g_slist_prepend (prof->per_thread, _tprofiler);      \
 619                         TlsSetValue ((prof)->tls_id, _tprofiler);       \
 620                 }       \
 621                 prof = _tprofiler;      \
 622         } while (0)
 623 #else
 624 /* thread unsafe but faster variant */
 625 #define GET_THREAD_PROF(prof)
 626 #endif
 627
 628 static gint
 629 compare_profile (MethodProfile *profa, MethodProfile *profb)
 630 {
 631         return (gint)((profb->total - profa->total)*1000);
 632 }
 633
 634 static void
 635 build_profile (MonoMethod *m, MethodProfile *prof, GList **funcs)
 636 {
 637         prof->method = m;
 638         *funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_profile);
 639 }
 640
 641 static char*
 642 method_get_name (MonoMethod* method)
 643 {
 644         char *sig, *res;
 645
 646         sig = mono_signature_get_desc (method->signature, FALSE);
 647         res = g_strdup_printf ("%s.%s::%s(%s)", method->klass->name_space, method->klass->name,
 648                 method->name, sig);
 649         g_free (sig);
 650         return res;
 651 }
 652
 653 static void output_callers (MethodProfile *p);
 654
 655 static void
 656 output_profile (GList *funcs)
 657 {
 658         GList *tmp;
 659         MethodProfile *p;
 660         char *m;
 661         guint64 total_calls = 0;
 662
 663         if (funcs)
 664                 g_print ("Time(ms) Count   P/call(ms) Method name\n");
 665         for (tmp = funcs; tmp; tmp = tmp->next) {
 666                 p = tmp->data;
 667                 total_calls += p->count;
 668                 if (!(gint)(p->total*1000))
 669                         continue;
 670                 m = method_get_name (p->method);
 671                 printf ("########################\n% 8.3f %7llu % 8.3f  %s\n",
 672                         (double)(p->total*1000), p->count, (double)(p->total*1000)/(double)p->count, m);
 673                 g_free (m);
 674                 /* callers */
 675                 output_callers (p);
 676         }
 677         printf ("Total number of calls: %lld\n", total_calls);
 678 }
 679
 680 typedef struct {
 681         MethodProfile *mp;
 682         guint count;
 683 } NewobjProfile;
 684
 685 static gint
 686 compare_newobj_profile (NewobjProfile *profa, NewobjProfile *profb)
 687 {
 688         return (gint)profb->count - (gint)profa->count;
 689 }
 690
 691 static void
 692 build_newobj_profile (MonoClass *class, MethodProfile *mprof, GList **funcs)
 693 {
 694         NewobjProfile *prof = g_new (NewobjProfile, 1);
 695         AllocInfo *tmp;
 696         guint count = 0;
 697
 698         prof->mp = mprof;
 699         /* we use the total amount of memory to sort */
 700         for (tmp = mprof->alloc_info; tmp; tmp = tmp->next)
 701                 count += tmp->mem;
 702         prof->count = count;
 703         *funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_newobj_profile);
 704 }
 705
 706 static int
 707 compare_caller (CallerInfo *a, CallerInfo *b)
 708 {
 709         return b->count - a->count;
 710 }
 711
 712 static int
 713 compare_alloc (AllocInfo *a, AllocInfo *b)
 714 {
 715         return b->mem - a->mem;
 716 }
 717
 718 static GSList*
 719 sort_alloc_list (AllocInfo *ai)
 720 {
 721         GSList *l = NULL;
 722         AllocInfo *tmp;
 723         for (tmp = ai; tmp; tmp = tmp->next) {
 724                 l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_alloc);
 725         }
 726         return l;
 727 }
 728
 729 static GSList*
 730 sort_caller_list (CallerInfo *ai)
 731 {
 732         GSList *l = NULL;
 733         CallerInfo *tmp;
 734         for (tmp = ai; tmp; tmp = tmp->next) {
 735                 l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_caller);
 736         }
 737         return l;
 738 }
 739
 740 static void
 741 output_callers (MethodProfile *p) {
 742         guint total_callers, percent;
 743         GSList *sorted, *tmps;
 744         CallerInfo *cinfo;
 745         char *m;
 746
 747         g_print ("  Callers (with count) that contribute at least for 1%%:\n");
 748         total_callers = 0;
 749         for (cinfo = p->caller_info; cinfo; cinfo = cinfo->next) {
 750                 total_callers += cinfo->count;
 751         }
 752         sorted = sort_caller_list (p->caller_info);
 753         for (tmps = sorted; tmps; tmps = tmps->next) {
 754                 cinfo = tmps->data;
 755                 percent = (cinfo->count * 100)/total_callers;
 756                 if (percent < 1)
 757                         continue;
 758                 m = method_get_name (cinfo->caller);
 759                 g_print ("    %8d % 3d %% %s\n", cinfo->count, percent, m);
 760                 g_free (m);
 761         }
 762 }
 763
 764 static void
 765 output_newobj_profile (GList *proflist)
 766 {
 767         GList *tmp;
 768         NewobjProfile *p;
 769         MethodProfile *mp;
 770         AllocInfo *ainfo;
 771         MonoClass *klass;
 772         const char* isarray;
 773         char buf [256];
 774         char *m;
 775         guint total = 0;
 776         GSList *sorted, *tmps;
 777
 778         g_print ("\nAllocation profiler\n");
 779
 780         if (proflist)
 781                 g_print ("%-9s %s\n", "Total mem", "Method");
 782         for (tmp = proflist; tmp; tmp = tmp->next) {
 783                 p = tmp->data;
 784                 total += p->count;
 785                 if (p->count < 50000)
 786                         continue;
 787                 mp = p->mp;
 788                 m = method_get_name (mp->method);
 789                 g_print ("########################\n%8d KB %s\n", p->count / 1024, m);
 790                 g_free (m);
 791                 sorted = sort_alloc_list (mp->alloc_info);
 792                 for (tmps = sorted; tmps; tmps = tmps->next) {
 793                         ainfo = tmps->data;
 794                         if (ainfo->mem < 50000)
 795                                 continue;
 796                         klass = ainfo->klass;
 797                         if (klass->rank) {
 798                                 isarray = "[]";
 799                                 klass = klass->element_class;
 800                         } else {
 801                                 isarray = "";
 802                         }
 803                         g_snprintf (buf, sizeof (buf), "%s.%s%s",
 804                                 klass->name_space, klass->name, isarray);
 805                         g_print ("    %8d KB %8d %-48s\n", ainfo->mem / 1024, ainfo->count, buf);
 806                 }
 807                 /* callers */
 808                 output_callers (mp);
 809         }
 810         g_print ("Total memory allocated: %d KB\n", total / 1024);
 811 }
 812
 813 static void
 814 merge_methods (MonoMethod *method, MethodProfile *profile, MonoProfiler *prof)
 815 {
 816         MethodProfile *mprof;
 817         AllocInfo *talloc_info, *alloc_info;
 818         CallerInfo *tcaller_info, *caller_info;
 819
 820         mprof = g_hash_table_lookup (prof->methods, method);
 821         if (!mprof) {
 822                 /* the master thread didn't see this method, just transfer the info as is */
 823                 g_hash_table_insert (prof->methods, method, profile);
 824                 return;
 825         }
 826         /* merge the info from profile into mprof */
 827         mprof->count += profile->count;
 828         mprof->total += profile->total;
 829         /* merge alloc info */
 830         for (talloc_info = profile->alloc_info; talloc_info; talloc_info = talloc_info->next) {
 831                 for (alloc_info = mprof->alloc_info; alloc_info; alloc_info = alloc_info->next) {
 832                         if (alloc_info->klass == talloc_info->klass) {
 833                                 /* mprof already has a record for the klass, merge */
 834                                 alloc_info->count += talloc_info->count;
 835                                 alloc_info->mem += talloc_info->mem;
 836                                 break;
 837                         }
 838                 }
 839                 if (!alloc_info) {
 840                         /* mprof didn't have the info, just copy it over */
 841                         alloc_info = mono_mempool_alloc0 (prof->mempool, sizeof (AllocInfo));
 842                         *alloc_info = *talloc_info;
 843                         alloc_info->next = mprof->alloc_info;
 844                         mprof->alloc_info = alloc_info->next;
 845                 }
 846         }
 847         /* merge callers info */
 848         for (tcaller_info = profile->caller_info; tcaller_info; tcaller_info = tcaller_info->next) {
 849                 for (caller_info = mprof->caller_info; caller_info; caller_info = caller_info->next) {
 850                         if (caller_info->caller == tcaller_info->caller) {
 851                                 /* mprof already has a record for the caller method, merge */
 852                                 caller_info->count += tcaller_info->count;
 853                                 break;
 854                         }
 855                 }
 856                 if (!caller_info) {
 857                         /* mprof didn't have the info, just copy it over */
 858                         caller_info = mono_mempool_alloc0 (prof->mempool, sizeof (CallerInfo));
 859                         *caller_info = *tcaller_info;
 860                         caller_info->next = mprof->caller_info;
 861                         mprof->caller_info = caller_info->next;
 862                 }
 863         }
 864 }
 865
 866 static void
 867 merge_thread_data (MonoProfiler *master, MonoProfiler *tprof)
 868 {
 869         master->jit_time += tprof->jit_time;
 870         master->methods_jitted += tprof->methods_jitted;
 871         if (master->max_jit_time < tprof->max_jit_time) {
 872                 master->max_jit_time = tprof->max_jit_time;
 873                 master->max_jit_method = tprof->max_jit_method;
 874         }
 875
 876         g_hash_table_foreach (tprof->methods, (GHFunc)merge_methods, master);
 877 }
 878
 879 static void
 880 simple_method_enter (MonoProfiler *prof, MonoMethod *method)
 881 {
 882         MethodProfile *profile_info;
 883         LastCallerInfo *callinfo;
 884         GET_THREAD_PROF (prof);
 885         /*g_print ("enter %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
 886         if (!(profile_info = g_hash_table_lookup (prof->methods, method))) {
 887                 profile_info = mono_mempool_alloc0 (prof->mempool, sizeof (MethodProfile));
 888                 MONO_TIMER_INIT (profile_info->u.timer);
 889                 g_hash_table_insert (prof->methods, method, profile_info);
 890         }
 891         profile_info->count++;
 892         if (prof->callers) {
 893                 CallerInfo *cinfo;
 894                 MonoMethod *caller = prof->callers->method;
 895                 for (cinfo = profile_info->caller_info; cinfo; cinfo = cinfo->next) {
 896                         if (cinfo->caller == caller)
 897                                 break;
 898                 }
 899                 if (!cinfo) {
 900                         cinfo = mono_mempool_alloc0 (prof->mempool, sizeof (CallerInfo));
 901                         cinfo->caller = caller;
 902                         cinfo->next = profile_info->caller_info;
 903                         profile_info->caller_info = cinfo;
 904                 }
 905                 cinfo->count++;
 906         }
 907         if (!(callinfo = prof->cstorage)) {
 908                 callinfo = mono_mempool_alloc (prof->mempool, sizeof (LastCallerInfo));
 909                 MONO_TIMER_INIT (callinfo->timer);
 910         } else {
 911                 prof->cstorage = prof->cstorage->next;
 912         }
 913         callinfo->method = method;
 914         callinfo->next = prof->callers;
 915         prof->callers = callinfo;
 916         MONO_TIMER_START (callinfo->timer);
 917 }
 918
 919 static void
 920 simple_method_leave (MonoProfiler *prof, MonoMethod *method)
 921 {
 922         MethodProfile *profile_info;
 923         LastCallerInfo *callinfo, *newcallinfo = NULL;
 924
 925         GET_THREAD_PROF (prof);
 926         /*g_print ("leave %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
 927         callinfo = prof->callers;
 928         /* should really not happen, but we don't catch exceptions events, yet ... */
 929         while (callinfo) {
 930                 MONO_TIMER_STOP (callinfo->timer);
 931                 profile_info = g_hash_table_lookup (prof->methods, callinfo->method);
 932                 if (profile_info)
 933                         profile_info->total += MONO_TIMER_ELAPSED (callinfo->timer);
 934                 newcallinfo = callinfo->next;
 935                 callinfo->next = prof->cstorage;
 936                 prof->cstorage = callinfo;
 937                 if (callinfo->method == method)
 938                         break;
 939                 callinfo = newcallinfo;
 940         }
 941         prof->callers = newcallinfo;
 942 }
 943
 944 static void
 945 simple_allocation (MonoProfiler *prof, MonoObject *obj, MonoClass *klass)
 946 {
 947         MethodProfile *profile_info;
 948         AllocInfo *tmp;
 949
 950         GET_THREAD_PROF (prof);
 951         if (prof->callers) {
 952                 if (!(profile_info = g_hash_table_lookup (prof->methods, prof->callers->method)))
 953                         g_assert_not_reached ();
 954         } else {
 955                 return; /* fine for now */
 956         }
 957
 958         for (tmp = profile_info->alloc_info; tmp; tmp = tmp->next) {
 959                 if (tmp->klass == klass)
 960                         break;
 961         }
 962         if (!tmp) {
 963                 tmp = mono_mempool_alloc0 (prof->mempool, sizeof (AllocInfo));
 964                 tmp->klass = klass;
 965                 tmp->next = profile_info->alloc_info;
 966                 profile_info->alloc_info = tmp;
 967         }
 968         tmp->count++;
 969         if (klass == mono_defaults.string_class) {
 970                 tmp->mem += sizeof (MonoString) + 2 * mono_string_length ((MonoString*)obj) + 2;
 971         } else if (klass->parent == mono_defaults.array_class) {
 972                 tmp->mem += sizeof (MonoArray) + mono_array_element_size (klass) * mono_array_length ((MonoArray*)obj);
 973         } else {
 974                 tmp->mem += mono_class_instance_size (klass);
 975         }
 976 }
 977
 978 static void
 979 simple_method_jit (MonoProfiler *prof, MonoMethod *method)
 980 {
 981         GET_THREAD_PROF (prof);
 982         prof->methods_jitted++;
 983         MONO_TIMER_START (prof->jit_timer);
 984 }
 985
 986 static void
 987 simple_method_end_jit (MonoProfiler *prof, MonoMethod *method, int result)
 988 {
 989         double jtime;
 990         GET_THREAD_PROF (prof);
 991         MONO_TIMER_STOP (prof->jit_timer);
 992         jtime = MONO_TIMER_ELAPSED (prof->jit_timer);
 993         prof->jit_time += jtime;
 994         if (jtime > prof->max_jit_time) {
 995                 prof->max_jit_time = jtime;
 996                 prof->max_jit_method = method;
 997         }
 998 }
 999
1000 static void
1001 simple_shutdown (MonoProfiler *prof)
1002 {
1003         GList *profile = NULL;
1004         MonoProfiler *tprof;
1005         GSList *tmp;
1006         char *str;
1007
1008         for (tmp = prof->per_thread; tmp; tmp = tmp->next) {
1009                 tprof = tmp->data;
1010                 merge_thread_data (prof, tprof);
1011         }
1012
1013         printf("Total time spent compiling %d methods (sec): %.4g\n", prof->methods_jitted, prof->jit_time);
1014         if (prof->max_jit_method) {
1015                 str = method_get_name (prof->max_jit_method);
1016                 printf("Slowest method to compile (sec): %.4g: %s\n", prof->max_jit_time, str);
1017                 g_free (str);
1018         }
1019         g_hash_table_foreach (prof->methods, (GHFunc)build_profile, &profile);
1020         output_profile (profile);
1021         g_list_free (profile);
1022         profile = NULL;
1023
1024         g_hash_table_foreach (prof->methods, (GHFunc)build_newobj_profile, &profile);
1025         output_newobj_profile (profile);
1026         g_list_free (profile);
1027 }
1028
1029 static void
1030 mono_profiler_install_simple (const char *desc)
1031 {
1032         MonoProfiler *prof;
1033
1034         MONO_TIMER_STARTUP;
1035
1036         prof = create_profiler ();
1037         prof->tls_id = TlsAlloc ();
1038         TlsSetValue (prof->tls_id, prof);
1039
1040         mono_profiler_install (prof, simple_shutdown);
1041         /* later do also object creation */
1042         mono_profiler_install_enter_leave (simple_method_enter, simple_method_leave);
1043         mono_profiler_install_jit_compile (simple_method_jit, simple_method_end_jit);
1044         mono_profiler_install_allocation (simple_allocation);
1045         mono_profiler_set_events (MONO_PROFILE_ENTER_LEAVE|MONO_PROFILE_JIT_COMPILATION|MONO_PROFILE_ALLOCATIONS);
1046 }
1047
1048 typedef void (*ProfilerInitializer) (const char*);
1049 #define INITIALIZER_NAME "mono_profiler_startup"
1050
1051 void
1052 mono_profiler_load (const char *desc)
1053 {
1054         if (!desc || (strcmp ("default", desc) == 0) || (strncmp (desc, "default:", 8) == 0)) {
1055                 mono_profiler_install_simple (desc);
1056         } else {
1057                 GModule *pmodule;
1058                 const char* col = strchr (desc, ':');
1059                 char* libname;
1060                 char* path;
1061                 char *mname;
1062                 if (col != NULL) {
1063                         mname = g_memdup (desc, col - desc);
1064                         mname [col - desc] = 0;
1065                 } else {
1066                         mname = g_strdup (desc);
1067                 }
1068                 libname = g_strdup_printf ("mono-profiler-%s", mname);
1069                 path = g_module_build_path (NULL, libname);
1070                 pmodule = g_module_open (path, G_MODULE_BIND_LAZY);
1071                 if (pmodule) {
1072                         ProfilerInitializer func;
1073                         if (!g_module_symbol (pmodule, INITIALIZER_NAME, (gpointer *)&func)) {
1074                                 g_warning ("Cannot find initializer function %s in profiler module: %s", INITIALIZER_NAME, libname);
1075                         } else {
1076                                 func (desc);
1077                         }
1078                 } else {
1079                         g_warning ("Error loading profiler module '%s': %s", libname, g_module_error ());
1080                 }
1081
1082                 g_free (libname);
1083                 g_free (mname);
1084                 g_free (path);
1085         }
1086 }
1087