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