[svn:parrot] r40821 - in branches/pluggable_runcore: . config/gen config/gen/platform config/gen/platform/generic config/gen/platform/win32 include/parrot src/runcore tools/dev

cotto at svn.parrot.org cotto at svn.parrot.org
Thu Aug 27 02:13:50 UTC 2009


Author: cotto
Date: Thu Aug 27 02:13:48 2009
New Revision: 40821
URL: https://trac.parrot.org/parrot/changeset/40821

Log:
[profiling] first attempt at an abstraction layer for high-resolution timing, including an untested win32 implementation
also, add context and sub addresses to output, clean up runcore code

Added:
   branches/pluggable_runcore/config/gen/platform/generic/hires_timer.c   (contents, props changed)
   branches/pluggable_runcore/config/gen/platform/win32/hires_timer.c   (contents, props changed)
Modified:
   branches/pluggable_runcore/MANIFEST
   branches/pluggable_runcore/config/gen/platform.pm
   branches/pluggable_runcore/config/gen/platform/platform_interface.h
   branches/pluggable_runcore/include/parrot/runcore_api.h
   branches/pluggable_runcore/src/runcore/cores.c
   branches/pluggable_runcore/tools/dev/pprof2cg.pl   (props changed)

Modified: branches/pluggable_runcore/MANIFEST
==============================================================================
--- branches/pluggable_runcore/MANIFEST	Wed Aug 26 22:58:27 2009	(r40820)
+++ branches/pluggable_runcore/MANIFEST	Thu Aug 27 02:13:48 2009	(r40821)
@@ -1,7 +1,7 @@
 # ex: set ro:
 # $Id$
 #
-# generated by tools/dev/mk_manifest_and_skip.pl Thu Aug 20 05:31:24 2009 UT
+# generated by tools/dev/mk_manifest_and_skip.pl Thu Aug 27 01:08:17 2009 UT
 #
 # See below for documentation on the format of this file.
 #
@@ -341,6 +341,7 @@
 config/gen/platform/generic/dl.h                            []
 config/gen/platform/generic/env.c                           []
 config/gen/platform/generic/exec.c                          []
+config/gen/platform/generic/hires_timer.c                   []
 config/gen/platform/generic/io.h                            []
 config/gen/platform/generic/itimer.c                        []
 config/gen/platform/generic/math.c                          []
@@ -368,6 +369,7 @@
 config/gen/platform/win32/dl.c                              []
 config/gen/platform/win32/env.c                             []
 config/gen/platform/win32/exec.c                            []
+config/gen/platform/win32/hires_timer.c                     []
 config/gen/platform/win32/io.h                              []
 config/gen/platform/win32/misc.c                            []
 config/gen/platform/win32/misc.h                            []

Modified: branches/pluggable_runcore/config/gen/platform.pm
==============================================================================
--- branches/pluggable_runcore/config/gen/platform.pm	Wed Aug 26 22:58:27 2009	(r40820)
+++ branches/pluggable_runcore/config/gen/platform.pm	Thu Aug 27 02:13:48 2009	(r40821)
@@ -223,6 +223,7 @@
         memexec.c
         exec.c
         misc.c
+        hires_timer.c
         /;
 
     my $plat_c = q{src/platform.c};

Added: branches/pluggable_runcore/config/gen/platform/generic/hires_timer.c
==============================================================================
--- /dev/null	00:00:00 1970	(empty, because file is newly added)
+++ branches/pluggable_runcore/config/gen/platform/generic/hires_timer.c	Thu Aug 27 02:13:48 2009	(r40821)
@@ -0,0 +1,94 @@
+/*
+ * $Id$
+ * Copyright (C) 2009, Parrot Foundation.
+ */
+
+/*
+
+=head1 NAME
+
+config/gen/platform/generic/hires_timer.c
+
+=head1 DESCRIPTION
+
+High-resolution timer support
+
+=head2 Functions
+
+=over 4
+
+=cut
+
+*/
+
+#include <time.h>
+#include "parrot/platform.h"
+
+
+/* Using real time can introduce error.  Hopefully all platforms will have
+ * hints that specify a more useful clock.
+ */
+
+#ifndef CLOCK_BEST
+#  if defined(CLOCK_PROCESS_CPUTIME_ID)
+#    define CLOCK_BEST CLOCK_PROCESS_CPUTIME_ID
+#  elif defined(CLOCK_PROF)
+#    define CLOCK_BEST CLOCK_PROF
+#  else
+#    define CLOCK_BEST CLOCK_REALTIME
+#  endif
+#endif
+
+#define TIME_IN_NS(n) ((n).tv_sec * 1000*1000*1000 + (n).tv_nsec)
+
+/*
+
+=item C<UHUGEINTVAL Parrot_hires_get_time()>
+
+Return a high-resolution number representing how long Parrot has been running.
+
+=cut
+
+*/
+
+UHUGEINTVAL Parrot_hires_get_time()
+{
+    struct timespec ts;
+    clock_gettime(CLOCK_BEST, &ts);
+    return TIME_IN_NS(ts);
+}
+
+/*
+
+=item C<UINTVAL Parrot_hires_get_resolution()>
+
+Return the number of ns that each time unit from Parrot_hires_get_time represents.
+
+=cut
+
+*/
+
+UINTVAL Parrot_hires_get_resolution()
+{
+    struct timespec ts;
+    clock_getres(CLOCK_BEST, &ts);
+    return (UINTVAL)TIME_IN_NS(ts);
+}
+
+
+
+
+/*
+
+=back
+
+=cut
+
+*/
+
+/*
+ * Local variables:
+ *   c-file-style: "parrot"
+ * End:
+ * vim: expandtab shiftwidth=4:
+ */

Modified: branches/pluggable_runcore/config/gen/platform/platform_interface.h
==============================================================================
--- branches/pluggable_runcore/config/gen/platform/platform_interface.h	Wed Aug 26 22:58:27 2009	(r40820)
+++ branches/pluggable_runcore/config/gen/platform/platform_interface.h	Thu Aug 27 02:13:48 2009	(r40821)
@@ -126,6 +126,13 @@
 
 #endif
 
+/*
+ * high-resolution timer support
+ */
+
+UHUGEINTVAL Parrot_hires_get_time(void);
+UINTVAL     Parrot_hires_get_resolution(void);
+
 
 struct parrot_string_t;
 INTVAL Parrot_Run_OS_Command(Interp*, struct parrot_string_t *);

Added: branches/pluggable_runcore/config/gen/platform/win32/hires_timer.c
==============================================================================
--- /dev/null	00:00:00 1970	(empty, because file is newly added)
+++ branches/pluggable_runcore/config/gen/platform/win32/hires_timer.c	Thu Aug 27 02:13:48 2009	(r40821)
@@ -0,0 +1,75 @@
+/*
+ * $Id$
+ * Copyright (C) 2009, Parrot Foundation.
+ */
+
+/*
+
+=head1 NAME
+
+config/gen/platform/win32/hires_timer.c
+
+=head1 DESCRIPTION
+
+High-resolution timer support for win32
+
+=head2 Functions
+
+=over 4
+
+=cut
+
+*/
+
+
+#define TIME_IN_NS(n) ((n).dwHighDateTime * 2^32 + (n).dwLowDateTime)
+
+/*
+
+=item C<UHUGEINTVAL Parrot_hires_get_time()>
+
+Return a high-resolution number representing how long Parrot has been running.
+
+=cut
+
+*/
+
+UHUGEINTVAL Parrot_hires_get_time()
+{
+    FILETIME creation, exit, kernel, user;
+    GetProcessTimes(GetCurrentProcess(), &creation, &exit, &kernel, &user);
+    return TIME_IN_NS(kernel) + TIME_IN_NS(user);
+}
+
+/*
+
+=item C<UINTVAL Parrot_hires_get_resolution()>
+
+Return the number of ns that each time unit from Parrot_hires_get_time represents.
+
+=cut
+
+*/
+
+UINTVAL Parrot_hires_get_resolution()
+{
+    return 100;
+}
+
+
+
+
+/*
+
+=back
+
+=cut
+
+*/
+
+/*
+ * Local variables:
+ *   c-file-style: "parrot"
+ * End:
+ * vim: expandtab shiftwidth=4:
+ */

Modified: branches/pluggable_runcore/include/parrot/runcore_api.h
==============================================================================
--- branches/pluggable_runcore/include/parrot/runcore_api.h	Wed Aug 26 22:58:27 2009	(r40820)
+++ branches/pluggable_runcore/include/parrot/runcore_api.h	Thu Aug 27 02:13:48 2009	(r40821)
@@ -57,11 +57,10 @@
     UINTVAL                  level;      /* how many nested runloops */
     UINTVAL                  time_size;  /* how big is the following array */
     UHUGEINTVAL             *time;       /* time spent between DO_OP and start/end of a runcore */
-    /* XXX: this will need to be made cross-platform */
-    struct timespec          runcore_start;
-    struct timespec          op_start;
-    struct timespec          op_finish;
-    struct timespec          runcore_finish;
+    UHUGEINTVAL              runcore_start;
+    UHUGEINTVAL              op_start;
+    UHUGEINTVAL              op_finish;
+    UHUGEINTVAL              runcore_finish;
 };
 
 

Modified: branches/pluggable_runcore/src/runcore/cores.c
==============================================================================
--- branches/pluggable_runcore/src/runcore/cores.c	Wed Aug 26 22:58:27 2009	(r40820)
+++ branches/pluggable_runcore/src/runcore/cores.c	Thu Aug 27 02:13:48 2009	(r40821)
@@ -266,8 +266,6 @@
 #  define CLOCK_BEST CLOCK_REALTIME
 #endif
 
-#define TIME_IN_NS(n) ((n).tv_sec * 1000*1000*1000 + (n).tv_nsec)
-
 
 /* HEADERIZER HFILE: include/parrot/runcore_api.h */
 
@@ -1076,15 +1074,16 @@
 ARGIN(opcode_t *pc))
 {
     ASSERT_ARGS(runops_profiling_core)
-            Parrot_Context_info prev_info, curr_info;
-    Parrot_Context     *prev_ctx;
-    opcode_t           *prev_pc;
+            Parrot_Context_info preop_info, postop_info;
+    Parrot_Context     *preop_ctx;
+    PMC                *preop_sub;
+    opcode_t           *preop_pc;
     static FILE        *prof_fd;
     HUGEINTVAL          op_time;
     char                unknown_sub[]  = "<unknown sub>";
     char                unknown_file[] = "<unknown file>";
 
-    clock_gettime(CLOCK_BEST, &runcore->runcore_start);
+    runcore->runcore_start = Parrot_hires_get_time();
 
     /* if we're in a nested runloop, */
     if (runcore->level != 0) {
@@ -1097,21 +1096,20 @@
 
         /* store the time between DO_OP and the start of this runcore in this
          * op's running total */
-        runcore->time[runcore->level] =
-            TIME_IN_NS(runcore->runcore_start) - TIME_IN_NS(runcore->op_start);
+        runcore->time[runcore->level] = runcore->runcore_start - runcore->op_start;
     }
 
-    prev_ctx = CONTEXT(interp);
-    Parrot_Context_get_info(interp, CONTEXT(interp), &curr_info);
-    fprintf(runcore->prof_fd, "F:%s\n", curr_info.file->strstart);
+    preop_ctx = CONTEXT(interp);
+    Parrot_Context_get_info(interp, CONTEXT(interp), &postop_info);
+    fprintf(runcore->prof_fd, "F:%s\n", postop_info.file->strstart);
     fprintf(runcore->prof_fd, "S:%s;%s\n",
-            VTABLE_get_string(interp, prev_ctx->current_namespace)->strstart,
-            curr_info.subname->strstart);
+            VTABLE_get_string(interp, preop_ctx->current_namespace)->strstart,
+            postop_info.subname->strstart);
 
     while (pc) {
 
-        char *file_preop, *file_postop;
-        char *sub_preop,  *sub_postop;
+        char *preop_file_name, *postop_file_name;
+        char *preop_sub_name,  *postop_sub_name;
         INTVAL get_new_info = 1;
 
         if (pc < code_start || pc >= code_end) {
@@ -1120,78 +1118,83 @@
         }
 
         /* avoid an extra call to Parrot_Context_get_info */
-        mem_sys_memcopy(&prev_info, &curr_info, sizeof (Parrot_Context_info));
+        mem_sys_memcopy(&preop_info, &postop_info, sizeof (Parrot_Context_info));
 
-        Parrot_Context_get_info(interp, CONTEXT(interp), &curr_info);
-        file_preop = prev_info.file->strstart;
-        sub_preop  = prev_info.subname->strstart;
+        Parrot_Context_get_info(interp, CONTEXT(interp), &postop_info);
+        preop_file_name = preop_info.file->strstart;
+        preop_sub_name  = preop_info.subname->strstart;
 
         CONTEXT(interp)->current_pc = pc;
-        prev_ctx = CONTEXT(interp);
-        prev_pc = pc;
+        preop_ctx = CONTEXT(interp);
+        preop_sub = preop_ctx->current_sub;
+        preop_pc = pc;
 
         runcore->level++;
         Profiling_exit_check_CLEAR(runcore);
-        clock_gettime(CLOCK_BEST, &runcore->op_start);
+        runcore->op_start = Parrot_hires_get_time();
         DO_OP(pc, interp);
-        clock_gettime(CLOCK_BEST, &runcore->op_finish);
+        runcore->op_finish = Parrot_hires_get_time();
 
         if (Profiling_exit_check_TEST(runcore)) {
-            op_time = TIME_IN_NS(runcore->op_finish) - TIME_IN_NS(runcore->runcore_finish);
+            op_time  = runcore->op_finish - runcore->runcore_finish;
             op_time += runcore->time[runcore->level];
             runcore->time[runcore->level] = 0;
         }
         else {
-            op_time = TIME_IN_NS(runcore->op_finish) - TIME_IN_NS(runcore->op_start);
+            op_time = runcore->op_finish - runcore->op_start;
         }
         runcore->level--;
 
-        file_postop = curr_info.file->strstart;
-        sub_postop  = curr_info.subname->strstart;
+        postop_file_name = postop_info.file->strstart;
+        postop_sub_name  = postop_info.subname->strstart;
 
-        if (!file_preop)  file_preop  = unknown_file;
-        if (!file_postop) file_postop = unknown_file;
-        if (!sub_preop)   sub_preop   = unknown_sub;
-        if (!sub_postop)  sub_postop  = unknown_sub;
+        if (!preop_file_name)  preop_file_name  = unknown_file;
+        if (!postop_file_name) postop_file_name = unknown_file;
+        if (!preop_sub_name)   preop_sub_name   = unknown_sub;
+        if (!postop_sub_name)  postop_sub_name  = unknown_sub;
 
-        if (prev_pc) {
+        if (preop_pc) {
 
             PMC                 *invoked;
+            /* XXX: find a more descriptive name */
             Parrot_Context_info  info;
 
             Parrot_Context_get_info(interp, CONTEXT(interp), &info);
 
-            if (strcmp(file_preop, file_postop))
-                fprintf(runcore->prof_fd, "F:%s\n", file_postop);
+            if (strcmp(preop_file_name, postop_file_name))
+                fprintf(runcore->prof_fd, "F:%s\n", postop_file_name);
 
-            if (strcmp(sub_preop, sub_postop))
+            if (strcmp(preop_sub_name, postop_sub_name))
                 fprintf(runcore->prof_fd, "S:%s;%s\n",
-                        VTABLE_get_string(interp, prev_ctx->current_namespace)->strstart,
-                        sub_postop);
+                        VTABLE_get_string(interp, preop_ctx->current_namespace)->strstart,
+                        postop_sub_name);
+
+            fprintf(runcore->prof_fd, "%d:%lli:%s:sub at 0x%x:ctx at 0x%x\n",
+                    postop_info.line, op_time,
+                    (interp->op_info_table)[*preop_pc].name,
+                    (unsigned int) preop_sub, (unsigned int) preop_ctx);
 
-            /* a change in context implies some sort of change in control flow */
-            if (prev_ctx != CONTEXT(interp) || Profiling_first_op_TEST(runcore)) {
+            if (preop_sub != CONTEXT(interp)->current_sub || Profiling_first_op_TEST(runcore)) {
                 Profiling_first_op_CLEAR(runcore);
-                if (info.subname->strstart && strcmp(sub_postop, info.subname->strstart)) {
-                    fprintf(runcore->prof_fd, "CS:%s at 0x%x\n",
-                            info.fullname->strstart, (unsigned int) CONTEXT(interp));
+
+                if (info.subname->strstart) {
+                    fprintf(runcore->prof_fd, "CS:%s;%s at 0x%x\n",
+                            VTABLE_get_string(interp, CONTEXT(interp)->current_namespace)->strstart,
+                            info.subname->strstart,
+                            (unsigned int) CONTEXT(interp)->current_sub);
                 }
                 else {
                     fprintf(runcore->prof_fd, "CS:%s;<unknown sub>@0x%x\n",
                             VTABLE_get_string(interp, CONTEXT(interp)->current_namespace)->strstart,
-                            (unsigned int) CONTEXT(interp));
+                            (unsigned int) CONTEXT(interp)->current_sub);
                 }
             }
 
-            fprintf(runcore->prof_fd, "%d:%lli:%s:0x%x\n",
-                    curr_info.line, op_time,
-                    (interp->op_info_table)[*prev_pc].name,
-                    (unsigned int) CONTEXT(interp));
-        } /* if (prev_pc) */
+        } /* if (preop_pc) */
     } /* while (pc) */
 
     Profiling_exit_check_SET(runcore);
-    clock_gettime(CLOCK_BEST, &runcore->runcore_finish);
+    runcore->runcore_finish = Parrot_hires_get_time();;
     return pc;
 
 }


More information about the parrot-commits mailing list