[project @ 1999-03-25 13:13:51 by simonm]
[ghc-hetmet.git] / ghc / rts / Profiling.c
1 /* -----------------------------------------------------------------------------
2  * $Id: Profiling.c,v 1.4 1999/03/25 13:14:06 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            fprintf(stderr,"Appending ");
295            printCCS(ccs1);
296            fprintf(stderr," to ");
297            printCCS(ccs2);
298            fprintf(stderr,"\n"));
299   return AppendCCS(ccs1,ccs2);
300 }
301 #endif
302
303 CostCentreStack *
304 AppendCCS ( CostCentreStack *ccs1, CostCentreStack *ccs2 )
305 {
306   CostCentreStack *ccs;
307
308   /* Optimisation: if we attempt to append a CCS to itself, we're
309    * going to end up with the same ccs after a great deal of pushing
310    * and removing of cost centres.  Furthermore, we'll generate a lot
311    * of intermediate CCSs which would not otherwise be generated.  So:
312    * let's cope with this common case first.
313    */
314   if (ccs1 == ccs2) {
315     return ccs1;
316   }
317
318   if (ccs2->cc->is_subsumed != CC_IS_BORING) {
319     return ccs1;
320   }
321   
322   ASSERT(ccs2->prevStack != NULL);
323   ccs = AppendCCS(ccs1, ccs2->prevStack);
324   return PushCostCentre(ccs,ccs2->cc);
325 }
326
327 CostCentreStack *
328 ActualPush ( CostCentreStack *ccs, CostCentre *cc )
329 {
330   CostCentreStack *new_ccs;
331   
332   /* allocate space for a new CostCentreStack */
333   new_ccs = (CostCentreStack *) stgMallocBytes(sizeof(CostCentreStack), "Error allocating space for CostCentreStack");
334   
335   return ActualPush_(ccs, cc, new_ccs);
336 }
337
338 static CostCentreStack *
339 ActualPush_ ( CostCentreStack *ccs, CostCentre *cc, CostCentreStack *new_ccs )
340 {
341   /* assign values to each member of the structure */
342   ASSIGN_CCS_ID(new_ccs->ccsID);
343   
344   new_ccs->cc = cc;
345   new_ccs->prevStack = ccs;
346   
347   new_ccs->indexTable = EMPTY_TABLE;
348   
349   /* Initialise the various _scc_ counters to zero
350    */
351   new_ccs->scc_count        = 0;
352   new_ccs->sub_scc_count    = 0;
353   new_ccs->sub_cafcc_count  = 0;
354   
355   /* Initialize all other stats here.  There should be a quick way
356    * that's easily used elsewhere too 
357    */
358   new_ccs->time_ticks = 0;
359   new_ccs->mem_alloc = 0;
360   
361   /* stacks are subsumed if either:
362        - the top cost centre is boring, and the rest of the CCS is subsumed
363        - the top cost centre is subsumed.
364   */
365   if (cc->is_subsumed == CC_IS_BORING) {
366     new_ccs->is_subsumed = ccs->is_subsumed;
367   } else {
368     new_ccs->is_subsumed = cc->is_subsumed;
369   }
370   
371   /* update the memoization table for the parent stack */
372   if (ccs != EMPTY_STACK)
373     ccs->indexTable = AddToIndexTable(ccs->indexTable, new_ccs, cc);
374   
375   /* make sure this CC is declared at the next heap/time sample */
376   DecCCS(new_ccs);
377   
378   /* return a pointer to the new stack */
379   return new_ccs;
380 }
381
382
383 CostCentreStack *
384 RemoveCC(CostCentreStack *ccs, CostCentre *cc)
385 {
386   CostCentreStack *del_ccs;
387   
388   if (ccs == EMPTY_STACK) {
389     return EMPTY_STACK;
390   } else {
391     if (ccs->cc == cc) {
392       return ccs->prevStack;
393     } else {
394       {
395         del_ccs = RemoveCC(ccs->prevStack, cc); 
396         
397         if (del_ccs == EMPTY_STACK)
398           return ccs;
399         else
400           return PushCostCentre(del_ccs,ccs->cc);
401       }
402     }
403   }
404 }
405
406
407 CostCentreStack *
408 IsInIndexTable(IndexTable *it, CostCentre *cc)
409 {
410   while (it!=EMPTY_TABLE)
411     {
412       if (it->cc==cc)
413         return it->ccs;
414       else
415         it = it->next;
416     }
417   
418   /* otherwise we never found it so return EMPTY_TABLE */
419   return EMPTY_TABLE;
420 }
421
422
423 IndexTable *
424 AddToIndexTable(IndexTable *it, CostCentreStack *new_ccs, CostCentre *cc)
425 {
426   IndexTable *new_it;
427   
428   new_it = stgMallocBytes(sizeof(IndexTable), "AddToIndexTable");
429   
430   new_it->cc = cc;
431   new_it->ccs = new_ccs;
432   new_it->next = it;
433   return new_it;
434 }
435
436
437 void
438 print_ccs (FILE *fp, CostCentreStack *ccs)
439 {
440   if (ccs == CCCS) {
441     fprintf(fp, "Cost-Centre Stack: ");
442   }
443   
444   if (ccs != CCS_MAIN)
445     {
446       print_ccs(fp, ccs->prevStack);
447       fprintf(fp, "->[%s,%s,%s]", 
448               ccs->cc->label, ccs->cc->module, ccs->cc->group);
449     } else {
450       fprintf(fp, "[%s,%s,%s]", 
451               ccs->cc->label, ccs->cc->module, ccs->cc->group);
452     }
453       
454   if (ccs == CCCS) {
455     fprintf(fp, "\n");
456   }
457 }
458
459
460 static void
461 DecCCS(CostCentreStack *ccs)
462 {
463    CCSDecList *temp_list;
464         
465    temp_list = 
466      (CCSDecList *) stgMallocBytes(sizeof(CCSDecList), 
467                                    "Error allocating space for CCSDecList");
468    temp_list->ccs = ccs;
469    temp_list->nextList = New_CCS_LIST;
470    
471    New_CCS_LIST = temp_list;
472 }
473
474 /* -----------------------------------------------------------------------------
475    Generating a time & allocation profiling report.
476    -------------------------------------------------------------------------- */
477
478 static FILE *prof_file;
479
480 void
481 report_ccs_profiling( void )
482 {
483     nat count;
484     char temp[128]; /* sigh: magic constant */
485     rtsBool do_groups = rtsFalse;
486
487     if (!RtsFlags.CcFlags.doCostCentres)
488         return;
489
490     stopProfTimer();
491
492     total_ticks = 0;
493     total_alloc = 0;
494     count_ticks(CCS_MAIN);
495     
496     /* open profiling output file */
497     if ((prof_file = fopen(prof_filename, "w")) == NULL) {
498         fprintf(stderr, "Can't open profiling report file %s\n", prof_filename);
499         return;
500     }
501     fprintf(prof_file, "\t%s Time and Allocation Profiling Report  (%s)\n", 
502             time_str(), "Final");
503
504     fprintf(prof_file, "\n\t  ");
505     fprintf(prof_file, " %s", prog_argv[0]);
506     fprintf(prof_file, " +RTS");
507     for (count = 0; rts_argv[count]; count++)
508         fprintf(prof_file, " %s", rts_argv[count]);
509     fprintf(prof_file, " -RTS");
510     for (count = 1; prog_argv[count]; count++)
511         fprintf(prof_file, " %s", prog_argv[count]);
512     fprintf(prof_file, "\n\n");
513
514     fprintf(prof_file, "\ttotal time  = %11.2f secs   (%lu ticks @ %d ms)\n",
515             total_ticks / (StgFloat) TICK_FREQUENCY, 
516             total_ticks, TICK_MILLISECS);
517
518     fprintf(prof_file, "\ttotal alloc = %11s bytes",
519             ullong_format_string((ullong) total_alloc * sizeof(W_),
520                                  temp, rtsTrue/*commas*/));
521     /* ToDo: 64-bit error! */
522
523 #if defined(PROFILING_DETAIL_COUNTS)
524     fprintf(prof_file, "  (%lu closures)", total_allocs);
525 #endif
526     fprintf(prof_file, "  (excludes profiling overheads)\n\n");
527
528     fprintf(prof_file, "%-24s %-10s", "COST CENTRE", "MODULE");
529
530 #ifdef NOT_YET
531     do_groups = have_interesting_groups(Registered_CC);
532     if (do_groups) fprintf(prof_file, " %-11.11s", "GROUP");
533 #endif
534
535     fprintf(prof_file, "%8s %5s %5s %8s %5s", "scc", "%time", "%alloc", "inner", "cafs");
536
537     if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
538         fprintf(prof_file, "  %5s %9s", "ticks", "bytes");
539 #if defined(PROFILING_DETAIL_COUNTS)
540         fprintf(prof_file, "  %8s %8s %8s %8s %8s %8s %8s",
541                 "closures", "thunks", "funcs", "PAPs", "subfuns", "subcafs", "cafssub");
542 #endif
543     }
544     fprintf(prof_file, "\n\n");
545
546     reportCCS(pruneCCSTree(CCS_MAIN), 0);
547
548     fclose(prof_file);
549 }
550
551 static void 
552 reportCCS(CostCentreStack *ccs, nat indent)
553 {
554   CostCentre *cc;
555   IndexTable *i;
556
557   cc = ccs->cc;
558   ASSERT(cc == CC_MAIN || cc->link != 0);
559   
560   /* Only print cost centres with non 0 data ! */
561   
562   if ( RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_ALL ||
563        ! ccs_to_ignore(ccs))
564         /* force printing of *all* cost centres if -P -P */ 
565     {
566
567     fprintf(prof_file, "%-*s%-*s %-10s", 
568             indent, "", 24-indent, cc->label, cc->module);
569
570 #ifdef NOT_YET
571     if (do_groups) fprintf(prof_file, " %-11.11s",cc->group);
572 #endif
573
574     fprintf(prof_file, "%8ld  %4.1f  %4.1f %8ld %5ld",
575             ccs->scc_count, 
576             total_ticks == 0 ? 0.0 : (ccs->time_ticks / (StgFloat) total_ticks * 100),
577             total_alloc == 0 ? 0.0 : (ccs->mem_alloc / (StgFloat) total_alloc * 100),
578             ccs->sub_scc_count, ccs->sub_cafcc_count);
579     
580     if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
581       fprintf(prof_file, "  %5ld %9ld", ccs->time_ticks, ccs->mem_alloc*sizeof(W_));
582 #if defined(PROFILING_DETAIL_COUNTS)
583       fprintf(prof_file, "  %8ld %8ld %8ld %8ld %8ld %8ld %8ld",
584               ccs->mem_allocs, ccs->thunk_count,
585               ccs->function_count, ccs->pap_count,
586               ccs->subsumed_fun_count,  ccs->subsumed_caf_count,
587               ccs->caffun_subsumed);
588 #endif
589     }
590     fprintf(prof_file, "\n");
591   }
592
593   for (i = ccs->indexTable; i != 0; i = i->next) {
594     reportCCS(i->ccs, indent+1);
595   }
596 }
597
598 /* Traverse the cost centre stack tree and accumulate
599  * ticks/allocations.
600  */
601 static void
602 count_ticks(CostCentreStack *ccs)
603 {
604   IndexTable *i;
605   
606   if (!ccs_to_ignore(ccs)) {
607     total_alloc += ccs->mem_alloc;
608     total_ticks += ccs->time_ticks;
609   }
610   for (i = ccs->indexTable; i != NULL; i = i->next)
611     count_ticks(i->ccs);
612 }
613
614 /* return rtsTrue if it is one of the ones that
615  * should not be reported normally (because it confuses
616  * the users)
617  */
618 static rtsBool
619 ccs_to_ignore (CostCentreStack *ccs)
620 {
621     if (    ccs == CCS_OVERHEAD 
622          || ccs == CCS_DONTZuCARE
623          || ccs == CCS_GC 
624          || ccs == CCS_SYSTEM) {
625         return rtsTrue;
626     } else {
627         return rtsFalse;
628     }
629 }
630
631 static CostCentreStack *
632 pruneCCSTree( CostCentreStack *ccs )
633 {
634   CostCentreStack *ccs1;
635   IndexTable *i, **prev;
636   
637   prev = &ccs->indexTable;
638   for (i = ccs->indexTable; i != 0; i = i->next) {
639     ccs1 = pruneCCSTree(i->ccs);
640     if (ccs1 == NULL) {
641       *prev = i->next;
642     } else {
643       prev = &(i->next);
644     }
645   }
646
647   if ( (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_ALL
648         /* force printing of *all* cost centres if -P -P */ )
649        
650        || ( ccs->indexTable != 0 )
651        || ( (ccs->scc_count || ccs->sub_scc_count || 
652              ccs->time_ticks || ccs->mem_alloc
653              || (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE
654                  && (ccs->sub_cafcc_count
655 #if defined(PROFILING_DETAIL_COUNTS)
656                      || cc->thunk_count || cc->function_count || cc->pap_count
657 #endif
658                      ))))) {
659     return ccs;
660   } else {
661     return NULL;
662   }
663 }
664
665 #ifdef DEBUG
666 static void
667 printCCS ( CostCentreStack *ccs )
668 {
669   fprintf(stderr,"<");
670   for (; ccs; ccs = ccs->prevStack ) {
671     fprintf(stderr,ccs->cc->label);
672     if (ccs->prevStack) {
673       fprintf(stderr,",");
674     }
675   }
676   fprintf(stderr,">");
677 }
678 #endif
679
680 #endif /* PROFILING */