rts/Profiling: Factor out report generation
[ghc.git] / rts / ProfilerReport.c
1 /* -----------------------------------------------------------------------------
2 *
3 * (c) The GHC Team, 1998-2017
4 *
5 * Generating cost-center profiler report
6 *
7 * ---------------------------------------------------------------------------*/
8
9 #ifdef PROFILING
10
11 #include "PosixSource.h"
12 #include "Rts.h"
13
14 #include "RtsUtils.h"
15 #include "ProfilerReport.h"
16 #include "Profiling.h"
17
18 static uint32_t numDigits ( StgInt i );
19 static void findCCSMaxLens ( CostCentreStack const *ccs,
20 uint32_t indent,
21 uint32_t *max_label_len,
22 uint32_t *max_module_len,
23 uint32_t *max_src_len,
24 uint32_t *max_id_len );
25 static void logCCS ( FILE *prof_file,
26 CostCentreStack const *ccs,
27 ProfilerTotals totals,
28 uint32_t indent,
29 uint32_t max_label_len,
30 uint32_t max_module_len,
31 uint32_t max_src_len,
32 uint32_t max_id_len );
33 static void fprintHeader ( FILE *prof_file,
34 uint32_t max_label_len, uint32_t max_module_len,
35 uint32_t max_src_len, uint32_t max_id_len );
36 static void reportCCS ( FILE *prof_file, CostCentreStack const *ccs,
37 ProfilerTotals totals );
38
39 static uint32_t
40 strlen_utf8 (char *s)
41 {
42 uint32_t n = 0;
43 unsigned char c;
44
45 for (; *s != '\0'; s++) {
46 c = *s;
47 if (c < 0x80 || c > 0xBF) n++;
48 }
49 return n;
50 }
51
52 /* -----------------------------------------------------------------------------
53 Generate the cost-centre-stack time/alloc report
54 -------------------------------------------------------------------------- */
55
56 static void
57 fprintHeader( FILE *prof_file, uint32_t max_label_len, uint32_t max_module_len,
58 uint32_t max_src_len, uint32_t max_id_len )
59 {
60 fprintf(prof_file, "%-*s %-*s %-*s %-*s %11s %12s %12s\n",
61 max_label_len, "",
62 max_module_len, "",
63 max_src_len, "",
64 max_id_len, "",
65 "", "individual", "inherited");
66
67 fprintf(prof_file, "%-*s %-*s %-*s %-*s",
68 max_label_len, "COST CENTRE",
69 max_module_len, "MODULE",
70 max_src_len, "SRC",
71 max_id_len, "no.");
72
73 fprintf(prof_file, " %11s %5s %6s %5s %6s",
74 "entries", "%time", "%alloc", "%time", "%alloc");
75
76 if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
77 fprintf(prof_file, " %5s %9s", "ticks", "bytes");
78 }
79
80 fprintf(prof_file, "\n\n");
81 }
82
83
84 /* -----------------------------------------------------------------------------
85 Generating the aggregated per-cost-centre time/alloc report.
86
87 This is the sorted list of cost centers appearing at the top of the output.
88 -------------------------------------------------------------------------- */
89
90 static CostCentre *sorted_cc_list;
91
92 static void
93 aggregateCCCosts( CostCentreStack *ccs )
94 {
95 IndexTable *i;
96
97 ccs->cc->mem_alloc += ccs->mem_alloc;
98 ccs->cc->time_ticks += ccs->time_ticks;
99
100 for (i = ccs->indexTable; i != 0; i = i->next) {
101 if (!i->back_edge) {
102 aggregateCCCosts(i->ccs);
103 }
104 }
105 }
106
107 static void
108 insertCCInSortedList( CostCentre *new_cc )
109 {
110 CostCentre **prev, *cc;
111
112 prev = &sorted_cc_list;
113 for (cc = sorted_cc_list; cc != NULL; cc = cc->link) {
114 if (new_cc->time_ticks > cc->time_ticks) {
115 new_cc->link = cc;
116 *prev = new_cc;
117 return;
118 } else {
119 prev = &(cc->link);
120 }
121 }
122 new_cc->link = NULL;
123 *prev = new_cc;
124 }
125
126
127 static void
128 reportPerCCCosts( FILE *prof_file, ProfilerTotals totals )
129 {
130 CostCentre *cc, *next;
131 uint32_t max_label_len, max_module_len, max_src_len;
132
133 aggregateCCCosts(CCS_MAIN);
134 sorted_cc_list = NULL;
135
136 max_label_len = 11; // no shorter than the "COST CENTRE" header
137 max_module_len = 6; // no shorter than the "MODULE" header
138 max_src_len = 3; // no shorter than the "SRC" header
139
140 for (cc = CC_LIST; cc != NULL; cc = next) {
141 next = cc->link;
142 if (cc->time_ticks > totals.total_prof_ticks/100
143 || cc->mem_alloc > totals.total_alloc/100
144 || RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_ALL) {
145 insertCCInSortedList(cc);
146
147 max_label_len = stg_max(strlen_utf8(cc->label), max_label_len);
148 max_module_len = stg_max(strlen_utf8(cc->module), max_module_len);
149 max_src_len = stg_max(strlen_utf8(cc->srcloc), max_src_len);
150 }
151 }
152
153 fprintf(prof_file, "%-*s %-*s %-*s",
154 max_label_len, "COST CENTRE", max_module_len, "MODULE", max_src_len, "SRC");
155 fprintf(prof_file, " %6s %6s", "%time", "%alloc");
156 if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
157 fprintf(prof_file, " %5s %9s", "ticks", "bytes");
158 }
159 fprintf(prof_file, "\n\n");
160
161 for (cc = sorted_cc_list; cc != NULL; cc = cc->link) {
162 if (ignoreCC(cc)) {
163 continue;
164 }
165 fprintf(prof_file, "%s%*s %s%*s %s%*s",
166 cc->label,
167 max_label_len - strlen_utf8(cc->label), "",
168 cc->module,
169 max_module_len - strlen_utf8(cc->module), "",
170 cc->srcloc,
171 max_src_len - strlen_utf8(cc->srcloc), "");
172
173 fprintf(prof_file, " %6.1f %6.1f",
174 totals.total_prof_ticks == 0 ? 0.0 : (cc->time_ticks / (StgFloat) totals.total_prof_ticks * 100),
175 totals.total_alloc == 0 ? 0.0 : (cc->mem_alloc / (StgFloat) totals.total_alloc * 100)
176 );
177
178 if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
179 fprintf(prof_file, " %5" FMT_Word64 " %9" FMT_Word64,
180 (StgWord64)(cc->time_ticks), cc->mem_alloc*sizeof(W_));
181 }
182 fprintf(prof_file, "\n");
183 }
184
185 fprintf(prof_file,"\n\n");
186 }
187
188 static uint32_t
189 numDigits(StgInt i) {
190 uint32_t result;
191
192 result = 1;
193
194 if (i < 0) i = 0;
195
196 while (i > 9) {
197 i /= 10;
198 result++;
199 }
200
201 return result;
202 }
203
204 static void
205 findCCSMaxLens(CostCentreStack const *ccs, uint32_t indent, uint32_t *max_label_len,
206 uint32_t *max_module_len, uint32_t *max_src_len, uint32_t *max_id_len) {
207 CostCentre *cc;
208 IndexTable *i;
209
210 cc = ccs->cc;
211
212 *max_label_len = stg_max(*max_label_len, indent + strlen_utf8(cc->label));
213 *max_module_len = stg_max(*max_module_len, strlen_utf8(cc->module));
214 *max_src_len = stg_max(*max_src_len, strlen_utf8(cc->srcloc));
215 *max_id_len = stg_max(*max_id_len, numDigits(ccs->ccsID));
216
217 for (i = ccs->indexTable; i != 0; i = i->next) {
218 if (!i->back_edge) {
219 findCCSMaxLens(i->ccs, indent+1,
220 max_label_len, max_module_len, max_src_len, max_id_len);
221 }
222 }
223 }
224
225 static void
226 logCCS(FILE *prof_file, CostCentreStack const *ccs, ProfilerTotals totals,
227 uint32_t indent,
228 uint32_t max_label_len, uint32_t max_module_len,
229 uint32_t max_src_len, uint32_t max_id_len)
230 {
231 CostCentre *cc;
232 IndexTable *i;
233
234 cc = ccs->cc;
235
236 /* Only print cost centres with non 0 data ! */
237
238 if (!ignoreCCS(ccs))
239 /* force printing of *all* cost centres if -Pa */
240 {
241
242 fprintf(prof_file, "%*s%s%*s %s%*s %s%*s",
243 indent, "",
244 cc->label,
245 max_label_len-indent - strlen_utf8(cc->label), "",
246 cc->module,
247 max_module_len - strlen_utf8(cc->module), "",
248 cc->srcloc,
249 max_src_len - strlen_utf8(cc->srcloc), "");
250
251 fprintf(prof_file,
252 " %*" FMT_Int "%11" FMT_Word64 " %5.1f %5.1f %5.1f %5.1f",
253 max_id_len, ccs->ccsID, ccs->scc_count,
254 totals.total_prof_ticks == 0 ? 0.0 : ((double)ccs->time_ticks / (double)totals.total_prof_ticks * 100.0),
255 totals.total_alloc == 0 ? 0.0 : ((double)ccs->mem_alloc / (double)totals.total_alloc * 100.0),
256 totals.total_prof_ticks == 0 ? 0.0 : ((double)ccs->inherited_ticks / (double)totals.total_prof_ticks * 100.0),
257 totals.total_alloc == 0 ? 0.0 : ((double)ccs->inherited_alloc / (double)totals.total_alloc * 100.0)
258 );
259
260 if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
261 fprintf(prof_file, " %5" FMT_Word64 " %9" FMT_Word64,
262 (StgWord64)(ccs->time_ticks), ccs->mem_alloc*sizeof(W_));
263 }
264 fprintf(prof_file, "\n");
265 }
266
267 for (i = ccs->indexTable; i != 0; i = i->next) {
268 if (!i->back_edge) {
269 logCCS(prof_file, i->ccs, totals, indent+1,
270 max_label_len, max_module_len, max_src_len, max_id_len);
271 }
272 }
273 }
274
275 static void
276 reportCCS(FILE *prof_file, CostCentreStack const *ccs, ProfilerTotals totals)
277 {
278 uint32_t max_label_len, max_module_len, max_src_len, max_id_len;
279
280 max_label_len = 11; // no shorter than "COST CENTRE" header
281 max_module_len = 6; // no shorter than "MODULE" header
282 max_src_len = 3; // no shorter than "SRC" header
283 max_id_len = 3; // no shorter than "no." header
284
285 findCCSMaxLens(ccs, 0,
286 &max_label_len, &max_module_len, &max_src_len, &max_id_len);
287
288 fprintHeader(prof_file,
289 max_label_len, max_module_len, max_src_len, max_id_len);
290 logCCS(prof_file, ccs, totals, 0,
291 max_label_len, max_module_len, max_src_len, max_id_len);
292 }
293
294 void
295 writeCCSReport( FILE *prof_file, CostCentreStack const *stack,
296 ProfilerTotals totals )
297 {
298 char temp[128]; /* sigh: magic constant */
299
300 fprintf(prof_file, "\t%s Time and Allocation Profiling Report (%s)\n",
301 time_str(), "Final");
302
303 fprintf(prof_file, "\n\t ");
304 fprintf(prof_file, " %s", prog_name);
305 fprintf(prof_file, " +RTS");
306 for (int count = 0; rts_argv[count]; count++)
307 fprintf(prof_file, " %s", rts_argv[count]);
308 fprintf(prof_file, " -RTS");
309 for (int count = 1; prog_argv[count]; count++)
310 fprintf(prof_file, " %s", prog_argv[count]);
311 fprintf(prof_file, "\n\n");
312
313 fprintf(prof_file, "\ttotal time = %11.2f secs (%lu ticks @ %d us, %d processor%s)\n",
314 ((double) totals.total_prof_ticks *
315 (double) RtsFlags.MiscFlags.tickInterval) / (TIME_RESOLUTION * n_capabilities),
316 (unsigned long) totals.total_prof_ticks,
317 (int) TimeToUS(RtsFlags.MiscFlags.tickInterval),
318 n_capabilities, n_capabilities > 1 ? "s" : "");
319
320 fprintf(prof_file, "\ttotal alloc = %11s bytes",
321 showStgWord64(totals.total_alloc * sizeof(W_),
322 temp, true/*commas*/));
323
324 fprintf(prof_file, " (excludes profiling overheads)\n\n");
325
326 reportPerCCCosts(prof_file, totals);
327 reportCCS(prof_file, stack, totals);
328 }
329
330
331 #endif /* PROFILING */