[svn:parrot] r40434 - in branches/pluggable_runcore: src/runcore tools/dev
cotto at svn.parrot.org
cotto at svn.parrot.org
Thu Aug 6 22:10:24 UTC 2009
Author: cotto
Date: Thu Aug 6 22:10:17 2009
New Revision: 40434
URL: https://trac.parrot.org/parrot/changeset/40434
Log:
[profiling] code cleanup and mildly better error messages and failure modes
Modified:
branches/pluggable_runcore/src/runcore/cores.c
branches/pluggable_runcore/tools/dev/pprof2cg.pl
Modified: branches/pluggable_runcore/src/runcore/cores.c
==============================================================================
--- branches/pluggable_runcore/src/runcore/cores.c Thu Aug 6 21:20:34 2009 (r40433)
+++ branches/pluggable_runcore/src/runcore/cores.c Thu Aug 6 22:10:17 2009 (r40434)
@@ -518,17 +518,18 @@
ASSERT_ARGS(runops_profile_core)
Parrot_Context_info prev_info, curr_info;
+ Parrot_Context *prev_ctx;
struct timespec preop, postop;
- opcode_t *old_pc;
+ opcode_t *prev_pc;
static FILE *prof_fd;
HUGEINTVAL op_time;
char unknown_sub[] = "(unknown sub)";
char unknown_file[] = "(unknown file)";
- static INTVAL interp_counter = 0;
+ static int interp_counter = 0;
- /* Hilarity ensues if inner runloops open and write to a separate FILE*, so
- * use a simple static counter to ensure that the FILE* only gets opened
- * and closed once. */
+ /* Hilarity ensues if an inner runloops opens and writes to a separate
+ * FILE*, so use a simple static counter to ensure that the FILE* only gets
+ * opened and closed once. */
if (interp_counter == 0) {
prof_fd = fopen("parrot.pprof", "w");
if (!prof_fd) {
@@ -538,10 +539,14 @@
}
interp_counter++;
+ fprintf(prof_fd, "NEW RUNLOOP (%d)\n", interp_counter);
+ prev_ctx = CONTEXT(interp);
Parrot_Context_get_info(interp, CONTEXT(interp), &curr_info);
fprintf(prof_fd, "F:%s\n", curr_info.file->strstart);
- fprintf(prof_fd, "S:%s\n", curr_info.subname->strstart);
+ fprintf(prof_fd, "S:%s;%s\n",
+ VTABLE_get_string(interp, prev_ctx->current_namespace)->strstart,
+ curr_info.subname->strstart);
while (pc) {
@@ -561,7 +566,8 @@
sub_preop = prev_info.subname->strstart;
CONTEXT(interp)->current_pc = pc;
- old_pc = pc;
+ prev_ctx = CONTEXT(interp);
+ prev_pc = pc;
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &preop);
DO_OP(pc, interp);
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &postop);
@@ -577,17 +583,20 @@
if (!sub_preop) sub_preop = unknown_sub;
if (!sub_postop) sub_postop = unknown_sub;
- if (old_pc) {
+ if (prev_pc) {
if (strcmp(file_preop, file_postop))
fprintf(prof_fd, "F:%s\n", file_postop);
if (strcmp(sub_preop, sub_postop))
- fprintf(prof_fd, "S:%s\n", sub_postop);
+ fprintf(prof_fd, "S:%s;%s\n",
+ VTABLE_get_string(interp, prev_ctx->current_namespace)->strstart,
+ sub_postop);
fprintf(prof_fd, "%d:%lli:%d:%s\n",
curr_info.line, op_time, (int)CONTEXT(interp)->recursion_depth,
- (interp->op_info_table)[*old_pc].name);
+ (interp->op_info_table)[*prev_pc].name);
}
}
+ fprintf(prof_fd, "END OF RUNLOOP (%d)\n", interp_counter);
interp_counter--;
if (interp_counter == 0)
Modified: branches/pluggable_runcore/tools/dev/pprof2cg.pl
==============================================================================
--- branches/pluggable_runcore/tools/dev/pprof2cg.pl Thu Aug 6 21:20:34 2009 (r40433)
+++ branches/pluggable_runcore/tools/dev/pprof2cg.pl Thu Aug 6 22:10:17 2009 (r40434)
@@ -8,8 +8,8 @@
use Data::Dumper;
#what about throw and rethrow?
-my @call_ops = (qw{invoke invokecc});
-my @return_ops = (qw{yield returncc tailcall});
+my @call_ops = (qw{invoke invokecc callmethod callmethodcc});
+my @return_ops = (qw{yield returncc tailcall tailcallmethod});
my @prof_stack = ();
my %stats;
@@ -17,30 +17,42 @@
my ($call, $return) = (0,0);
my $prev_func = '';
my $total_time = 0;
+my $func_num = 0;
my ($prev_line, $new_line, $op_num) = (0,0,0);
+sub maybe_say($@) {
+ #say $@;
+}
+
while (<>) {
if (/^F:(.*)$/) {
$file = $1;
- #say "found file $file";
+ maybe_say "found file $file";
$stats{$file} = {} unless exists $stats{$file};
}
elsif (/S:(.*)$/) {
$prev_func = $func;
$func = $1;
- #say "found func $func";
+ maybe_say "found func $func";
$stats{$file}{$func} = {} unless exists $stats{$file}{$func};
if ($return) {
#pop the current func and op number off the stack
#the func is there mainly for debugging
+ unless (@prof_stack) {
+ die "tried to pop off an empty stack when returning from $func";
+ }
+ for my $frame (@prof_stack) {
+ my ($file, $func, $line, $op_num) = @{$frame};
+ maybe_say "($file,$func,$line,$op_num)";
+ }
($file, $func, $line, $op_num) = @{pop @prof_stack};
- #say "popped func $func, op $op_num off the stack";
+ maybe_say "popped func $func, op $op_num off the stack";
$stats{$file}{$func}{$line}{$op_num}{func_name} = $prev_func;
}
}
- elsif (/^(\d+):(\d+):(\d+):(\w+)$/) {
+ elsif (/^(\d+):(\d+):(\d+):(.*)$/) {
my ($line, $op_time, $rec_depth, $op) = ($1, $2, $3, $4);
$new_line = ($line != $prev_line);
@@ -56,7 +68,7 @@
$op_num++;
}
- #say "$func line #$line, op #$op_num is $op";
+ maybe_say "$func line #$line, op #$op_num is $op";
if ($new_line) {
$stats{$file}{$func}{$line} = {line_calls_func => 0}
@@ -75,8 +87,8 @@
$stats{$file}{$func}{$line}{$op_num}{hits}++;
}
- #say "calling a func" if $call;
- #say "returning from a func" if $return;
+ maybe_say "calling a func" if $call;
+ maybe_say "returning from a func" if $return;
if ($call) {
@@ -84,17 +96,23 @@
$op_num++;
if (!exists $stats{$file}{$func}{$line}{$op_num}) {
$stats{$file}{$func}{$line}{$op_num} = {
- time => 0,
- hits => 1,
- op => "FUNCTION_CALL",
+ time => 0,
+ hits => 1,
+ op => "FUNCTION_CALL",
+ func_name => "unknown_function$func_num",
};
+ $func_num++;
}
else {
$stats{$file}{$func}{$line}{$op_num}{hits}++;
}
- #say "pushed func $func, op $op_num onto the stack";
+ maybe_say "pushed func $func, op $op_num onto the stack";
push @prof_stack, [$file, $func, $line, $op_num];
+ for my $frame (@prof_stack) {
+ my ($file, $func, $line, $op_num) = @{$frame};
+ maybe_say "($file,$func,$line,$op_num)";
+ }
$stats{$file}{$func}{$line}{line_calls_func} = 1;
}
else {
@@ -176,3 +194,5 @@
}
}
}
+
+say OUT_FH "totals: $total_time";
More information about the parrot-commits
mailing list