2 Copyright (C) 2009, Parrot Foundation.
7 src/runcore/profiling.c
11 Functions controlling Parrot's profiling runcore.
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"
33 # define getpid _getpid
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
),
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
),
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.
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
;
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.
145 PARROT_CAN_RETURN_NULL
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;
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
,
166 /* figure out what format the output should be in */
167 output_cstr
= Parrot_getenv(interp
, CONST_STRING(interp
, "PARROT_PROFILING_OUTPUT"));
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
;
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");
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
) {
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
;
209 runcore
->profile_fd
= fopen(profile_filename
, "w");
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
);
223 Parrot_str_free_cstring(profile_filename
);
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.
259 PARROT_WARN_UNUSED_RESULT
260 PARROT_CAN_RETURN_NULL
262 runops_profiling_core(PARROT_INTERP
, ARGIN(Parrot_profiling_runcore_t
*runcore
),
265 ASSERT_ARGS(runops_profiling_core
)
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
)) {
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
);
324 Parrot_Context
*preop_ctx
;
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
;
338 Profiling_exit_check_CLEAR(runcore
);
340 runcore
->op_start
= Parrot_hires_get_time();
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;
350 op_time
= runcore
->op_finish
- runcore
->op_start
;
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
;
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;
380 /* should probably warn about truncated namespace here */
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;
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;
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();
481 =item C<static void add_bogus_parent_runloop(Parrot_profiling_runcore_t *
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.
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.
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
)
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
);
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
);
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
);
564 fprintf(runcore
->profile_fd
, "CLI: %s\n", (char *) pprof_data
[PPROF_DATA_CLI
]);
567 case PPROF_LINE_VERSION
:
568 fprintf(runcore
->profile_fd
, "VERSION:%d\n", (int) pprof_data
[PPROF_DATA_VERSION
]);
571 case PPROF_LINE_END_OF_RUNLOOP
:
572 fprintf(runcore
->profile_fd
, "END_OF_RUNLOOP:1\n");
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.
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
)
604 =item C<void * destroy_profiling_core(PARROT_INTERP, Parrot_profiling_runcore_t
607 Perform any finalization needed by the profiling runcore.
613 PARROT_CAN_RETURN_NULL
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
);
643 * c-file-style: "parrot"
645 * vim: expandtab shiftwidth=4: