[project @ 1999-04-08 15:43:44 by simonm]
[ghc-hetmet.git] / ghc / rts / Profiling.c
1 /* -----------------------------------------------------------------------------
2  * $Id: Profiling.c,v 1.5 1999/04/08 15:43:45 simonm Exp $
3  *
4  * (c) The GHC Team, 1998-1999
5  *
6  * Support for profiling
7  *
8  * ---------------------------------------------------------------------------*/
9
10 #ifdef PROFILING
11
12 #include "Rts.h"
13 #include "RtsUtils.h"
14 #include "RtsFlags.h"
15 #include "ProfRts.h"
16 #include "StgRun.h"
17 #include "StgStartup.h"
18 #include "Storage.h"
19 #include "Proftimer.h"
20 #include "Itimer.h"
21
22 /*
23  * Global variables used to assign unique IDs to cc's, ccs's, and 
24  * closure_cats
25  */
26
27 unsigned int CC_ID;
28 unsigned int CCS_ID;
29 unsigned int HP_ID;
30
31 /* Table sizes from old profiling system.  Not sure if we'll need
32  * these.
33  */
34 nat time_intervals = 0;
35 nat earlier_ticks  = 0;
36 nat max_cc_no      = 0;
37 nat max_mod_no     = 0;
38 nat max_grp_no     = 0;
39 nat max_descr_no   = 0;
40 nat max_type_no    = 0;
41
42 /* Are we time-profiling?
43  */
44 rtsBool time_profiling = rtsFalse;
45
46 /* figures for the profiling report.
47  */
48 static lnat total_alloc, total_ticks;
49
50 /* Globals for opening the profiling log file
51  */
52 static char *prof_filename; /* prof report file name = <program>.prof */
53 static FILE *prof_file;
54
55 /* The Current Cost Centre Stack (for attributing costs)
56  */
57 CostCentreStack *CCCS;
58
59 /* Linked lists to keep track of cc's and ccs's that haven't
60  * been declared in the log file yet
61  */
62 CostCentre *CC_LIST;
63 CostCentreStack *CCS_LIST;
64 CCSDecList *New_CCS_LIST;
65
66 /*
67  * Built-in cost centres and cost-centre stacks:
68  *
69  *    MAIN   is the root of the cost-centre stack tree.  If there are
70  *           no _scc_s in the program, all costs will be attributed
71  *           to MAIN.
72  *
73  *    SYSTEM is the RTS in general (scheduler, etc.).  All costs for
74  *           RTS operations apart from garbage collection are attributed
75  *           to SYSTEM.
76  *
77  *    GC     is the storage manager / garbage collector.
78  *
79  *    OVERHEAD gets all costs generated by the profiling system
80  *           itself.  These are costs that would not be incurred
81  *           during non-profiled execution of the program.
82  *
83  *    SUBSUMED is the one-and-only CCS placed on top-level functions. 
84  *           It indicates that all costs are to be attributed to the
85  *           enclosing cost centre stack.  SUBSUMED never accumulates
86  *           any costs.
87  *
88  *    DONT_CARE is a placeholder cost-centre we assign to static
89  *           constructors.  It should *never* accumulate any costs.
90  */
91
92 CC_DECLARE(CC_MAIN,      "MAIN",        "MAIN",      "MAIN",  CC_IS_BORING,);
93 CC_DECLARE(CC_SYSTEM,    "SYSTEM",      "MAIN",      "MAIN",  CC_IS_BORING,);
94 CC_DECLARE(CC_GC,        "GC",          "GC",        "GC",    CC_IS_BORING,);
95 CC_DECLARE(CC_OVERHEAD,  "OVERHEAD_of", "PROFILING", "PROFILING", CC_IS_CAF,);
96 CC_DECLARE(CC_SUBSUMED,  "SUBSUMED",    "MAIN",      "MAIN",  CC_IS_SUBSUMED,);
97 CC_DECLARE(CC_DONTZuCARE,"DONT_CARE",   "MAIN",      "MAIN",  CC_IS_BORING,);
98
99 CCS_DECLARE(CCS_MAIN,       CC_MAIN,       CC_IS_BORING,   );
100 CCS_DECLARE(CCS_SYSTEM,     CC_SYSTEM,     CC_IS_BORING,   );
101 CCS_DECLARE(CCS_GC,         CC_GC,         CC_IS_BORING,   );
102 CCS_DECLARE(CCS_OVERHEAD,   CC_OVERHEAD,   CC_IS_CAF,      );
103 CCS_DECLARE(CCS_SUBSUMED,   CC_SUBSUMED,   CC_IS_SUBSUMED, );
104 CCS_DECLARE(CCS_DONTZuCARE, CC_DONTZuCARE, CC_IS_BORING,   );
105
106 /* 
107  * Static Functions
108  */
109
110 static CostCentreStack * ActualPush_ ( CostCentreStack *ccs, CostCentre *cc, 
111                                        CostCentreStack *new_ccs );
112
113 static    void registerCostCentres ( void );
114 static rtsBool ccs_to_ignore       ( CostCentreStack *ccs );
115 static    void count_ticks         ( CostCentreStack *ccs );
116 static    void reportCCS           ( CostCentreStack *ccs, nat indent );
117 static    void DecCCS              ( CostCentreStack *ccs );
118 static    CostCentreStack *pruneCCSTree ( CostCentreStack *ccs );
119 #ifdef DEBUG
120 static    void printCCS            ( CostCentreStack *ccs );
121 #endif
122
123 /* -----------------------------------------------------------------------------
124    Initialise the profiling environment
125    -------------------------------------------------------------------------- */
126
127 void
128 initProfiling (void)
129 {
130   CostCentreStack *ccs, *next;
131
132   /* for the benefit of allocate()... */
133   CCCS = CCS_SYSTEM;
134
135   if (!RtsFlags.CcFlags.doCostCentres)
136     return;
137   
138   time_profiling = rtsTrue;
139
140   /* Initialise the log file name */
141   prof_filename = stgMallocBytes(strlen(prog_argv[0]) + 6, "initProfiling");
142   sprintf(prof_filename, "%s.prof", prog_argv[0]);
143
144   /* Initialize counters for IDs */
145   CC_ID  = 0;
146   CCS_ID = 0;
147   HP_ID  = 0;
148   
149   /* Initialize Declaration lists to NULL */
150   CC_LIST  = NULL;
151   CCS_LIST = NULL;
152
153   /* Register all the cost centres / stacks in the program 
154    * CC_MAIN gets link = 0, all others have non-zero link.
155    */
156   REGISTER_CC(CC_MAIN);
157   REGISTER_CC(CC_SYSTEM);
158   REGISTER_CC(CC_GC);
159   REGISTER_CC(CC_OVERHEAD);
160   REGISTER_CC(CC_SUBSUMED);
161   REGISTER_CC(CC_DONTZuCARE);
162   REGISTER_CCS(CCS_MAIN);
163   REGISTER_CCS(CCS_SYSTEM);
164   REGISTER_CCS(CCS_GC);
165   REGISTER_CCS(CCS_OVERHEAD);
166   REGISTER_CCS(CCS_SUBSUMED);
167   REGISTER_CCS(CCS_DONTZuCARE);
168
169   CCCS = CCS_OVERHEAD;
170   registerCostCentres();
171
172   /* find all the "special" cost centre stacks, and make them children
173    * of CCS_MAIN.
174    */
175   ASSERT(CCS_MAIN->prevStack == 0);
176   for (ccs = CCS_LIST; ccs != CCS_MAIN; ) {
177     next = ccs->prevStack;
178     ccs->prevStack = 0;
179     ActualPush_(CCS_MAIN,ccs->cc,ccs);
180     ccs = next;
181   }
182   
183   /* profiling is the only client of the VTALRM system at the moment,
184    * so just install the profiling tick handler. */
185   install_vtalrm_handler(handleProfTick);
186   startProfTimer();
187 };
188
189 void 
190 endProfiling ( void )
191 {
192   stopProfTimer();
193 }
194
195 void
196 heapCensus ( bdescr *bd )
197 {
198   /* nothing yet */
199 }
200
201 /* -----------------------------------------------------------------------------
202    Register Cost Centres
203
204    At the moment, this process just supplies a unique integer to each
205    statically declared cost centre and cost centre stack in the
206    program.
207
208    The code generator inserts a small function "reg<moddule>" in each
209    module which registers any cost centres from that module and calls
210    the registration functions in each of the modules it imports.  So,
211    if we call "regMain", each reachable module in the program will be
212    registered. 
213
214    The reg* functions are compiled in the same way as STG code,
215    i.e. without normal C call/return conventions.  Hence we must use
216    StgRun to call this stuff.
217    -------------------------------------------------------------------------- */
218
219 /* The registration functions use an explicit stack... 
220  */
221 #define REGISTER_STACK_SIZE  (BLOCK_SIZE * 4)
222 F_ *register_stack;
223
224 static void
225 registerCostCentres ( void )
226 {
227   /* this storage will be reclaimed by the garbage collector,
228    * as a large block.
229    */
230   register_stack = (F_ *)allocate(REGISTER_STACK_SIZE / sizeof(W_));
231
232   StgRun((StgFunPtr)stg_register);
233 }
234
235
236 /* -----------------------------------------------------------------------------
237    Cost-centre stack manipulation
238    -------------------------------------------------------------------------- */
239
240 #ifdef DEBUG
241 CostCentreStack * _PushCostCentre ( CostCentreStack *ccs, CostCentre *cc );
242 CostCentreStack *
243 PushCostCentre ( CostCentreStack *ccs, CostCentre *cc )
244 #define PushCostCentre _PushCostCentre
245 {
246   IF_DEBUG(prof, 
247            fprintf(stderr,"Pushing %s on ", cc->label);
248            printCCS(ccs);
249            fprintf(stderr,"\n"));
250   return PushCostCentre(ccs,cc);
251 }
252 #endif
253
254 CostCentreStack *
255 PushCostCentre ( CostCentreStack *ccs, CostCentre *cc )
256 {
257   CostCentreStack *temp_ccs;
258   
259   if (ccs == EMPTY_STACK)
260     return ActualPush(ccs,cc);
261   else {
262     if (ccs->cc == cc)
263       return ccs;
264     else {
265       /* check if we've already memoized this stack */
266       temp_ccs = IsInIndexTable(ccs->indexTable,cc);
267       
268       if (temp_ccs != EMPTY_STACK)
269         return temp_ccs;
270       else {
271         /* remove the CC to avoid loops */
272         ccs = RemoveCC(ccs,cc);
273         /* have a different stack now, need to check the memo table again */
274         temp_ccs = IsInIndexTable(ccs->indexTable,cc);
275         if (temp_ccs != EMPTY_STACK)
276           return temp_ccs;
277         else
278           return ActualPush(ccs,cc);
279       }
280     }
281   }
282 }
283
284 /* Append ccs1 to ccs2 (ignoring any CAF cost centre at the root of ccs1 */
285
286 #ifdef DEBUG
287 CostCentreStack *_AppendCCS ( CostCentreStack *ccs1, CostCentreStack *ccs2 );
288 CostCentreStack *
289 AppendCCS ( CostCentreStack *ccs1, CostCentreStack *ccs2 )
290 #define AppendCCS _AppendCCS
291 {
292   CostCentreStack *ccs;
293   IF_DEBUG(prof, 
294            if (ccs1 != ccs2) {
295              fprintf(stderr,"Appending ");
296              printCCS(ccs1);
297              fprintf(stderr," to ");
298              printCCS(ccs2);
299              fprintf(stderr,"\n");});
300   return AppendCCS(ccs1,ccs2);
301 }
302 #endif
303
304 CostCentreStack *
305 AppendCCS ( CostCentreStack *ccs1, CostCentreStack *ccs2 )
306 {
307   CostCentreStack *ccs;
308
309   /* Optimisation: if we attempt to append a CCS to itself, we're
310    * going to end up with the same ccs after a great deal of pushing
311    * and removing of cost centres.  Furthermore, we'll generate a lot
312    * of intermediate CCSs which would not otherwise be generated.  So:
313    * let's cope with this common case first.
314    */
315   if (ccs1 == ccs2) {
316     return ccs1;
317   }
318
319   if (ccs2->cc->is_subsumed != CC_IS_BORING) {
320     return ccs1;
321   }
322   
323   ASSERT(ccs2->prevStack != NULL);
324   ccs = AppendCCS(ccs1, ccs2->prevStack);
325   return PushCostCentre(ccs,ccs2->cc);
326 }
327
328 CostCentreStack *
329 ActualPush ( CostCentreStack *ccs, CostCentre *cc )
330 {
331   CostCentreStack *new_ccs;
332   
333   /* allocate space for a new CostCentreStack */
334   new_ccs = (CostCentreStack *) stgMallocBytes(sizeof(CostCentreStack), "Error allocating space for CostCentreStack");
335   
336   return ActualPush_(ccs, cc, new_ccs);
337 }
338
339 static CostCentreStack *
340 ActualPush_ ( CostCentreStack *ccs, CostCentre *cc, CostCentreStack *new_ccs )
341 {
342   /* assign values to each member of the structure */
343   ASSIGN_CCS_ID(new_ccs->ccsID);
344   
345   new_ccs->cc = cc;
346   new_ccs->prevStack = ccs;
347   
348   new_ccs->indexTable = EMPTY_TABLE;
349   
350   /* Initialise the various _scc_ counters to zero
351    */
352   new_ccs->scc_count        = 0;
353   new_ccs->sub_scc_count    = 0;
354   new_ccs->sub_cafcc_count  = 0;
355   
356   /* Initialize all other stats here.  There should be a quick way
357    * that's easily used elsewhere too 
358    */
359   new_ccs->time_ticks = 0;
360   new_ccs->mem_alloc = 0;
361   
362   /* stacks are subsumed if either:
363        - the top cost centre is boring, and the rest of the CCS is subsumed
364        - the top cost centre is subsumed.
365   */
366   if (cc->is_subsumed == CC_IS_BORING) {
367     new_ccs->is_subsumed = ccs->is_subsumed;
368   } else {
369     new_ccs->is_subsumed = cc->is_subsumed;
370   }
371   
372   /* update the memoization table for the parent stack */
373   if (ccs != EMPTY_STACK)
374     ccs->indexTable = AddToIndexTable(ccs->indexTable, new_ccs, cc);
375   
376   /* make sure this CC is declared at the next heap/time sample */
377   DecCCS(new_ccs);
378   
379   /* return a pointer to the new stack */
380   return new_ccs;
381 }
382
383
384 CostCentreStack *
385 RemoveCC(CostCentreStack *ccs, CostCentre *cc)
386 {
387   CostCentreStack *del_ccs;
388   
389   if (ccs == EMPTY_STACK) {
390     return EMPTY_STACK;
391   } else {
392     if (ccs->cc == cc) {
393       return ccs->prevStack;
394     } else {
395       {
396         del_ccs = RemoveCC(ccs->prevStack, cc); 
397         
398         if (del_ccs == EMPTY_STACK)
399           return ccs;
400         else
401           return PushCostCentre(del_ccs,ccs->cc);
402       }
403     }
404   }
405 }
406
407
408 CostCentreStack *
409 IsInIndexTable(IndexTable *it, CostCentre *cc)
410 {
411   while (it!=EMPTY_TABLE)
412     {
413       if (it->cc==cc)
414         return it->ccs;
415       else
416         it = it->next;
417     }
418   
419   /* otherwise we never found it so return EMPTY_TABLE */
420   return EMPTY_TABLE;
421 }
422
423
424 IndexTable *
425 AddToIndexTable(IndexTable *it, CostCentreStack *new_ccs, CostCentre *cc)
426 {
427   IndexTable *new_it;
428   
429   new_it = stgMallocBytes(sizeof(IndexTable), "AddToIndexTable");
430   
431   new_it->cc = cc;
432   new_it->ccs = new_ccs;
433   new_it->next = it;
434   return new_it;
435 }
436
437
438 void
439 print_ccs (FILE *fp, CostCentreStack *ccs)
440 {
441   if (ccs == CCCS) {
442     fprintf(fp, "Cost-Centre Stack: ");
443   }
444   
445   if (ccs != CCS_MAIN)
446     {
447       print_ccs(fp, ccs->prevStack);
448       fprintf(fp, "->[%s,%s,%s]", 
449               ccs->cc->label, ccs->cc->module, ccs->cc->group);
450     } else {
451       fprintf(fp, "[%s,%s,%s]", 
452               ccs->cc->label, ccs->cc->module, ccs->cc->group);
453     }
454       
455   if (ccs == CCCS) {
456     fprintf(fp, "\n");
457   }
458 }
459
460
461 static void
462 DecCCS(CostCentreStack *ccs)
463 {
464    CCSDecList *temp_list;
465         
466    temp_list = 
467      (CCSDecList *) stgMallocBytes(sizeof(CCSDecList), 
468                                    "Error allocating space for CCSDecList");
469    temp_list->ccs = ccs;
470    temp_list->nextList = New_CCS_LIST;
471    
472    New_CCS_LIST = temp_list;
473 }
474
475 /* -----------------------------------------------------------------------------
476    Generating a time & allocation profiling report.
477    -------------------------------------------------------------------------- */
478
479 static FILE *prof_file;
480
481 void
482 report_ccs_profiling( void )
483 {
484     nat count;
485     char temp[128]; /* sigh: magic constant */
486     rtsBool do_groups = rtsFalse;
487
488     if (!RtsFlags.CcFlags.doCostCentres)
489         return;
490
491     stopProfTimer();
492
493     total_ticks = 0;
494     total_alloc = 0;
495     count_ticks(CCS_MAIN);
496     
497     /* open profiling output file */
498     if ((prof_file = fopen(prof_filename, "w")) == NULL) {
499         fprintf(stderr, "Can't open profiling report file %s\n", prof_filename);
500         return;
501     }
502     fprintf(prof_file, "\t%s Time and Allocation Profiling Report  (%s)\n", 
503             time_str(), "Final");
504
505     fprintf(prof_file, "\n\t  ");
506     fprintf(prof_file, " %s", prog_argv[0]);
507     fprintf(prof_file, " +RTS");
508     for (count = 0; rts_argv[count]; count++)
509         fprintf(prof_file, " %s", rts_argv[count]);
510     fprintf(prof_file, " -RTS");
511     for (count = 1; prog_argv[count]; count++)
512         fprintf(prof_file, " %s", prog_argv[count]);
513     fprintf(prof_file, "\n\n");
514
515     fprintf(prof_file, "\ttotal time  = %11.2f secs   (%lu ticks @ %d ms)\n",
516             total_ticks / (StgFloat) TICK_FREQUENCY, 
517             total_ticks, TICK_MILLISECS);
518
519     fprintf(prof_file, "\ttotal alloc = %11s bytes",
520             ullong_format_string((ullong) total_alloc * sizeof(W_),
521                                  temp, rtsTrue/*commas*/));
522     /* ToDo: 64-bit error! */
523
524 #if defined(PROFILING_DETAIL_COUNTS)
525     fprintf(prof_file, "  (%lu closures)", total_allocs);
526 #endif
527     fprintf(prof_file, "  (excludes profiling overheads)\n\n");
528
529     fprintf(prof_file, "%-24s %-10s", "COST CENTRE", "MODULE");
530
531 #ifdef NOT_YET
532     do_groups = have_interesting_groups(Registered_CC);
533     if (do_groups) fprintf(prof_file, " %-11.11s", "GROUP");
534 #endif
535
536     fprintf(prof_file, "%8s %5s %5s %8s %5s", "scc", "%time", "%alloc", "inner", "cafs");
537
538     if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
539         fprintf(prof_file, "  %5s %9s", "ticks", "bytes");
540 #if defined(PROFILING_DETAIL_COUNTS)
541         fprintf(prof_file, "  %8s %8s %8s %8s %8s %8s %8s",
542                 "closures", "thunks", "funcs", "PAPs", "subfuns", "subcafs", "cafssub");
543 #endif
544     }
545     fprintf(prof_file, "\n\n");
546
547     reportCCS(pruneCCSTree(CCS_MAIN), 0);
548
549     fclose(prof_file);
550 }
551
552 static void 
553 reportCCS(CostCentreStack *ccs, nat indent)
554 {
555   CostCentre *cc;
556   IndexTable *i;
557
558   cc = ccs->cc;
559   ASSERT(cc == CC_MAIN || cc->link != 0);
560   
561   /* Only print cost centres with non 0 data ! */
562   
563   if ( RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_ALL ||
564        ! ccs_to_ignore(ccs))
565         /* force printing of *all* cost centres if -P -P */ 
566     {
567
568     fprintf(prof_file, "%-*s%-*s %-10s", 
569             indent, "", 24-indent, cc->label, cc->module);
570
571 #ifdef NOT_YET
572     if (do_groups) fprintf(prof_file, " %-11.11s",cc->group);
573 #endif
574
575     fprintf(prof_file, "%8ld  %4.1f  %4.1f %8ld %5ld",
576             ccs->scc_count, 
577             total_ticks == 0 ? 0.0 : (ccs->time_ticks / (StgFloat) total_ticks * 100),
578             total_alloc == 0 ? 0.0 : (ccs->mem_alloc / (StgFloat) total_alloc * 100),
579             ccs->sub_scc_count, ccs->sub_cafcc_count);
580     
581     if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
582       fprintf(prof_file, "  %5ld %9ld", ccs->time_ticks, ccs->mem_alloc*sizeof(W_));
583 #if defined(PROFILING_DETAIL_COUNTS)
584       fprintf(prof_file, "  %8ld %8ld %8ld %8ld %8ld %8ld %8ld",
585               ccs->mem_allocs, ccs->thunk_count,
586               ccs->function_count, ccs->pap_count,
587               ccs->subsumed_fun_count,  ccs->subsumed_caf_count,
588               ccs->caffun_subsumed);
589 #endif
590     }
591     fprintf(prof_file, "\n");
592   }
593
594   for (i = ccs->indexTable; i != 0; i = i->next) {
595     reportCCS(i->ccs, indent+1);
596   }
597 }
598
599 /* Traverse the cost centre stack tree and accumulate
600  * ticks/allocations.
601  */
602 static void
603 count_ticks(CostCentreStack *ccs)
604 {
605   IndexTable *i;
606   
607   if (!ccs_to_ignore(ccs)) {
608     total_alloc += ccs->mem_alloc;
609     total_ticks += ccs->time_ticks;
610   }
611   for (i = ccs->indexTable; i != NULL; i = i->next)
612     count_ticks(i->ccs);
613 }
614
615 /* return rtsTrue if it is one of the ones that
616  * should not be reported normally (because it confuses
617  * the users)
618  */
619 static rtsBool
620 ccs_to_ignore (CostCentreStack *ccs)
621 {
622     if (    ccs == CCS_OVERHEAD 
623          || ccs == CCS_DONTZuCARE
624          || ccs == CCS_GC 
625          || ccs == CCS_SYSTEM) {
626         return rtsTrue;
627     } else {
628         return rtsFalse;
629     }
630 }
631
632 static CostCentreStack *
633 pruneCCSTree( CostCentreStack *ccs )
634 {
635   CostCentreStack *ccs1;
636   IndexTable *i, **prev;
637   
638   prev = &ccs->indexTable;
639   for (i = ccs->indexTable; i != 0; i = i->next) {
640     ccs1 = pruneCCSTree(i->ccs);
641     if (ccs1 == NULL) {
642       *prev = i->next;
643     } else {
644       prev = &(i->next);
645     }
646   }
647
648   if ( (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_ALL
649         /* force printing of *all* cost centres if -P -P */ )
650        
651        || ( ccs->indexTable != 0 )
652        || ( (ccs->scc_count || ccs->sub_scc_count || 
653              ccs->time_ticks || ccs->mem_alloc
654              || (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE
655                  && (ccs->sub_cafcc_count
656 #if defined(PROFILING_DETAIL_COUNTS)
657                      || cc->thunk_count || cc->function_count || cc->pap_count
658 #endif
659                      ))))) {
660     return ccs;
661   } else {
662     return NULL;
663   }
664 }
665
666 #ifdef DEBUG
667 static void
668 printCCS ( CostCentreStack *ccs )
669 {
670   fprintf(stderr,"<");
671   for (; ccs; ccs = ccs->prevStack ) {
672     fprintf(stderr,ccs->cc->label);
673     if (ccs->prevStack) {
674       fprintf(stderr,",");
675     }
676   }
677   fprintf(stderr,">");
678 }
679 #endif
680
681 #endif /* PROFILING */