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