* configure.ac (ENABLE_RT_TIMING): Added.
authoredwin <none@none>
Wed, 5 Apr 2006 12:56:43 +0000 (12:56 +0000)
committeredwin <none@none>
Wed, 5 Apr 2006 12:56:43 +0000 (12:56 +0000)
* src/vm/jit/jit.c (ENABLE_RT_TIMING): Added code for real-time timing
of compiler passes.

* src/vm/jit/jit.h (jit_print_time_stats): Added.

* src/vm/vm.c (vm_exit_handler): Call jit_print_time_stats.

configure.ac
src/cacao/Makefile.am
src/vm/jit/jit.c
src/vm/jit/jit.h
src/vm/vm.c

index 6a880ecb55642b5bce7b64ae447765ecc3be9cdd..f93bc5d2ede03be7dd06b051299beb70c5988730 100644 (file)
@@ -373,6 +373,23 @@ if test x"${ENABLE_STATISTICS}" = "xyes"; then
 fi
 
 
+dnl check for compiler timing
+AC_MSG_CHECKING(whether real-time timing should be enabled)
+AC_ARG_ENABLE([rt-timing],
+              [AS_HELP_STRING(--enable-rt-timing,enable real-time timing [[default=no]])],
+              [case "${enableval}" in
+                   yes) ENABLE_RT_TIMING=yes;;
+                   *) ENABLE_RT_TIMING=no;;
+               esac],
+              [ENABLE_RT_TIMING=no])
+AC_MSG_RESULT(${ENABLE_RT_TIMING})
+AM_CONDITIONAL([ENABLE_RT_TIMING], test x"${ENABLE_RT_TIMING}" = "xyes")
+
+if test x"${ENABLE_RT_TIMING}" = "xyes"; then
+    AC_DEFINE([ENABLE_RT_TIMING], 1, [enable real-time timing])
+fi
+
+
 dnl check for JVMTI
 AC_MSG_CHECKING(whether to compile JVMTI support)
 AC_ARG_ENABLE([jvmti],
index 5737f8559c54509b376379d7deb7ec01640c1809..0fb0fa78863e09c51f96c78645fcf48056289c11 100644 (file)
@@ -28,7 +28,7 @@
 ##
 ## Changes:
 ##
-## $Id: Makefile.am 4690 2006-03-27 11:37:46Z twisti $
+## $Id: Makefile.am 4737 2006-04-05 12:56:43Z edwin $
 
 ## Process this file with automake to produce Makefile.in
 
@@ -104,6 +104,10 @@ CLASSPATH_LIBS = \
 #endif
 endif
 
+if ENABLE_RT_TIMING
+cacao_LDFLAGS += -lrt
+endif
+
 libcacaovm_la_SOURCES =
 
 libcacaovm_la_LIBADD = \
index 1f93d804ec5e399278573a26ddf5f33e4a7847f6..6a87e424b44a63c00c399b3d46a0a3f951943de7 100644 (file)
@@ -31,7 +31,7 @@
             Christian Thalinger
             Christian Ullrich
 
-   $Id: jit.c 4709 2006-03-30 10:14:22Z twisti $
+   $Id: jit.c 4737 2006-04-05 12:56:43Z edwin $
 
 */
 
 
 #include <assert.h>
 
+#if defined(ENABLE_RT_TIMING)
+#include <time.h>
+#include <errno.h>
+#endif
+
 #include "mm/memory.h"
 #include "native/native.h"
 #include "toolbox/logging.h"
@@ -1463,6 +1468,94 @@ u1 *jit_compile(methodinfo *m)
        return r;
 }
 
+/*****************************************************************************/
+/* TIMING OF COMPILER PASSES                                                 */
+/*****************************************************************************/
+
+#if defined(ENABLE_RT_TIMING)
+
+#define JIT_GET_TIME(ts) \
+       do { if (clock_gettime(CLOCK_THREAD_CPUTIME_ID,&(ts)) != 0) { \
+               fprintf(stderr,"could not get time: %s\n",strerror(errno)); \
+               abort(); \
+       }} while (0)
+
+#define JITTIME_CHECKS     0
+#define JITTIME_PARSE      1
+#define JITTIME_STACK      2
+#define JITTIME_TYPECHECK  3
+#define JITTIME_LOOP       4
+#define JITTIME_IFCONV     5
+#define JITTIME_ALLOC      6
+#define JITTIME_RPLPOINTS  7
+#define JITTIME_CODEGEN    8
+#define JITTIME_TOTAL      9
+#define JITTIME_N          10
+
+struct jit_time_stat {
+       int index;
+       const char *name;
+};
+
+static struct jit_time_stat jit_time_stat_defs[] = {
+       { JITTIME_CHECKS,    "checks at beginning" },
+       { JITTIME_PARSE,     "parse" },
+       { JITTIME_STACK,     "analyse_stack" },
+       { JITTIME_TYPECHECK, "typecheck" },
+       { JITTIME_LOOP,      "loop" },
+       { JITTIME_IFCONV,    "if conversion" },
+       { JITTIME_ALLOC,     "register allocation" },
+       { JITTIME_RPLPOINTS, "replacement point generation" },
+       { JITTIME_CODEGEN,   "codegen" },
+       { JITTIME_TOTAL,     "total" },
+       { 0,              NULL }
+};
+
+static long long jit_time_sum[JITTIME_N] = { 0 };
+
+static long jit_time_diff_usec(struct timespec *a,struct timespec *b)
+{
+       long diff;
+       time_t atime;
+
+       diff = (b->tv_nsec - a->tv_nsec) / 1000;
+       atime = a->tv_sec;
+       while (atime < b->tv_sec) {
+               atime++;
+               diff += 1000000;
+       }
+       return diff;
+}
+
+static void jit_time_diff(struct timespec *a,struct timespec *b,int index)
+{
+       long diff;
+
+       diff = jit_time_diff_usec(a,b);
+       jit_time_sum[index] += diff;
+}
+
+void jit_print_time_stats(FILE *file)
+{
+       struct jit_time_stat *stats;
+       double total;
+
+       stats = jit_time_stat_defs;
+       total = jit_time_sum[JITTIME_TOTAL];
+       while (stats->name) {
+               fprintf(file,"%12lld usec %3.0f%% %s\n",
+                               jit_time_sum[stats->index],
+                               (total != 0.0) ? jit_time_sum[stats->index] / total * 100.0 : 0.0,
+                               stats->name);
+               stats++;
+       }
+}
+
+#else /* !defined(ENABLE_RT_TIMING) */
+
+#define JIT_GET_TIME(ts)
+
+#endif /* defined(ENABLE_RT_TIMING) */
 
 /* jit_compile_intern **********************************************************
 
@@ -1476,6 +1569,14 @@ static u1 *jit_compile_intern(jitdata *jd)
        codegendata *cd;
        codeinfo    *code;
 
+#if defined(ENABLE_RT_TIMING)
+       struct timespec time_start,time_checks,time_parse,time_stack,
+                                       time_typecheck,time_loop,time_ifconv,time_alloc,
+                                       time_rplpoints,time_codegen;
+#endif
+       
+       JIT_GET_TIME(time_start);
+
        /* get required compiler data */
 
        m    = jd->m;
@@ -1532,6 +1633,8 @@ static u1 *jit_compile_intern(jitdata *jd)
        }
 #endif
 
+       JIT_GET_TIME(time_checks);
+
        /* call the compiler passes ***********************************************/
 
        DEBUG_JIT_COMPILEVERBOSE("Parsing: ");
@@ -1543,6 +1646,7 @@ static u1 *jit_compile_intern(jitdata *jd)
 
                return NULL;
        }
+       JIT_GET_TIME(time_parse);
 
        DEBUG_JIT_COMPILEVERBOSE("Parsing done: ");
        DEBUG_JIT_COMPILEVERBOSE("Analysing: ");
@@ -1554,6 +1658,7 @@ static u1 *jit_compile_intern(jitdata *jd)
 
                return NULL;
        }
+       JIT_GET_TIME(time_stack);
 
        DEBUG_JIT_COMPILEVERBOSE("Analysing done: ");
 
@@ -1571,6 +1676,7 @@ static u1 *jit_compile_intern(jitdata *jd)
                DEBUG_JIT_COMPILEVERBOSE("Typechecking done: ");
        }
 #endif
+       JIT_GET_TIME(time_typecheck);
 
 #if defined(ENABLE_LOOP)
        if (opt_loops) {
@@ -1579,12 +1685,14 @@ static u1 *jit_compile_intern(jitdata *jd)
                optimize_loops(jd);
        }
 #endif
+       JIT_GET_TIME(time_loop);
 
 #if defined(ENABLE_IFCONV)
        if (jd->flags & JITDATA_FLAG_IFCONV)
                if (!ifconv_static(jd))
                        return NULL;
 #endif
+       JIT_GET_TIME(time_ifconv);
 
 #if defined(ENABLE_JIT)
 # if defined(ENABLE_INTRP)
@@ -1615,6 +1723,7 @@ static u1 *jit_compile_intern(jitdata *jd)
        }
 # endif
 #endif /* defined(ENABLE_JIT) */
+       JIT_GET_TIME(time_alloc);
 
        /* Allocate memory for basic block profiling information. This
           _must_ be done after loop optimization and register allocation,
@@ -1629,6 +1738,7 @@ static u1 *jit_compile_intern(jitdata *jd)
 
        if (!replace_create_replacement_points(jd))
                return NULL;
+       JIT_GET_TIME(time_rplpoints);
 
        /* now generate the machine code */
 
@@ -1656,6 +1766,7 @@ static u1 *jit_compile_intern(jitdata *jd)
                return NULL;
        }
 #endif
+       JIT_GET_TIME(time_codegen);
 
        DEBUG_JIT_COMPILEVERBOSE("Generating code done: ");
 
@@ -1688,6 +1799,18 @@ static u1 *jit_compile_intern(jitdata *jd)
        code->prev = m->code;
        m->code = code;
 
+#if defined(ENABLE_RT_TIMING)
+       jit_time_diff(&time_start,&time_checks,JITTIME_CHECKS);
+       jit_time_diff(&time_checks,&time_parse,JITTIME_PARSE);
+       jit_time_diff(&time_parse,&time_stack,JITTIME_STACK);
+       jit_time_diff(&time_stack,&time_typecheck,JITTIME_TYPECHECK);
+       jit_time_diff(&time_typecheck,&time_loop,JITTIME_LOOP);
+       jit_time_diff(&time_loop,&time_alloc,JITTIME_ALLOC);
+       jit_time_diff(&time_alloc,&time_rplpoints,JITTIME_RPLPOINTS);
+       jit_time_diff(&time_rplpoints,&time_codegen,JITTIME_CODEGEN);
+       jit_time_diff(&time_start,&time_codegen,JITTIME_TOTAL);
+#endif
+
        /* return pointer to the methods entry point */
 
        return code->entrypoint;
index 48e0806c86604a2d2a0e0fcfc8c62cc042b51593..9e431bfbdcc68652db4a020f063be096ea771c8b 100644 (file)
@@ -30,7 +30,7 @@
    Changes: Christian Thalinger
                        Edwin Steiner
 
-   $Id: jit.h 4734 2006-04-05 09:57:55Z edwin $
+   $Id: jit.h 4737 2006-04-05 12:56:43Z edwin $
 
 */
 
@@ -957,6 +957,10 @@ void md_dcacheflush(u1 *addr, s4 nbytes);
 void intrp_md_init(void);
 #endif
 
+#if defined(ENABLE_RT_TIMING)
+void jit_print_time_stats(FILE *file);
+#endif
+
 #endif /* _JIT_H */
 
 
index 5447ac65531cfd673b7df36329fbe5f1189bcbea..dcb460d42eb3a790419d2f511011f34387eeb8ae 100644 (file)
@@ -65,6 +65,7 @@
 #include "vm/stringlocal.h"
 #include "vm/suck.h"
 #include "vm/vm.h"
+#include "vm/jit/jit.h"
 #include "vm/jit/asmpart.h"
 #include "vm/jit/profile/profile.h"
 
@@ -1337,6 +1338,10 @@ void vm_exit_handler(void)
                                       flags */
 #endif
 
+#if defined(ENABLE_RT_TIMING)
+       jit_print_time_stats(stderr);
+#endif
+
        if (opt_verbose || getcompilingtime || opt_stat) {
                log_text("CACAO terminated");