The attached patch (not for application, yet) hijacks parrot -p to emit
dprofpp-compatible output to standard error. This allows us to profile PIR
code at the PIR level (not the C level).
The caveats are:
* you'll have to edit out anything else that appears on standard error, or
dprofpp will complain
* you'll have to edit the file manually to add the magic old-style dprofpp
header, or dprofpp will complain
The header is:
#fOrTyTwO
$hz=100;
$XS_VERSION=’DProf 19970606’;
# All values are given in HZ
$rrun_utime=2; $rrun_stime=0; $rrun_rtime=7
PART2
Don't worry about that part. Just catenate it to the file, then run dprofpp
to your results.
Some of the statistics are a little bit wonky (probably because the header is
wrong-ish), but they should give you a much better idea of where your time is
going in PIR programs.
I may make this emit callgrind-compatible output in the future, but this was
the easiest proof of concept I could make work now. Enjoy.
-- c
=== src/runops_cores.c
==================================================================
--- src/runops_cores.c (revision 26556)
+++ src/runops_cores.c (local)
@@ -23,11 +23,16 @@
#include "parrot/embed.h"
#include "trace.h"
#include "interp_guts.h"
+#include <sys/times.h>
+#include <time.h>
#ifdef HAVE_COMPUTED_GOTO
# include "parrot/oplib/core_ops_cg.h"
#endif
+#define Parrot_report_entry(i) Parrot_report_profile((i), "+")
+#define Parrot_report_exit(i) Parrot_report_profile((i), "-")
+
/* HEADERIZER HFILE: src/runops_cores.h */
/* HEADERIZER BEGIN: static */
@@ -38,6 +43,10 @@
__attribute__nonnull__(1)
__attribute__nonnull__(2);
+static void Parrot_report_profile(PARROT_INTERP, const char *s)
+ __attribute__nonnull__(1)
+ __attribute__nonnull__(2);
+
/* HEADERIZER END: static */
/*
@@ -274,8 +283,9 @@
opcode_t *
runops_profile_core(PARROT_INTERP, ARGIN(opcode_t *pc))
{
- RunProfile * const profile = interp->profile;
- const opcode_t old_op = profile->cur_op;
+ RunProfile * const profile = interp->profile;
+ const opcode_t old_op = profile->cur_op;
+ int report_entry = 1;
/* if reentering the runloop, remember old op and calc time 'til now */
if (old_op)
@@ -283,13 +293,24 @@
Parrot_floatval_time() - profile->starttime;
while (pc) {/* && pc >= code_start && pc < code_end) */
- opcode_t cur_op;
+ opcode_t cur_op;
+ op_info_t op_info = interp->op_info_table[*pc];
CONTEXT(interp)->current_pc = pc;
profile->cur_op = cur_op = *pc + PARROT_PROF_EXTRA;
profile->starttime = Parrot_floatval_time();
profile->data[cur_op].numcalls++;
+ if (report_entry) {
+ Parrot_report_entry(interp);
+ report_entry = 0;
+ }
+
+ if (op_info.jump & PARROT_JUMP_ENEXT) {
+ Parrot_report_exit(interp);
+ report_entry = 1;
+ }
+
DO_OP(pc, interp);
/* profile->cur_op may be different, if exception was thrown */
@@ -306,6 +327,22 @@
return pc;
}
+void
+Parrot_report_profile(PARROT_INTERP, NOTNULL(const char *s))
+{
+ Parrot_Context *ctx = CONTEXT(interp);
+ struct tms buf;
+ Parrot_Context_info info;
+
+ Parrot_Context_get_info(interp, ctx, &info);
+ times(&buf);
+
+ fprintf( stderr, "%s %02d %02d %d %s::%s\n",
+ s, (int)buf.tms_utime, (int)buf.tms_stime, (int)time(NULL),
+ string_to_cstring(interp, info.nsname),
+ string_to_cstring(interp, info.subname) );
+}
+
/*
=back
