JSON profiler reports
[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 insertCCInSortedList( CostCentre *new_cc )
94 {
95 CostCentre **prev, *cc;
96
97 prev = &sorted_cc_list;
98 for (cc = sorted_cc_list; cc != NULL; cc = cc->link) {
99 if (new_cc->time_ticks > cc->time_ticks) {
100 new_cc->link = cc;
101 *prev = new_cc;
102 return;
103 } else {
104 prev = &(cc->link);
105 }
106 }
107 new_cc->link = NULL;
108 *prev = new_cc;
109 }
110
111
112 static void
113 reportPerCCCosts( FILE *prof_file, ProfilerTotals totals )
114 {
115 CostCentre *cc, *next;
116 uint32_t max_label_len, max_module_len, max_src_len;
117
118 sorted_cc_list = NULL;
119
120 max_label_len = 11; // no shorter than the "COST CENTRE" header
121 max_module_len = 6; // no shorter than the "MODULE" header
122 max_src_len = 3; // no shorter than the "SRC" header
123
124 for (cc = CC_LIST; cc != NULL; cc = next) {
125 next = cc->link;
126 if (cc->time_ticks > totals.total_prof_ticks/100
127 || cc->mem_alloc > totals.total_alloc/100
128 || RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_ALL) {
129 insertCCInSortedList(cc);
130
131 max_label_len = stg_max(strlen_utf8(cc->label), max_label_len);
132 max_module_len = stg_max(strlen_utf8(cc->module), max_module_len);
133 max_src_len = stg_max(strlen_utf8(cc->srcloc), max_src_len);
134 }
135 }
136
137 fprintf(prof_file, "%-*s %-*s %-*s",
138 max_label_len, "COST CENTRE", max_module_len, "MODULE", max_src_len, "SRC");
139 fprintf(prof_file, " %6s %6s", "%time", "%alloc");
140 if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
141 fprintf(prof_file, " %5s %9s", "ticks", "bytes");
142 }
143 fprintf(prof_file, "\n\n");
144
145 for (cc = sorted_cc_list; cc != NULL; cc = cc->link) {
146 if (ignoreCC(cc)) {
147 continue;
148 }
149 fprintf(prof_file, "%s%*s %s%*s %s%*s",
150 cc->label,
151 max_label_len - strlen_utf8(cc->label), "",
152 cc->module,
153 max_module_len - strlen_utf8(cc->module), "",
154 cc->srcloc,
155 max_src_len - strlen_utf8(cc->srcloc), "");
156
157 fprintf(prof_file, " %6.1f %6.1f",
158 totals.total_prof_ticks == 0 ? 0.0 : (cc->time_ticks / (StgFloat) totals.total_prof_ticks * 100),
159 totals.total_alloc == 0 ? 0.0 : (cc->mem_alloc / (StgFloat) totals.total_alloc * 100)
160 );
161
162 if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
163 fprintf(prof_file, " %5" FMT_Word64 " %9" FMT_Word64,
164 (StgWord64)(cc->time_ticks), cc->mem_alloc*sizeof(W_));
165 }
166 fprintf(prof_file, "\n");
167 }
168
169 fprintf(prof_file,"\n\n");
170 }
171
172 static uint32_t
173 numDigits(StgInt i) {
174 uint32_t result;
175
176 result = 1;
177
178 if (i < 0) i = 0;
179
180 while (i > 9) {
181 i /= 10;
182 result++;
183 }
184
185 return result;
186 }
187
188 static void
189 findCCSMaxLens(CostCentreStack const *ccs, uint32_t indent, uint32_t *max_label_len,
190 uint32_t *max_module_len, uint32_t *max_src_len, uint32_t *max_id_len) {
191 CostCentre *cc;
192 IndexTable *i;
193
194 cc = ccs->cc;
195
196 *max_label_len = stg_max(*max_label_len, indent + strlen_utf8(cc->label));
197 *max_module_len = stg_max(*max_module_len, strlen_utf8(cc->module));
198 *max_src_len = stg_max(*max_src_len, strlen_utf8(cc->srcloc));
199 *max_id_len = stg_max(*max_id_len, numDigits(ccs->ccsID));
200
201 for (i = ccs->indexTable; i != 0; i = i->next) {
202 if (!i->back_edge) {
203 findCCSMaxLens(i->ccs, indent+1,
204 max_label_len, max_module_len, max_src_len, max_id_len);
205 }
206 }
207 }
208
209 static void
210 logCCS(FILE *prof_file, CostCentreStack const *ccs, ProfilerTotals totals,
211 uint32_t indent,
212 uint32_t max_label_len, uint32_t max_module_len,
213 uint32_t max_src_len, uint32_t max_id_len)
214 {
215 CostCentre *cc;
216 IndexTable *i;
217
218 cc = ccs->cc;
219
220 /* Only print cost centres with non 0 data ! */
221
222 if (!ignoreCCS(ccs))
223 /* force printing of *all* cost centres if -Pa */
224 {
225
226 fprintf(prof_file, "%*s%s%*s %s%*s %s%*s",
227 indent, "",
228 cc->label,
229 max_label_len-indent - strlen_utf8(cc->label), "",
230 cc->module,
231 max_module_len - strlen_utf8(cc->module), "",
232 cc->srcloc,
233 max_src_len - strlen_utf8(cc->srcloc), "");
234
235 fprintf(prof_file,
236 " %*" FMT_Int "%11" FMT_Word64 " %5.1f %5.1f %5.1f %5.1f",
237 max_id_len, ccs->ccsID, ccs->scc_count,
238 totals.total_prof_ticks == 0 ? 0.0 : ((double)ccs->time_ticks / (double)totals.total_prof_ticks * 100.0),
239 totals.total_alloc == 0 ? 0.0 : ((double)ccs->mem_alloc / (double)totals.total_alloc * 100.0),
240 totals.total_prof_ticks == 0 ? 0.0 : ((double)ccs->inherited_ticks / (double)totals.total_prof_ticks * 100.0),
241 totals.total_alloc == 0 ? 0.0 : ((double)ccs->inherited_alloc / (double)totals.total_alloc * 100.0)
242 );
243
244 if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
245 fprintf(prof_file, " %5" FMT_Word64 " %9" FMT_Word64,
246 (StgWord64)(ccs->time_ticks), ccs->mem_alloc*sizeof(W_));
247 }
248 fprintf(prof_file, "\n");
249 }
250
251 for (i = ccs->indexTable; i != 0; i = i->next) {
252 if (!i->back_edge) {
253 logCCS(prof_file, i->ccs, totals, indent+1,
254 max_label_len, max_module_len, max_src_len, max_id_len);
255 }
256 }
257 }
258
259 static void
260 reportCCS(FILE *prof_file, CostCentreStack const *ccs, ProfilerTotals totals)
261 {
262 uint32_t max_label_len, max_module_len, max_src_len, max_id_len;
263
264 max_label_len = 11; // no shorter than "COST CENTRE" header
265 max_module_len = 6; // no shorter than "MODULE" header
266 max_src_len = 3; // no shorter than "SRC" header
267 max_id_len = 3; // no shorter than "no." header
268
269 findCCSMaxLens(ccs, 0,
270 &max_label_len, &max_module_len, &max_src_len, &max_id_len);
271
272 fprintHeader(prof_file,
273 max_label_len, max_module_len, max_src_len, max_id_len);
274 logCCS(prof_file, ccs, totals, 0,
275 max_label_len, max_module_len, max_src_len, max_id_len);
276 }
277
278 void
279 writeCCSReport( FILE *prof_file, CostCentreStack const *stack,
280 ProfilerTotals totals )
281 {
282 char temp[128]; /* sigh: magic constant */
283
284 fprintf(prof_file, "\t%s Time and Allocation Profiling Report (%s)\n",
285 time_str(), "Final");
286
287 fprintf(prof_file, "\n\t ");
288 fprintf(prof_file, " %s", prog_name);
289 fprintf(prof_file, " +RTS");
290 for (int count = 0; rts_argv[count]; count++)
291 fprintf(prof_file, " %s", rts_argv[count]);
292 fprintf(prof_file, " -RTS");
293 for (int count = 1; prog_argv[count]; count++)
294 fprintf(prof_file, " %s", prog_argv[count]);
295 fprintf(prof_file, "\n\n");
296
297 fprintf(prof_file, "\ttotal time = %11.2f secs (%lu ticks @ %d us, %d processor%s)\n",
298 ((double) totals.total_prof_ticks *
299 (double) RtsFlags.MiscFlags.tickInterval) / (TIME_RESOLUTION * n_capabilities),
300 (unsigned long) totals.total_prof_ticks,
301 (int) TimeToUS(RtsFlags.MiscFlags.tickInterval),
302 n_capabilities, n_capabilities > 1 ? "s" : "");
303
304 fprintf(prof_file, "\ttotal alloc = %11s bytes",
305 showStgWord64(totals.total_alloc * sizeof(W_),
306 temp, true/*commas*/));
307
308 fprintf(prof_file, " (excludes profiling overheads)\n\n");
309
310 reportPerCCCosts(prof_file, totals);
311 reportCCS(prof_file, stack, totals);
312 }
313
314
315 #endif /* PROFILING */