This adds timing information to profiling. Yeah, that means we have to
call Parrot_floatval_time() twice for each op. You'll probably need to
iterate many, many times to see any time at all--for example, the
program:
set I0, 10000
FOO:
dec I0
if I0, FOO
end
produces:
Operation profile:
CODE OP FULL NAME CALLS TOTAL TIME AVG TIME
----- ------------ ------------ ---------- ----------
0 end 1 0.000000 0.000000
72 set_i_ic 1 0.000000 0.000000
296 if_i_ic 100000 0.139997 0.000001
332 dec_i 100000 0.231001 0.000002
----- ------------ ------------ ---------- ----------
4 200002 0.370998 0.000002
That's mostly a testimonial to how fast Parrot is. :^)
--Brent Dax
[EMAIL PROTECTED]
Parrot Configure pumpking and regex hacker
<obra> mmmm. hawt sysadmin chx0rs
<lathos> This is sad. I know of *a* hawt sysamin chx0r.
<obra> I know more than a few.
<lathos> obra: There are two? Are you sure it's not the same one?
--- ../../parrot-cvs/parrot/interpreter.c Thu Jan 10 16:04:54 2002
+++ interpreter.c Sun Jan 13 00:48:12 2002
@@ -400,12 +400,13 @@
unsigned int i;
if (interpreter->profile == NULL) {
- interpreter->profile = (INTVAL *)
- mem_sys_allocate(interpreter->op_count *
sizeof(INTVAL));
+ interpreter->profile = (ProfData *)
+ mem_sys_allocate(interpreter->op_count *
sizeof(ProfData));
}
for (i = 0; i < interpreter->op_count; i++) {
- interpreter->profile[i] = 0;
+ interpreter->profile[i].numcalls = 0;
+ interpreter->profile[i].time = 0.0;
}
}
@@ -529,7 +530,7 @@
/* Done. Return and be done with it */
interpreter->code = (struct PackFile *)NULL;
- interpreter->profile = (INTVAL *)NULL;
+ interpreter->profile = (ProfData *)NULL;
interpreter->resume_flag = 0;
interpreter->resume_offset = 0;
--- ../../parrot-cvs/parrot/runops_cores.c Tue Jan 1 10:26:42 2002
+++ runops_cores.c Sun Jan 13 01:02:04 2002
@@ -44,6 +44,8 @@
opcode_t * code_start;
INTVAL code_size;
opcode_t * code_end;
+ opcode_t * lastpc;
+ FLOATVAL time;
code_start = (opcode_t *)interpreter->code->byte_code;
code_size = interpreter->code->byte_code_size;
@@ -55,13 +57,18 @@
while (pc && pc >= code_start && pc < code_end ) {
if (interpreter->flags & PARROT_PROFILE_FLAG) {
- interpreter->profile[*pc]++;
+ interpreter->profile[*pc].numcalls++;
+ lastpc=pc;
+ time=Parrot_floatval_time();
}
DO_OP(pc, interpreter);
if (interpreter->flags & PARROT_TRACE_FLAG) {
trace_op(interpreter, code_start, code_end, pc);
+ }
+ if (interpreter->flags & PARROT_PROFILE_FLAG) {
+ interpreter->profile[*lastpc].time +=
Parrot_floatval_time() - time;
}
}
--- ../../parrot-cvs/parrot/test_main.c Wed Jan 9 09:26:34 2002
+++ test_main.c Sun Jan 13 01:07:36 2002
@@ -255,26 +255,37 @@
unsigned int j;
int op_count = 0;
int call_count = 0;
+ FLOATVAL time = 0.0;
printf("Operation profile:\n\n");
- printf(" CODE OP FULL NAME CALLS\n");
- printf(" ----- ------------ ------------\n");
+ printf(" CODE OP FULL NAME CALLS TOTAL TIME AVG
TIME \n");
+
printf(" ----- ------------ ------------ ---------- ----------\n");
for (j = 0; j < interpreter->op_count; j++) {
- if(interpreter->profile[j] > 0) {
+ if(interpreter->profile[j].numcalls > 0) {
op_count++;
- call_count += interpreter->profile[j];
+ call_count += interpreter->profile[j].numcalls;
+ time += interpreter->profile[j].time;
- printf(" %5d %-12s %12ld\n", j,
+ printf(" %5d %-12s %12ld %5.6f %5.6f\n", j,
interpreter->op_info_table[j].full_name,
- interpreter->profile[j]);
+ interpreter->profile[j].numcalls,
+ interpreter->profile[j].time,
+ interpreter->profile[j].time /
(FLOATVAL)interpreter->profile[j].numcalls
+ );
}
}
- printf(" ----- ------------ ------------\n");
- printf(" %5d %-12s %12d\n", op_count, "", call_count);
+
printf(" ----- ------------ ------------ ---------- ----------\n");
+ printf(" %5d %-12s %12d %5.6f %5.6f\n",
+ op_count,
+ "",
+ call_count,
+ time,
+ time / (FLOATVAL)call_count
+ );
}
}
--- ../../parrot-cvs/parrot/include\parrot\interpreter.h Thu Jan 10
16:04:56 2002
+++ include\parrot\interpreter.h Sun Jan 13 00:44:20 2002
@@ -28,6 +28,12 @@
STRING_FUNCS *(**string_funcs)(); /* String function table */
#endif
+typedef struct ProfData {
+ INTVAL numcalls;
+ FLOATVAL time;
+} ProfData;
+
+
struct Parrot_Interp {
struct IReg *int_reg; /* Current top of int reg stack */
struct NReg *num_reg; /* Current top of the float reg
stack */
@@ -57,7 +63,7 @@
INTVAL flags; /* Various interpreter flags
that signal that runops
should do something */
- INTVAL * profile; /* The array where we keep
the profile counters */
+ ProfData* profile; /* The array where we keep
the profile counters */
INTVAL resume_flag;
size_t resume_offset;
