CmmLayoutStack: Add unwind information on stack fixups
[ghc.git] / rts / Ticky.c
1 /* -----------------------------------------------------------------------------
2 *
3 * (c) The AQUA project, Glasgow University, 1992-1997
4 * (c) The GHC Team, 1998-1999
5 *
6 * Ticky-ticky profiling
7 *-------------------------------------------------------------------------- */
8
9 #define TICKY_C /* define those variables */
10 #include "PosixSource.h"
11 #include "Rts.h"
12
13 /* Catch-all top-level counter struct. Allocations from CAFs will go
14 * here.
15 */
16 StgEntCounter top_ct
17 = { 0, 0, 0,
18 "TOP", "",
19 0, 0, NULL };
20
21 /* Data structure used in ``registering'' one of these counters. */
22
23 StgEntCounter *ticky_entry_ctrs = NULL; /* root of list of them */
24
25 /* We want Haskell code compiled with -ticky to be linkable with any
26 * version of the RTS, so we have to make sure all the symbols that
27 * ticky-compiled code may refer to are defined by every RTS. (#3439)
28 * Hence the #ifdef is here, rather than up above.
29 */
30 #if defined(TICKY_TICKY)
31
32 #include "Ticky.h"
33
34 /* -----------------------------------------------------------------------------
35 Print out all the counters
36 -------------------------------------------------------------------------- */
37
38 static void printRegisteredCounterInfo (FILE *); /* fwd decl */
39
40 #define INTAVG(a,b) ((b == 0) ? 0.0 : ((double) (a) / (double) (b)))
41 #define PC(a) (100.0 * a)
42
43 #define AVG(thing) \
44 StgDouble avg##thing = INTAVG(tot##thing,ctr##thing)
45
46 void
47 PrintTickyInfo(void)
48 {
49 unsigned long i;
50
51 unsigned long tot_thk_enters = ENT_STATIC_THK_MANY_ctr + ENT_DYN_THK_MANY_ctr
52 + ENT_STATIC_THK_SINGLE_ctr + ENT_DYN_THK_SINGLE_ctr;
53 unsigned long tot_con_enters = ENT_STATIC_CON_ctr + ENT_DYN_CON_ctr;
54
55 unsigned long tot_fun_direct_enters = ENT_STATIC_FUN_DIRECT_ctr + ENT_DYN_FUN_DIRECT_ctr;
56 unsigned long tot_ind_enters = ENT_STATIC_IND_ctr + ENT_DYN_IND_ctr;
57
58 unsigned long tot_known_calls =
59 KNOWN_CALL_ctr + KNOWN_CALL_TOO_FEW_ARGS_ctr +
60 + KNOWN_CALL_EXTRA_ARGS_ctr;
61 unsigned long tot_tail_calls =
62 UNKNOWN_CALL_ctr + tot_known_calls;
63
64 unsigned long tot_enters =
65 tot_con_enters + tot_fun_direct_enters +
66 tot_ind_enters + ENT_PERM_IND_ctr + ENT_PAP_ctr + tot_thk_enters;
67 unsigned long jump_direct_enters =
68 tot_enters - ENT_VIA_NODE_ctr;
69
70
71 unsigned long tot_returns =
72 RET_NEW_ctr + RET_OLD_ctr + RET_UNBOXED_TUP_ctr;
73
74 unsigned long tot_returns_of_new = RET_NEW_ctr;
75
76 unsigned long con_updates = UPD_CON_IN_NEW_ctr + UPD_CON_IN_PLACE_ctr;
77 unsigned long pap_updates = UPD_PAP_IN_NEW_ctr + UPD_PAP_IN_PLACE_ctr;
78
79 unsigned long tot_updates = UPD_SQUEEZED_ctr + pap_updates + con_updates;
80
81 unsigned long tot_new_updates = UPD_NEW_IND_ctr + UPD_NEW_PERM_IND_ctr;
82 unsigned long tot_old_updates = UPD_OLD_IND_ctr + UPD_OLD_PERM_IND_ctr;
83 unsigned long tot_gengc_updates = tot_new_updates + tot_old_updates;
84
85 FILE *tf = RtsFlags.TickyFlags.tickyFile;
86
87 /* If tf = NULL, that means the user passed in stderr for the ticky stats
88 file. According to a comment in RtsFlags.c, this means to use
89 debugBelch to print out messages. But this function prints out a lot
90 of stuff so in order to avoid changing a lot of code, we just dump
91 the same output to stderr (for now). */
92 if( tf == NULL )
93 tf = stderr;
94
95 fprintf(tf,"\nSTACK USAGE:\n"); /* NB: some bits are direction sensitive */
96
97
98 fprintf(tf,"\nENTERS: %lu of which %lu (%.1f%%) direct to the entry code\n\t\t [the rest indirected via Node's info ptr]\n",
99 tot_enters,
100 jump_direct_enters,
101 PC(INTAVG(jump_direct_enters,tot_enters)));
102 fprintf(tf,"%11lu (%5.1f%%) thunks\n",
103 tot_thk_enters,
104 PC(INTAVG(tot_thk_enters,tot_enters)));
105 fprintf(tf, "%11lu (%5.1f%%) data values\n",
106 tot_con_enters,
107 PC(INTAVG(tot_con_enters,tot_enters)));
108 fprintf(tf, "%11lu (%5.1f%%) normal indirections\n",
109 tot_ind_enters,
110 PC(INTAVG(tot_ind_enters,tot_enters)));
111 fprintf(tf,"%11" FMT_Int " (%5.1f%%) permanent indirections\n",
112 ENT_PERM_IND_ctr,
113 PC(INTAVG(ENT_PERM_IND_ctr,tot_enters)));
114
115
116 fprintf(tf, "\nFUNCTION ENTRIES: %lu\n", tot_fun_direct_enters);
117
118 fprintf(tf, "\nTAIL CALLS: %lu, of which %lu (%.lf%%) were to known functions\n",
119 tot_tail_calls, tot_known_calls,
120 PC(INTAVG(tot_known_calls,tot_tail_calls)));
121
122 fprintf(tf, "\nSLOW APPLICATIONS: %" FMT_Int " evaluated, %" FMT_Int " unevaluated\n",
123 SLOW_CALL_ctr, SLOW_CALL_UNEVALD_ctr);
124 fprintf(tf, "\n");
125 fprintf(tf, " Too few args Correct args Too many args\n");
126 fprintf(tf, " FUN %8" FMT_Int " %8" FMT_Int " %8" FMT_Int "\n",
127 SLOW_CALL_FUN_TOO_FEW_ctr, SLOW_CALL_FUN_CORRECT_ctr, SLOW_CALL_FUN_TOO_MANY_ctr);
128 fprintf(tf, " PAP %8" FMT_Int " %8" FMT_Int " %8" FMT_Int "\n",
129 SLOW_CALL_PAP_TOO_FEW_ctr, SLOW_CALL_PAP_CORRECT_ctr, SLOW_CALL_PAP_TOO_MANY_ctr);
130 fprintf(tf, "\n");
131
132 fprintf(tf, "\nRETURNS: %lu\n", tot_returns);
133 fprintf(tf, "%11lu (%5.1f%%) from entering a new constructor\n\t\t [the rest from entering an existing constructor]\n",
134 tot_returns_of_new,
135 PC(INTAVG(tot_returns_of_new,tot_returns)));
136
137
138 fprintf(tf, "\nRET_NEW: %11" FMT_Int ": ", RET_NEW_ctr);
139 for (i = 0; i < TICKY_BIN_COUNT; i++) {
140 fprintf(tf, "%5.1f%%", PC(INTAVG(RET_NEW_hst[i], RET_NEW_ctr)));
141 }
142 fprintf(tf, "\n");
143
144 fprintf(tf, "RET_OLD: %11" FMT_Int ": ", RET_OLD_ctr);
145 for (i = 0; i < TICKY_BIN_COUNT; i++) {
146 fprintf(tf, "%5.1f%%", PC(INTAVG(RET_OLD_hst[i], RET_OLD_ctr)));
147 }
148 fprintf(tf, "\n");
149
150 fprintf(tf, "RET_UNBOXED_TUP: %11" FMT_Int ": ", RET_UNBOXED_TUP_ctr);
151 for (i = 0; i < TICKY_BIN_COUNT; i++) {
152 fprintf(tf, "%5.1f%%", PC(INTAVG(RET_UNBOXED_TUP_hst[i],
153 RET_UNBOXED_TUP_ctr)));
154 }
155 fprintf(tf, "\n");
156
157 fprintf(tf,"\nUPDATE FRAMES: %" FMT_Int " (%" FMT_Int " omitted from thunks)",
158 UPDF_PUSHED_ctr,
159 UPDF_OMITTED_ctr);
160
161 fprintf(tf,"\nCATCH FRAMES: %" FMT_Int "", CATCHF_PUSHED_ctr);
162
163 if (UPDF_RCC_PUSHED_ctr != 0) {
164 fprintf(tf,"%11" FMT_Int " restore cost centre frames (%" FMT_Int " omitted)\n",
165 UPDF_RCC_PUSHED_ctr,
166 UPDF_RCC_OMITTED_ctr);
167 }
168
169 fprintf(tf,"\nUPDATES: %ld\n", tot_updates);
170 fprintf(tf, "%11lu (%5.1f%%) data values\n\t\t [%" FMT_Int " in place, %" FMT_Int " allocated new space]\n",
171 con_updates,
172 PC(INTAVG(con_updates,tot_updates)),
173 UPD_CON_IN_PLACE_ctr, UPD_CON_IN_NEW_ctr);
174
175 fprintf(tf, "%11lu (%5.1f%%) partial applications\n\t\t [%" FMT_Int " in place, %" FMT_Int " allocated new space]\n",
176 pap_updates,
177 PC(INTAVG(pap_updates,tot_updates)),
178 UPD_PAP_IN_PLACE_ctr, UPD_PAP_IN_NEW_ctr);
179
180 fprintf(tf,"%11" FMT_Int " (%5.1f%%) updates by squeezing\n",
181 UPD_SQUEEZED_ctr,
182 PC(INTAVG(UPD_SQUEEZED_ctr, tot_updates)));
183
184 if (tot_gengc_updates != 0) {
185 fprintf(tf, "\nNEW GEN UPDATES: %9lu (%5.1f%%)\n",
186 tot_new_updates,
187 PC(INTAVG(tot_new_updates,tot_gengc_updates)));
188 fprintf(tf, "OLD GEN UPDATES: %9lu (%5.1f%%)\n",
189 tot_old_updates,
190 PC(INTAVG(tot_old_updates,tot_gengc_updates)));
191 }
192
193 printRegisteredCounterInfo(tf);
194
195 fprintf(tf,"\n**************************************************\n");
196
197 /* here, we print out all the raw numbers; these are really
198 more useful when we want to snag them for subsequent
199 rdb-etc processing. WDP 95/11
200 */
201
202 #define PR_CTR(ctr) \
203 do { fprintf(tf,"%11" FMT_Int " " #ctr "\n", ctr); } while(0)
204
205 /* COND_PR_CTR takes a boolean; if false then msg is the printname rather than ctr */
206 #define COND_PR_CTR(ctr,b,msg) \
207 if (b) { fprintf(tf,"%11" FMT_Int " " #ctr "\n", ctr); } else { fprintf(tf,"%11" FMT_Int " " msg "\n", ctr); }
208
209 #define PR_HST(hst,i) \
210 do { fprintf(tf,"%11" FMT_Int " " #hst "_" #i "\n", hst[i]); } while(0)
211
212 ALLOC_HEAP_ctr = (StgInt)ALLOC_HEAP_ctr + (StgInt)ALLOC_RTS_ctr;
213 ALLOC_HEAP_tot = (StgInt)ALLOC_HEAP_tot + (StgInt)ALLOC_RTS_tot;
214
215 PR_CTR(ALLOC_HEAP_ctr);
216 PR_CTR(ALLOC_HEAP_tot);
217
218 PR_CTR(HEAP_CHK_ctr);
219 PR_CTR(STK_CHK_ctr);
220
221 PR_CTR(ALLOC_RTS_ctr);
222 PR_CTR(ALLOC_RTS_tot);
223
224 PR_CTR(ALLOC_FUN_ctr);
225 PR_CTR(ALLOC_FUN_gds);
226
227 PR_CTR(ALLOC_PAP_ctr);
228 PR_CTR(ALLOC_PAP_adm);
229 PR_CTR(ALLOC_PAP_gds);
230
231 PR_CTR(ALLOC_UP_THK_ctr);
232 PR_CTR(ALLOC_SE_THK_ctr);
233 PR_CTR(ALLOC_THK_gds);
234
235 PR_CTR(ALLOC_CON_ctr);
236 PR_CTR(ALLOC_CON_gds);
237
238 PR_CTR(ALLOC_PRIM_ctr);
239 PR_CTR(ALLOC_PRIM_gds);
240 PR_CTR(ALLOC_PRIM_slp);
241
242 PR_CTR(ENT_VIA_NODE_ctr);
243 PR_CTR(ENT_STATIC_CON_ctr);
244 PR_CTR(ENT_DYN_CON_ctr);
245 PR_CTR(ENT_STATIC_FUN_DIRECT_ctr);
246 PR_CTR(ENT_DYN_FUN_DIRECT_ctr);
247 PR_CTR(ENT_LNE_ctr);
248 PR_CTR(ENT_STATIC_IND_ctr);
249 PR_CTR(ENT_DYN_IND_ctr);
250
251 /* The counters ENT_PERM_IND and UPD_{NEW,OLD}_PERM_IND are not dumped
252 * at the end of execution unless update squeezing is turned off (+RTS
253 * -Z =RtsFlags.GcFlags.squeezeUpdFrames), as they will be wrong
254 * otherwise. Why? Because for each update frame squeezed out, we
255 * count an UPD_NEW_PERM_IND *at GC time* (i.e., too early). And
256 * further, when we enter the closure that has been updated, we count
257 * the ENT_PERM_IND, but we then enter the PERM_IND that was built for
258 * the next update frame below, and so on down the chain until we
259 * finally reach the value. Thus we count many new ENT_PERM_INDs too
260 * early.
261 *
262 * This of course refers to the -ticky version that uses PERM_INDs to
263 * determine the number of closures entered 0/1/>1. KSW 1999-04. */
264 COND_PR_CTR(ENT_PERM_IND_ctr,RtsFlags.GcFlags.squeezeUpdFrames == false,"E!NT_PERM_IND_ctr requires +RTS -Z");
265
266 PR_CTR(ENT_AP_ctr);
267 PR_CTR(ENT_PAP_ctr);
268 PR_CTR(ENT_AP_STACK_ctr);
269 PR_CTR(ENT_BH_ctr);
270 PR_CTR(ENT_STATIC_THK_SINGLE_ctr);
271 PR_CTR(ENT_STATIC_THK_MANY_ctr);
272 PR_CTR(ENT_DYN_THK_SINGLE_ctr);
273 PR_CTR(ENT_DYN_THK_MANY_ctr);
274 PR_CTR(UPD_CAF_BH_UPDATABLE_ctr);
275 PR_CTR(UPD_CAF_BH_SINGLE_ENTRY_ctr);
276
277 PR_CTR(SLOW_CALL_fast_v16_ctr);
278 PR_CTR(SLOW_CALL_fast_v_ctr);
279 PR_CTR(SLOW_CALL_fast_f_ctr);
280 PR_CTR(SLOW_CALL_fast_d_ctr);
281 PR_CTR(SLOW_CALL_fast_l_ctr);
282 PR_CTR(SLOW_CALL_fast_n_ctr);
283 PR_CTR(SLOW_CALL_fast_p_ctr);
284 PR_CTR(SLOW_CALL_fast_pv_ctr);
285 PR_CTR(SLOW_CALL_fast_pp_ctr);
286 PR_CTR(SLOW_CALL_fast_ppv_ctr);
287 PR_CTR(SLOW_CALL_fast_ppp_ctr);
288 PR_CTR(SLOW_CALL_fast_pppv_ctr);
289 PR_CTR(SLOW_CALL_fast_pppp_ctr);
290 PR_CTR(SLOW_CALL_fast_ppppp_ctr);
291 PR_CTR(SLOW_CALL_fast_pppppp_ctr);
292 PR_CTR(VERY_SLOW_CALL_ctr);
293
294 PR_CTR(UNKNOWN_CALL_ctr);
295 PR_CTR(KNOWN_CALL_ctr);
296 PR_CTR(KNOWN_CALL_TOO_FEW_ARGS_ctr);
297 PR_CTR(KNOWN_CALL_EXTRA_ARGS_ctr);
298 PR_CTR(MULTI_CHUNK_SLOW_CALL_ctr);
299 PR_CTR(MULTI_CHUNK_SLOW_CALL_CHUNKS_ctr);
300 PR_CTR(SLOW_CALL_ctr);
301 PR_CTR(SLOW_CALL_FUN_TOO_FEW_ctr);
302 PR_CTR(SLOW_CALL_FUN_CORRECT_ctr);
303 PR_CTR(SLOW_CALL_FUN_TOO_MANY_ctr);
304 PR_CTR(SLOW_CALL_PAP_TOO_FEW_ctr);
305 PR_CTR(SLOW_CALL_PAP_CORRECT_ctr);
306 PR_CTR(SLOW_CALL_PAP_TOO_MANY_ctr);
307 PR_CTR(SLOW_CALL_UNEVALD_ctr);
308
309 PR_CTR(RET_NEW_ctr);
310 PR_CTR(RET_OLD_ctr);
311 PR_CTR(RET_UNBOXED_TUP_ctr);
312
313 #define PR_HST_BINS(hst) for (i = 0; i < TICKY_BIN_COUNT; i++) \
314 { fprintf(tf,"%11" FMT_Int " " #hst "_%lu\n", hst[i], i); }
315
316 PR_HST_BINS(RET_NEW_hst);
317 PR_HST_BINS(RET_OLD_hst);
318 PR_HST_BINS(RET_UNBOXED_TUP_hst);
319
320 #undef PR_HST_BINS
321
322 PR_CTR(UPDF_OMITTED_ctr);
323 PR_CTR(UPDF_PUSHED_ctr);
324 PR_CTR(CATCHF_PUSHED_ctr);
325
326 PR_CTR(UPDF_RCC_PUSHED_ctr);
327 PR_CTR(UPDF_RCC_OMITTED_ctr);
328
329 PR_CTR(UPD_SQUEEZED_ctr);
330 PR_CTR(UPD_CON_IN_NEW_ctr);
331 PR_CTR(UPD_CON_IN_PLACE_ctr);
332 PR_CTR(UPD_PAP_IN_NEW_ctr);
333 PR_CTR(UPD_PAP_IN_PLACE_ctr);
334
335 PR_CTR(UPD_NEW_IND_ctr);
336 /* see comment on ENT_PERM_IND_ctr */
337 COND_PR_CTR(UPD_NEW_PERM_IND_ctr,RtsFlags.GcFlags.squeezeUpdFrames == false,"U!PD_NEW_PERM_IND_ctr requires +RTS -Z");
338 PR_CTR(UPD_OLD_IND_ctr);
339 /* see comment on ENT_PERM_IND_ctr */
340 COND_PR_CTR(UPD_OLD_PERM_IND_ctr,RtsFlags.GcFlags.squeezeUpdFrames == false,"U!PD_OLD_PERM_IND_ctr requires +RTS -Z");
341
342 PR_CTR(GC_SEL_ABANDONED_ctr);
343 PR_CTR(GC_SEL_MINOR_ctr);
344 PR_CTR(GC_SEL_MAJOR_ctr);
345 PR_CTR(GC_FAILED_PROMOTION_ctr);
346 }
347
348 /* To print out all the registered-counter info: */
349
350 static void
351 printRegisteredCounterInfo (FILE *tf)
352 {
353 StgEntCounter *p;
354
355 if ( ticky_entry_ctrs != NULL ) {
356 fprintf(tf,"\nThe following table is explained by http://ghc.haskell.org/trac/ghc/wiki/Debugging/TickyTicky\nAll allocation numbers are in bytes.\n");
357 fprintf(tf,"\n**************************************************\n\n");
358 }
359 fprintf(tf, "%11s%11s%11s %-23s %s\n",
360 "Entries", "Alloc", "Alloc'd", "Non-void Arguments", "STG Name");
361 fprintf(tf, "--------------------------------------------------------------------------------\n");
362 /* Function name at the end so it doesn't mess up the tabulation */
363
364 for (p = ticky_entry_ctrs; p != NULL; p = p->link) {
365 fprintf(tf, "%11" FMT_Int "%11" FMT_Int "%11" FMT_Int " %3lu %-20.20s %s",
366 p->entry_count,
367 p->allocs,
368 p->allocd,
369 (unsigned long)p->arity,
370 p->arg_kinds,
371 p->str);
372
373 fprintf(tf, "\n");
374
375 }
376 }
377 #endif /* TICKY_TICKY */