fix codetest failure - ASSERT_ARGS does not have a ; after and
[parrot.git] / src / runcore / profiling.c
blob8e16a4cddeeaae098f9d59b6e9170b052dde23a0
1 /*
2 Copyright (C) 2009, Parrot Foundation.
3 $Id$
5 =head1 NAME
7 src/runcore/profiling.c
9 =head1 DESCRIPTION
11 Functions controlling Parrot's profiling runcore.
13 =head2 Functions
15 =over 4
17 =cut
21 #include "parrot/runcore_api.h"
22 #include "parrot/embed.h"
23 #include "parrot/runcore_profiling.h"
24 #include "parrot/oplib/core_ops.h"
26 #include "profiling.str"
28 #include "pmc/pmc_sub.h"
29 #include "pmc/pmc_callcontext.h"
30 #include "pmc/pmc_namespace.h"
32 #ifdef WIN32
33 # define getpid _getpid
34 #endif
36 #define PPROF_VERSION 2
37 #define MAX_NS_DEPTH 32
39 #define code_start interp->code->base.data
40 #define code_end (interp->code->base.data + interp->code->base.size)
42 /* HEADERIZER HFILE: include/parrot/runcore_profiling.h */
44 /* HEADERIZER BEGIN: static */
45 /* Don't modify between HEADERIZER BEGIN / HEADERIZER END. Your changes will be lost. */
47 static void add_bogus_parent_runloop(
48 ARGIN(Parrot_profiling_runcore_t * runcore))
49 __attribute__nonnull__(1);
51 PARROT_CAN_RETURN_NULL
52 static void * init_profiling_core(PARROT_INTERP,
53 ARGIN(Parrot_profiling_runcore_t *runcore),
54 ARGIN(opcode_t *pc))
55 __attribute__nonnull__(1)
56 __attribute__nonnull__(2)
57 __attribute__nonnull__(3);
59 static void record_values_ascii_pprof(
60 ARGIN(Parrot_profiling_runcore_t * runcore),
61 ARGIN(PPROF_DATA *pprof_data),
62 ARGIN_NULLOK(Parrot_profiling_line type))
63 __attribute__nonnull__(1)
64 __attribute__nonnull__(2);
66 static void record_values_none(
67 ARGIN(Parrot_profiling_runcore_t * runcore),
68 ARGIN(PPROF_DATA *pprof_data),
69 ARGIN_NULLOK(Parrot_profiling_line type))
70 __attribute__nonnull__(1)
71 __attribute__nonnull__(2);
73 PARROT_WARN_UNUSED_RESULT
74 PARROT_CAN_RETURN_NULL
75 static opcode_t * runops_profiling_core(PARROT_INTERP,
76 ARGIN(Parrot_profiling_runcore_t *runcore),
77 ARGIN(opcode_t *pc))
78 __attribute__nonnull__(1)
79 __attribute__nonnull__(2)
80 __attribute__nonnull__(3);
82 #define ASSERT_ARGS_add_bogus_parent_runloop __attribute__unused__ int _ASSERT_ARGS_CHECK = (\
83 PARROT_ASSERT_ARG(runcore))
84 #define ASSERT_ARGS_init_profiling_core __attribute__unused__ int _ASSERT_ARGS_CHECK = (\
85 PARROT_ASSERT_ARG(interp) \
86 , PARROT_ASSERT_ARG(runcore) \
87 , PARROT_ASSERT_ARG(pc))
88 #define ASSERT_ARGS_record_values_ascii_pprof __attribute__unused__ int _ASSERT_ARGS_CHECK = (\
89 PARROT_ASSERT_ARG(runcore) \
90 , PARROT_ASSERT_ARG(pprof_data))
91 #define ASSERT_ARGS_record_values_none __attribute__unused__ int _ASSERT_ARGS_CHECK = (\
92 PARROT_ASSERT_ARG(runcore) \
93 , PARROT_ASSERT_ARG(pprof_data))
94 #define ASSERT_ARGS_runops_profiling_core __attribute__unused__ int _ASSERT_ARGS_CHECK = (\
95 PARROT_ASSERT_ARG(interp) \
96 , PARROT_ASSERT_ARG(runcore) \
97 , PARROT_ASSERT_ARG(pc))
98 /* Don't modify between HEADERIZER BEGIN / HEADERIZER END. Your changes will be lost. */
99 /* HEADERIZER END: static */
104 =item C<void Parrot_runcore_profiling_init(PARROT_INTERP)>
106 Registers the profiling runcore with Parrot.
108 =cut
112 void
113 Parrot_runcore_profiling_init(PARROT_INTERP)
115 ASSERT_ARGS(Parrot_runcore_profiling_init)
117 Parrot_profiling_runcore_t *coredata =
118 mem_gc_allocate_zeroed_typed(interp, Parrot_profiling_runcore_t);
120 coredata->name = CONST_STRING(interp, "profiling");
121 coredata->id = PARROT_PROFILING_CORE;
122 coredata->opinit = PARROT_CORE_OPLIB_INIT;
123 coredata->runops = (Parrot_runcore_runops_fn_t) init_profiling_core;
124 coredata->destroy = NULL;
125 coredata->prepare_run = NULL;
126 coredata->flags = 0;
128 PARROT_RUNCORE_FUNC_TABLE_SET(coredata);
130 Parrot_runcore_register(interp, (Parrot_runcore_t *) coredata);
136 =item C<static void * init_profiling_core(PARROT_INTERP,
137 Parrot_profiling_runcore_t *runcore, opcode_t *pc)>
139 Perform initialization for the profiling runcore.
141 =cut
145 PARROT_CAN_RETURN_NULL
146 static void *
147 init_profiling_core(PARROT_INTERP, ARGIN(Parrot_profiling_runcore_t *runcore), ARGIN(opcode_t *pc))
149 ASSERT_ARGS(init_profiling_core)
151 char *profile_filename, *output_cstr, *filename_cstr;
153 /* initialize the runcore struct */
154 runcore->runops = (Parrot_runcore_runops_fn_t) runops_profiling_core;
155 runcore->destroy = (Parrot_runcore_destroy_fn_t) destroy_profiling_core;
157 runcore->prev_ctx = NULL;
158 runcore->profiling_flags = 0;
159 runcore->runloop_count = 0;
160 runcore->level = 0;
161 runcore->time_size = 32;
162 runcore->line_cache = parrot_new_pointer_hash(interp);
163 runcore->time = mem_gc_allocate_n_typed(interp, runcore->time_size,
164 UHUGEINTVAL);
166 /* figure out what format the output should be in */
167 output_cstr = Parrot_getenv(interp, CONST_STRING(interp, "PARROT_PROFILING_OUTPUT"));
169 if (output_cstr) {
171 STRING *profile_format_str = Parrot_str_new(interp, output_cstr, 0);
172 if (Parrot_str_equal(interp, profile_format_str, CONST_STRING(interp, "pprof"))) {
173 runcore->output_fn = record_values_ascii_pprof;
175 else if (Parrot_str_equal(interp, profile_format_str, CONST_STRING(interp, "none"))) {
176 runcore->output_fn = record_values_none;
178 else {
179 fprintf(stderr, "'%s' is not a valid profiling output format.\n", output_cstr);
180 fprintf(stderr, "Valid values are pprof and none. The default is pprof.\n");
181 exit(1);
184 else {
185 runcore->output_fn = record_values_ascii_pprof;
188 /* figure out where to write the output */
189 filename_cstr = Parrot_getenv(interp, CONST_STRING(interp, "PARROT_PROFILING_FILENAME"));
191 if (runcore->output_fn != record_values_none) {
192 if (filename_cstr) {
193 STRING *lc_filename;
194 runcore->profile_filename = Parrot_str_new(interp, filename_cstr, 0);
195 /* this is a little goofy, but it means that we unconditionally free
196 * profile_filename later in this function */
197 profile_filename = Parrot_str_to_cstring(interp, runcore->profile_filename);
198 lc_filename = Parrot_str_downcase(interp, runcore->profile_filename);
200 if (Parrot_str_equal(interp, lc_filename, CONST_STRING(interp, "stderr"))) {
201 runcore->profile_fd = stderr;
202 runcore->profile_filename = lc_filename;
204 else if (Parrot_str_equal(interp, lc_filename, CONST_STRING(interp, "stdout"))) {
205 runcore->profile_fd = stdout;
206 runcore->profile_filename = lc_filename;
208 else
209 runcore->profile_fd = fopen(profile_filename, "w");
211 else {
212 runcore->profile_filename = Parrot_sprintf_c(interp, "parrot.pprof.%d", getpid());
213 profile_filename = Parrot_str_to_cstring(interp, runcore->profile_filename);
214 runcore->profile_fd = fopen(profile_filename, "w");
217 if (!runcore->profile_fd) {
218 fprintf(stderr, "unable to open %s for writing", profile_filename);
219 Parrot_str_free_cstring(profile_filename);
220 exit(1);
223 Parrot_str_free_cstring(profile_filename);
225 else {
226 runcore->profile_filename = CONST_STRING(interp, "none");
229 /* figure out if annotations are wanted */
230 if (Parrot_getenv(interp, CONST_STRING(interp, "PARROT_PROFILING_ANNOTATIONS"))) {
231 Profiling_report_annotations_SET(runcore);
234 if (Parrot_getenv(interp, CONST_STRING(interp, "PARROT_PROFILING_CANONICAL_OUTPUT"))) {
235 Profiling_canonical_output_SET(runcore);
238 /* put profile_filename in the gc root set so it won't get collected */
239 Parrot_pmc_gc_register(interp, (PMC *) runcore->profile_filename);
241 Profiling_first_loop_SET(runcore);
243 return runops_profiling_core(interp, runcore, pc);
249 =item C<static opcode_t * runops_profiling_core(PARROT_INTERP,
250 Parrot_profiling_runcore_t *runcore, opcode_t *pc)>
252 Runs the Parrot operations starting at C<pc> until there are no more
253 operations, with tracing, bounds checking, and profiling enabled.
255 =cut
259 PARROT_WARN_UNUSED_RESULT
260 PARROT_CAN_RETURN_NULL
261 static opcode_t *
262 runops_profiling_core(PARROT_INTERP, ARGIN(Parrot_profiling_runcore_t *runcore),
263 ARGIN(opcode_t *pc))
265 ASSERT_ARGS(runops_profiling_core)
267 PMC *argv;
268 opcode_t *preop_pc;
269 UHUGEINTVAL op_time;
270 PPROF_DATA pprof_data[PPROF_DATA_MAX + 1];
272 runcore->runcore_start = Parrot_hires_get_time();
274 /* if we're in a nested runloop, */
275 if (runcore->level != 0) {
277 if (runcore->level >= runcore->time_size) {
278 runcore->time_size *= 2;
279 runcore->time = mem_gc_realloc_n_typed(interp,
280 runcore->time, runcore->time_size + 1, UHUGEINTVAL);
283 /* store the time between DO_OP and the start of this runcore in this
284 * op's running total */
285 runcore->time[runcore->level] =
286 runcore->runcore_start - runcore->op_start;
289 argv = VTABLE_get_pmc_keyed_int(interp, interp->iglobals, IGLOBALS_ARGV_LIST);
291 /* argv isn't initialized until after :init (etc) subs are executed */
292 if (argv && !Profiling_have_printed_cli_TEST(runcore)) {
294 char *cli_cstr;
295 STRING *space, *cli_args, *cli_exe, *cli_str;
296 PMC *exe_name = VTABLE_get_pmc_keyed_int(interp, interp->iglobals, IGLOBALS_EXECUTABLE);
298 space = CONST_STRING(interp, " ");
299 cli_args = Parrot_str_join(interp, space, argv);
300 cli_exe = VTABLE_get_string(interp, exe_name);
301 cli_str = Parrot_sprintf_c(interp, "%Ss %Ss", cli_exe, cli_args);
302 cli_cstr = Parrot_str_to_cstring(interp, cli_str);
304 /* CLI line won't reflect any options passed to the parrot binary. */
305 pprof_data[PPROF_DATA_CLI] = (PPROF_DATA) cli_cstr;
306 runcore->output_fn(runcore, pprof_data, PPROF_LINE_CLI);
308 Parrot_str_free_cstring(cli_cstr);
310 Profiling_have_printed_cli_SET(runcore);
313 if (Profiling_first_loop_TEST(runcore)) {
315 Profiling_first_loop_CLEAR(runcore);
317 pprof_data[PPROF_DATA_VERSION] = (PPROF_DATA) PPROF_VERSION;
318 runcore->output_fn(runcore, pprof_data, PPROF_LINE_VERSION);
320 add_bogus_parent_runloop(runcore);
323 while (pc) {
324 Parrot_Context *preop_ctx;
325 INTVAL preop_line;
326 PMC *preop_ctx_pmc;
328 if (pc < code_start || pc >= code_end)
329 Parrot_ex_throw_from_c_args(interp, NULL, 1,
330 "attempt to access code outside of current code segment");
332 preop_ctx_pmc = CURRENT_CONTEXT(interp);
333 preop_ctx = PMC_data_typed(preop_ctx_pmc, Parrot_Context*);
334 preop_ctx->current_pc = pc;
335 preop_pc = pc;
337 ++runcore->level;
338 Profiling_exit_check_CLEAR(runcore);
340 runcore->op_start = Parrot_hires_get_time();
341 DO_OP(pc, interp);
342 runcore->op_finish = Parrot_hires_get_time();
344 if (Profiling_exit_check_TEST(runcore)) {
345 op_time = runcore->op_finish - runcore->runcore_finish;
346 op_time += runcore->time[runcore->level];
347 runcore->time[runcore->level] = 0;
349 else
350 op_time = runcore->op_finish - runcore->op_start;
352 --runcore->level;
354 /* if current context changed since the last printing of a CS line... */
355 /* Occasionally the ctx stays the same while the sub changes, possible
356 * with a call to a subclass' method. */
358 if ((runcore->prev_ctx != preop_ctx)
359 || runcore->prev_sub != preop_ctx->current_sub) {
361 if (preop_ctx->current_sub) {
362 STRING *sub_name, *full_ns, *ns_separator, *preop_filename;
363 char *full_ns_cstr, *filename_cstr;
364 STRING *ns_names[MAX_NS_DEPTH];
365 PMC *ns = preop_ctx->current_namespace;
366 INTVAL i;
368 preop_filename = Parrot_Sub_get_filename_from_pc(interp,
369 Parrot_pcc_get_sub(interp, preop_ctx_pmc), pc);
371 filename_cstr = Parrot_str_to_cstring(interp, preop_filename);
373 /* build the namespace string */
374 full_ns = Parrot_str_new(interp, "", 0);
375 ns_separator = Parrot_str_new(interp, ";", 1);
377 i = MAX_NS_DEPTH - 1;
378 for (;ns ; --i) {
379 if (i < 0) {
380 /* should probably warn about truncated namespace here */
381 break;
383 GETATTR_NameSpace_name(interp, ns, ns_names[i]);
384 GETATTR_NameSpace_parent(interp, ns, ns);
387 i += 2; /* the root namespace has an empty name, so ignore it */
388 for (;i < MAX_NS_DEPTH; ++i) {
389 full_ns = Parrot_str_concat(interp, full_ns, ns_names[i]);
390 full_ns = Parrot_str_concat(interp, full_ns, ns_separator);
393 GETATTR_Sub_name(interp, preop_ctx->current_sub, sub_name);
394 full_ns = Parrot_str_concat(interp, full_ns, sub_name);
395 full_ns_cstr = Parrot_str_to_cstring(interp, full_ns);
397 pprof_data[PPROF_DATA_NAMESPACE] = (PPROF_DATA) full_ns_cstr;
398 pprof_data[PPROF_DATA_FILENAME] = (PPROF_DATA) filename_cstr;
400 if (Profiling_canonical_output_TEST(runcore)) {
401 pprof_data[PPROF_DATA_SUB_ADDR] = (PPROF_DATA) 0x3;
402 pprof_data[PPROF_DATA_CTX_ADDR] = (PPROF_DATA) 0x3;
404 else {
405 pprof_data[PPROF_DATA_SUB_ADDR] = (PPROF_DATA) preop_ctx->current_sub;
406 pprof_data[PPROF_DATA_CTX_ADDR] = (PPROF_DATA) preop_ctx;
409 runcore->output_fn(runcore, pprof_data, PPROF_LINE_CONTEXT_SWITCH);
411 Parrot_str_free_cstring(full_ns_cstr);
412 Parrot_str_free_cstring(filename_cstr);
415 runcore->prev_ctx = preop_ctx;
416 runcore->prev_sub = preop_ctx->current_sub;
419 preop_line = hash_value_to_int(interp, runcore->line_cache,
420 parrot_hash_get(interp, runcore->line_cache,
421 preop_ctx->current_pc));
423 if (preop_line == 0) {
424 preop_line = Parrot_Sub_get_line_from_pc(interp,
425 Parrot_pcc_get_sub(interp, preop_ctx_pmc),
426 preop_ctx->current_pc);
427 parrot_hash_put(interp, runcore->line_cache, preop_ctx->current_pc,
428 (void *) preop_line);
431 if (Profiling_report_annotations_TEST(runcore) && interp->code->annotations) {
432 PMC * const annot = PackFile_Annotations_lookup(interp,
433 interp->code->annotations, pc - code_start + 1, NULL);
435 if (!PMC_IS_NULL(annot)) {
437 PMC *iter = VTABLE_get_iter(interp, annot);
438 while (VTABLE_get_bool(interp, iter)) {
440 STRING *key = VTABLE_shift_string(interp, iter);
441 STRING *val = VTABLE_get_string_keyed_str(interp, annot, key);
442 char *key_cstr = Parrot_str_to_cstring(interp, key);
443 char *val_cstr = Parrot_str_to_cstring(interp, val);
445 pprof_data[PPROF_DATA_ANNOTATION_NAME] = (PPROF_DATA) key_cstr;
446 pprof_data[PPROF_DATA_ANNOTATION_VALUE] = (PPROF_DATA) val_cstr;
447 runcore->output_fn(runcore, pprof_data, PPROF_LINE_ANNOTATION);
449 Parrot_str_free_cstring(key_cstr);
450 Parrot_str_free_cstring(val_cstr);
455 if (Profiling_canonical_output_TEST(runcore)) {
456 pprof_data[PPROF_DATA_TIME] = 1;
458 else {
459 pprof_data[PPROF_DATA_TIME] = op_time;
461 pprof_data[PPROF_DATA_LINE] = preop_line;
462 pprof_data[PPROF_DATA_OPNAME] = (PPROF_DATA)(interp->code->op_info_table)[*preop_pc]->name;
463 runcore->output_fn(runcore, pprof_data, PPROF_LINE_OP);
466 /* make it easy to tell separate runloops apart */
467 if (runcore->level == 0) {
469 runcore->output_fn(runcore, pprof_data, PPROF_LINE_END_OF_RUNLOOP);
471 add_bogus_parent_runloop(runcore);
474 Profiling_exit_check_SET(runcore);
475 runcore->runcore_finish = Parrot_hires_get_time();
476 return pc;
481 =item C<static void add_bogus_parent_runloop(Parrot_profiling_runcore_t *
482 runcore)>
484 Record profiling information for a bogus parent runloop. Parrot program
485 generally have several runloops, so a little trickery is needed to profile them
486 all as a single program. This is accomplished by having a fake sub named
487 'main' which has no cost in itself but which appears to call all top-level
488 runloops as children.
490 =cut
494 static void
495 add_bogus_parent_runloop(ARGIN(Parrot_profiling_runcore_t * runcore))
497 ASSERT_ARGS(add_bogus_parent_runloop)
499 PPROF_DATA pprof_data[PPROF_DATA_MAX+1];
501 /* make all separate runloops appear to come from a single source */
502 pprof_data[PPROF_DATA_NAMESPACE] = (PPROF_DATA) "main";
503 pprof_data[PPROF_DATA_FILENAME] = (PPROF_DATA) "no_file";
504 pprof_data[PPROF_DATA_SUB_ADDR] = 1;
505 pprof_data[PPROF_DATA_CTX_ADDR] = 1;
506 runcore->output_fn(runcore, pprof_data, PPROF_LINE_CONTEXT_SWITCH);
508 pprof_data[PPROF_DATA_LINE] = runcore->runloop_count;
509 pprof_data[PPROF_DATA_TIME] = 0;
510 pprof_data[PPROF_DATA_OPNAME] = (PPROF_DATA) "noop";
511 runcore->output_fn(runcore, pprof_data, PPROF_LINE_OP);
513 ++runcore->runloop_count;
518 =item C<static void record_values_ascii_pprof(Parrot_profiling_runcore_t *
519 runcore, PPROF_DATA *pprof_data, Parrot_profiling_line type)>
521 Record profiling data to a filehandle in a human-readable format.
523 =cut
527 static void
528 record_values_ascii_pprof(ARGIN(Parrot_profiling_runcore_t * runcore),
529 ARGIN(PPROF_DATA *pprof_data), ARGIN_NULLOK(Parrot_profiling_line type))
531 ASSERT_ARGS(record_values_ascii_pprof)
533 switch (type) {
534 case PPROF_LINE_CONTEXT_SWITCH:
536 char *pd_namespace = (char *) pprof_data[PPROF_DATA_NAMESPACE];
537 char *pd_filename = (char *) pprof_data[PPROF_DATA_FILENAME];
538 void *sub_addr = (void *) pprof_data[PPROF_DATA_SUB_ADDR];
539 void *ctx_addr = (void *) pprof_data[PPROF_DATA_CTX_ADDR];
540 fprintf(runcore->profile_fd,
541 "CS:{x{ns:%s}x}{x{file:%s}x}{x{sub:%p}x}{x{ctx:%p}x}\n",
542 pd_namespace, pd_filename, sub_addr, ctx_addr);
544 break;
546 case PPROF_LINE_OP:
548 PPROF_DATA line = (PPROF_DATA) pprof_data[PPROF_DATA_LINE];
549 PPROF_DATA time = (PPROF_DATA) pprof_data[PPROF_DATA_TIME];
550 char *opname = (char *) pprof_data[PPROF_DATA_OPNAME];
551 fprintf(runcore->profile_fd, "OP:{x{line:%d}x}{x{time:%d}x}{x{op:%s}x}\n",
552 (int) line, (int) time, opname);
554 break;
556 case PPROF_LINE_ANNOTATION:
558 char *name = (char *) pprof_data[PPROF_DATA_ANNOTATION_NAME];
559 char *value = (char *) pprof_data[PPROF_DATA_ANNOTATION_VALUE];
560 fprintf(runcore->profile_fd, "AN:{x{name:%s}x}{x{value:%s}x}\n", name, value);
563 case PPROF_LINE_CLI:
564 fprintf(runcore->profile_fd, "CLI: %s\n", (char *) pprof_data[PPROF_DATA_CLI]);
565 break;
567 case PPROF_LINE_VERSION:
568 fprintf(runcore->profile_fd, "VERSION:%d\n", (int) pprof_data[PPROF_DATA_VERSION]);
569 break;
571 case PPROF_LINE_END_OF_RUNLOOP:
572 fprintf(runcore->profile_fd, "END_OF_RUNLOOP:1\n");
573 break;
575 default:
576 break;
577 } /* switch */
582 =item C<static void record_values_none(Parrot_profiling_runcore_t * runcore,
583 PPROF_DATA *pprof_data, Parrot_profiling_line type)>
585 Accept data but don't actually write it anywhere.
587 =cut
591 static void
592 record_values_none(ARGIN(Parrot_profiling_runcore_t * runcore),
593 ARGIN(PPROF_DATA *pprof_data), ARGIN_NULLOK(Parrot_profiling_line type))
595 ASSERT_ARGS(record_values_none)
596 UNUSED(runcore);
597 UNUSED(pprof_data);
598 UNUSED(type);
604 =item C<void * destroy_profiling_core(PARROT_INTERP, Parrot_profiling_runcore_t
605 *runcore)>
607 Perform any finalization needed by the profiling runcore.
609 =cut
613 PARROT_CAN_RETURN_NULL
614 void *
615 destroy_profiling_core(PARROT_INTERP, ARGIN(Parrot_profiling_runcore_t *runcore))
617 ASSERT_ARGS(destroy_profiling_core)
619 char *filename_cstr = Parrot_str_to_cstring(interp, runcore->profile_filename);
621 fprintf(stderr, "\nPROFILING RUNCORE: wrote profile to %s\n"
622 "Use tools/dev/pprof2cg.pl to generate Callgrind-compatible "
623 "output from this file.\n", filename_cstr);
625 Parrot_str_free_cstring(filename_cstr);
626 parrot_hash_destroy(interp, runcore->line_cache);
628 if (runcore->output_fn != record_values_none)
629 fclose(runcore->profile_fd);
630 mem_gc_free(interp, runcore->time);
632 return NULL;
637 =back
642 * Local variables:
643 * c-file-style: "parrot"
644 * End:
645 * vim: expandtab shiftwidth=4: