[m-rev.] for review: report real times in benchmarking.report_stats
Peter Wang
wangp at students.cs.mu.oz.au
Mon Aug 7 15:45:01 AEST 2006
Estimated hours taken: 1
Branches: main
Let benchmark.report_stats/0 report real times on POSIX platforms.
configure.in:
Check for time.h and gettimeofday().
runtime/mercury_conf.h.in:
Add MR_HAVE_TIME_H, MR_HAVE_GETTIMEOFDAY.
Unrelated change: add MR_HAVE_PTHREAD_H.
runtime/mercury_timing.c:
runtime/mercury_timing.h:
Add `MR_get_real_milliseconds'.
runtime/mercury_wrapper.c:
runtime/mercury_wrapper.h:
Rename MR_time_* globals to MR_user_time_*.
Add and initialise MR_real_time_* globals.
library/benchmarking.m:
Output real times in ML_report_stats().
Correct spelling of milliseconds.
java/runtime/Native.c:
java/runtime/Native.java.in:
trace/mercury_trace_declarative.c:
Correct spelling of milliseconds.
Index: configure.in
===================================================================
RCS file: /home/mercury1/repository/mercury/configure.in,v
retrieving revision 1.460
diff -u -r1.460 configure.in
--- configure.in 4 Aug 2006 04:30:35 -0000 1.460
+++ configure.in 7 Aug 2006 04:57:47 -0000
@@ -920,7 +920,8 @@
open close dup dup2 fdopen fileno fstat stat lstat isatty \
getpid setpgid fork execlp wait kill \
grantpt unlockpt ptsname tcgetattr tcsetattr ioctl \
- access sleep opendir readdir closedir mkdir symlink readlink
+ access sleep opendir readdir closedir mkdir symlink readlink \
+ gettimeofday
#-----------------------------------------------------------------------------#
MERCURY_CHECK_FOR_HEADERS( \
@@ -928,7 +929,7 @@
asm/sigcontext.h sys/param.h sys/time.h sys/times.h \
sys/types.h sys/stat.h fcntl.h termios.h sys/ioctl.h \
sys/stropts.h windows.h dirent.h getopt.h malloc.h \
- semaphore.h pthread.h)
+ semaphore.h pthread.h time.h)
if test "$MR_HAVE_GETOPT_H" = 1; then
GETOPT_H_AVAILABLE=yes
Index: java/runtime/Native.c
===================================================================
RCS file: /home/mercury1/repository/mercury/java/runtime/Native.c,v
retrieving revision 1.2
diff -u -r1.2 Native.c
--- java/runtime/Native.c 12 Feb 2004 02:24:35 -0000 1.2
+++ java/runtime/Native.c 7 Aug 2006 04:57:47 -0000
@@ -42,10 +42,10 @@
/*
* Class: Native
- * Method: get_user_cpu_miliseconds
+ * Method: get_user_cpu_milliseconds
* Signature: ()I
*/
-JNIEXPORT jint JNICALL Java_mercury_runtime_Native_get_1user_1cpu_1miliseconds(
+JNIEXPORT jint JNICALL Java_mercury_runtime_Native_get_1user_1cpu_1milliseconds(
JNIEnv *, jclass);
#include "mercury_imp.h"
@@ -108,9 +108,9 @@
}
JNIEXPORT jint JNICALL
-Java_mercury_runtime_Native_get_1user_1cpu_1miliseconds(
+Java_mercury_runtime_Native_get_1user_1cpu_1milliseconds(
JNIEnv *env, jclass obj)
{
- return MR_get_user_cpu_miliseconds();
+ return MR_get_user_cpu_milliseconds();
}
Index: java/runtime/Native.java.in
===================================================================
RCS file: /home/mercury1/repository/mercury/java/runtime/Native.java.in,v
retrieving revision 1.4
diff -u -r1.4 Native.java.in
--- java/runtime/Native.java.in 12 Feb 2004 02:24:35 -0000 1.4
+++ java/runtime/Native.java.in 7 Aug 2006 04:58:12 -0000
@@ -138,10 +138,10 @@
public static native int clk_tck();
/*
- ** get_user_cpu_miliseconds():
+ ** get_user_cpu_milliseconds():
** Native method to return the CPU time consumed by the process,
- ** in miliseconds, from an arbitrary initial time.
+ ** in milliseconds, from an arbitrary initial time.
*/
- public static native int get_user_cpu_miliseconds();
+ public static native int get_user_cpu_milliseconds();
}
Index: library/benchmarking.m
===================================================================
RCS file: /home/mercury1/repository/mercury/library/benchmarking.m,v
retrieving revision 1.69
diff -u -r1.69 benchmarking.m
--- library/benchmarking.m 19 Apr 2006 05:17:49 -0000 1.69
+++ library/benchmarking.m 7 Aug 2006 04:57:47 -0000
@@ -123,7 +123,7 @@
#include <stdlib.h>
#include ""mercury_prof_mem.h""
#include ""mercury_heap_profile.h""
-#include ""mercury_wrapper.h"" /* for MR_time_at_last_stat */
+#include ""mercury_wrapper.h"" /* for MR_user_time_at_last_stat */
#ifdef MR_MPROF_PROFILE_MEMORY
@@ -178,7 +178,8 @@
void
ML_report_stats(void)
{
- int time_at_prev_stat;
+ int user_time_at_prev_stat;
+ int real_time_at_prev_stat;
#if !defined(MR_HIGHLEVEL_CODE) || !defined(MR_CONSERVATIVE_GC)
MercuryEngine *eng;
#endif
@@ -191,16 +192,24 @@
** Print timing and stack usage information
*/
- time_at_prev_stat = MR_time_at_last_stat;
- MR_time_at_last_stat = MR_get_user_cpu_miliseconds();
+ user_time_at_prev_stat = MR_user_time_at_last_stat;
+ MR_user_time_at_last_stat = MR_get_user_cpu_milliseconds();
+
+ real_time_at_prev_stat = MR_real_time_at_last_stat;
+ MR_real_time_at_last_stat = MR_get_real_milliseconds();
#if !defined(MR_HIGHLEVEL_CODE) || !defined(MR_CONSERVATIVE_GC)
eng = MR_get_engine();
#endif
- fprintf(stderr, ""[Time: +%.3fs, %.3fs,"",
- (MR_time_at_last_stat - time_at_prev_stat) / 1000.0,
- (MR_time_at_last_stat - MR_time_at_start) / 1000.0
+ fprintf(stderr, ""[User time: +%.3fs, %.3fs,"",
+ (MR_user_time_at_last_stat - user_time_at_prev_stat) / 1000.0,
+ (MR_user_time_at_last_stat - MR_user_time_at_start) / 1000.0
+ );
+
+ fprintf(stderr, "" Real time: +%.3fs, %.3fs,"",
+ (MR_real_time_at_last_stat - real_time_at_prev_stat) / 1000.0,
+ (MR_real_time_at_last_stat - MR_real_time_at_start) / 1000.0
);
#ifndef MR_HIGHLEVEL_CODE
@@ -602,7 +611,7 @@
static {
if (mercury.runtime.Native.isAvailable()) {
- time_at_start = mercury.runtime.Native.get_user_cpu_miliseconds();
+ time_at_start = mercury.runtime.Native.get_user_cpu_milliseconds();
time_at_last_stat = time_at_start;
}
}
@@ -610,7 +619,7 @@
private static void
ML_report_stats() {
int time_at_prev_stat = time_at_last_stat;
- time_at_last_stat = get_user_cpu_miliseconds_1_p_0();
+ time_at_last_stat = get_user_cpu_milliseconds_1_p_0();
System.err.print(""[Time: "" +
((time_at_last_stat - time_at_prev_stat) / 1000.0) +
@@ -644,9 +653,9 @@
:- pragma promise_pure(benchmark_det/5).
benchmark_det(Pred, In, Out, Repeats, Time) :-
- impure get_user_cpu_miliseconds(StartTime),
+ impure get_user_cpu_milliseconds(StartTime),
impure benchmark_det_loop(Pred, In, Out, Repeats),
- impure get_user_cpu_miliseconds(EndTime),
+ impure get_user_cpu_milliseconds(EndTime),
Time0 = EndTime - StartTime,
cc_multi_equal(Time0, Time).
@@ -668,9 +677,9 @@
:- pragma promise_pure(benchmark_func/5).
benchmark_func(Func, In, Out, Repeats, Time) :-
- impure get_user_cpu_miliseconds(StartTime),
+ impure get_user_cpu_milliseconds(StartTime),
impure benchmark_func_loop(Func, In, Out, Repeats),
- impure get_user_cpu_miliseconds(EndTime),
+ impure get_user_cpu_milliseconds(EndTime),
Time0 = EndTime - StartTime,
cc_multi_equal(Time0, Time).
@@ -691,9 +700,9 @@
:- pragma promise_pure(benchmark_det_io/7).
benchmark_det_io(Pred, InA, OutA, InB, OutB, Repeats, Time) :-
- impure get_user_cpu_miliseconds(StartTime),
+ impure get_user_cpu_milliseconds(StartTime),
impure benchmark_det_loop_io(Pred, InA, OutA, InB, OutB, Repeats),
- impure get_user_cpu_miliseconds(EndTime),
+ impure get_user_cpu_milliseconds(EndTime),
Time = EndTime - StartTime.
% XXX cc_multi_equal(Time0, Time).
@@ -717,9 +726,9 @@
:- pragma promise_pure(benchmark_nondet/5).
benchmark_nondet(Pred, In, Count, Repeats, Time) :-
- impure get_user_cpu_miliseconds(StartTime),
+ impure get_user_cpu_milliseconds(StartTime),
impure benchmark_nondet_loop(Pred, In, Count, Repeats),
- impure get_user_cpu_miliseconds(EndTime),
+ impure get_user_cpu_milliseconds(EndTime),
Time0 = EndTime - StartTime,
cc_multi_equal(Time0, Time).
@@ -746,19 +755,19 @@
N > 0,
( true ; impure repeat(N - 1) ).
-:- impure pred get_user_cpu_miliseconds(int::out) is det.
+:- impure pred get_user_cpu_milliseconds(int::out) is det.
:- pragma foreign_proc("C",
- get_user_cpu_miliseconds(Time::out),
+ get_user_cpu_milliseconds(Time::out),
[will_not_call_mercury],
"
- Time = MR_get_user_cpu_miliseconds();
+ Time = MR_get_user_cpu_milliseconds();
").
% XXX Can't seem to get this to work -- perhaps Diagnostics isn't yet
% available in Beta 1 of the .NET framework.
% :- pragma foreign_proc("MC++",
-% get_user_cpu_miliseconds(_Time::out),
+% get_user_cpu_milliseconds(_Time::out),
% [will_not_call_mercury],
% "
% // This won't return the elapsed time since program start,
@@ -768,14 +777,14 @@
% ").
:- pragma foreign_proc("Java",
- get_user_cpu_miliseconds(Time::out),
+ get_user_cpu_milliseconds(Time::out),
[will_not_call_mercury],
"
if (mercury.runtime.Native.isAvailable()) {
- Time = mercury.runtime.Native.get_user_cpu_miliseconds();
+ Time = mercury.runtime.Native.get_user_cpu_milliseconds();
} else {
throw new java.lang.RuntimeException(
- ""get_user_cpu_miliseconds is not implemented in pure Java."" +
+ ""get_user_cpu_milliseconds is not implemented in pure Java."" +
""Native dynamic link library is required."");
}
").
Index: runtime/mercury_conf.h.in
===================================================================
RCS file: /home/mercury1/repository/mercury/runtime/mercury_conf.h.in,v
retrieving revision 1.55
diff -u -r1.55 mercury_conf.h.in
--- runtime/mercury_conf.h.in 4 Jul 2006 04:46:38 -0000 1.55
+++ runtime/mercury_conf.h.in 7 Aug 2006 04:57:47 -0000
@@ -153,6 +153,8 @@
#undef MR_HAVE_DIRENT_H
#undef MR_HAVE_MALLOC_H
#undef MR_HAVE_SEMAPHORE_H
+#undef MR_HAVE_PTHREAD_H
+#undef MR_HAVE_TIME_H
/*
** MR_HAVE_POSIX_TIMES is defined if we have the POSIX
@@ -240,6 +242,7 @@
** MR_HAVE_MKDIR we have the mkdir function.
** MR_HAVE_SYMLINK we have the symlink function.
** MR_HAVE_READLINK we have the readlink function.
+** MR_HAVE_GETTIMEOFDAY we have the gettimeofday function.
*/
#undef MR_HAVE_GETPID
#undef MR_HAVE_SETPGID
@@ -295,6 +298,7 @@
#undef MR_HAVE_MKDIR
#undef MR_HAVE_SYMLINK
#undef MR_HAVE_READLINK
+#undef MR_HAVE_GETTIMEOFDAY
/*
** We use mprotect() and signals to catch stack and heap overflows.
Index: runtime/mercury_timing.c
===================================================================
RCS file: /home/mercury1/repository/mercury/runtime/mercury_timing.c,v
retrieving revision 1.9
diff -u -r1.9 mercury_timing.c
--- runtime/mercury_timing.c 4 May 2005 07:42:17 -0000 1.9
+++ runtime/mercury_timing.c 7 Aug 2006 04:57:47 -0000
@@ -17,6 +17,14 @@
#include <sys/times.h> /* for times() and `struct tms' */
#endif
+#ifdef MR_HAVE_SYS_TIME_H
+ #include <sys/time.h>
+#endif
+
+#ifdef MR_HAVE_TIME_H
+ #include <time.h>
+#endif
+
#ifdef MR_WIN32_GETPROCESSTIMES
#include <windows.h>
#endif
@@ -24,7 +32,7 @@
#include "mercury_timing.h"
int
-MR_get_user_cpu_miliseconds(void)
+MR_get_user_cpu_milliseconds(void)
{
#if defined(MR_WIN32_GETPROCESSTIMES)
#define FILETIME_TO_MILLISEC(time, msec) \
@@ -50,13 +58,13 @@
return user_msec + kernel_msec;
#elif defined(MR_HAVE_SYS_TIMES_H)
#ifdef MR_CLOCK_TICKS_PER_SECOND
- const double ticks_per_milisecond = MR_CLOCK_TICKS_PER_SECOND / 1000.0;
+ const double ticks_per_millisecond = MR_CLOCK_TICKS_PER_SECOND / 1000.0;
struct tms t;
if (times(&t) == -1) {
return -1;
}
- return (int) (t.tms_utime / ticks_per_milisecond);
+ return (int) (t.tms_utime / ticks_per_millisecond);
#else
return -1;
#endif
@@ -64,3 +72,18 @@
return -1;
#endif
}
+
+int
+MR_get_real_milliseconds(void)
+{
+#if defined(MR_HAVE_GETTIMEOFDAY)
+ struct timeval tv;
+
+ if (gettimeofday(&tv, NULL) == -1) {
+ return -1;
+ }
+ return (tv.tv_sec * 1000) + (tv.tv_usec / 1000);
+#else
+ return -1;
+#endif
+}
Index: runtime/mercury_timing.h
===================================================================
RCS file: /home/mercury1/repository/mercury/runtime/mercury_timing.h,v
retrieving revision 1.4
diff -u -r1.4 mercury_timing.h
--- runtime/mercury_timing.h 13 Feb 2002 09:56:42 -0000 1.4
+++ runtime/mercury_timing.h 7 Aug 2006 04:57:47 -0000
@@ -7,7 +7,7 @@
/*
** mercury_timing.h - interface to timing routines.
** Defines `MR_CLOCK_TICKS_PER_SECOND'
-** and `MR_get_user_cpu_miliseconds()'.
+** and `MR_get_user_cpu_milliseconds()'.
*/
#ifndef MERCURY_TIMING_H
@@ -42,9 +42,15 @@
#endif
/*
-** MR_get_user_cpu_miliseconds() returns the CPU time consumed by the
-** process, in miliseconds, from an arbitrary initial time.
+** MR_get_user_cpu_milliseconds() returns the CPU time consumed by the
+** process, in milliseconds, from an arbitrary initial time.
*/
-int MR_get_user_cpu_miliseconds(void);
+int MR_get_user_cpu_milliseconds(void);
+
+/*
+** MR_get_real_milliseconds() returns the real time
+** in milliseconds, from an arbitrary initial time.
+*/
+int MR_get_real_milliseconds(void);
#endif /* MERCURY_TIMING_H */
Index: runtime/mercury_wrapper.c
===================================================================
RCS file: /home/mercury1/repository/mercury/runtime/mercury_wrapper.c,v
retrieving revision 1.162
diff -u -r1.162 mercury_wrapper.c
--- runtime/mercury_wrapper.c 5 Jul 2006 03:00:44 -0000 1.162
+++ runtime/mercury_wrapper.c 7 Aug 2006 04:57:47 -0000
@@ -261,9 +261,12 @@
static MR_bool MR_print_table_statistics = MR_FALSE;
/* timing */
-int MR_time_at_last_stat;
-int MR_time_at_start;
-static int MR_time_at_finish;
+int MR_user_time_at_last_stat;
+int MR_user_time_at_start;
+static int MR_user_time_at_finish;
+
+int MR_real_time_at_last_stat;
+int MR_real_time_at_start;
/* time profiling */
enum MR_TimeProfileMethod
@@ -1845,8 +1848,11 @@
MR_CONTEXT(MR_ctxt_nondetstack_zone)->MR_zone_min;
#endif
- MR_time_at_start = MR_get_user_cpu_miliseconds();
- MR_time_at_last_stat = MR_time_at_start;
+ MR_user_time_at_start = MR_get_user_cpu_milliseconds();
+ MR_user_time_at_last_stat = MR_user_time_at_start;
+
+ MR_real_time_at_start = MR_get_real_milliseconds();
+ MR_real_time_at_last_stat = MR_real_time_at_start;
for (repcounter = 0; repcounter < repeats; repcounter++) {
#ifdef MR_DEEP_PROFILING
@@ -1870,7 +1876,7 @@
}
if (use_own_timer) {
- MR_time_at_finish = MR_get_user_cpu_miliseconds();
+ MR_user_time_at_finish = MR_get_user_cpu_milliseconds();
}
#if defined(MR_USE_GCC_NONLOCAL_GOTOS) && defined(MR_LOWLEVEL_DEBUG)
@@ -1925,9 +1931,9 @@
}
#endif
- if (use_own_timer) {
+ if (use_own_timer) {
printf("%8.3fu ",
- ((double) (MR_time_at_finish - MR_time_at_start)) / 1000);
+ ((double) (MR_user_time_at_finish - MR_user_time_at_start)) / 1000);
}
#ifdef MR_TYPE_CTOR_STATS
Index: runtime/mercury_wrapper.h
===================================================================
RCS file: /home/mercury1/repository/mercury/runtime/mercury_wrapper.h,v
retrieving revision 1.73
diff -u -r1.73 mercury_wrapper.h
--- runtime/mercury_wrapper.h 24 Feb 2006 07:11:20 -0000 1.73
+++ runtime/mercury_wrapper.h 7 Aug 2006 04:57:47 -0000
@@ -268,8 +268,10 @@
extern char *MR_lld_print_more_min_max;
/* timing */
-extern int MR_time_at_start;
-extern int MR_time_at_last_stat;
+extern int MR_user_time_at_start;
+extern int MR_user_time_at_last_stat;
+extern int MR_real_time_at_start;
+extern int MR_real_time_at_last_stat;
/* time profiling */
enum MR_TimeProfileMethod {
Index: trace/mercury_trace_declarative.c
===================================================================
RCS file: /home/mercury1/repository/mercury/trace/mercury_trace_declarative.c,v
retrieving revision 1.100
diff -u -r1.100 mercury_trace_declarative.c
--- trace/mercury_trace_declarative.c 13 Jun 2006 09:49:03 -0000 1.100
+++ trace/mercury_trace_declarative.c 7 Aug 2006 04:57:47 -0000
@@ -1759,7 +1759,7 @@
MR_edt_inside = MR_FALSE;
MR_edt_building_supertree = create_supertree;
MR_edt_suspicion_accumulator = 0;
- MR_edt_start_time = MR_get_user_cpu_miliseconds();
+ MR_edt_start_time = MR_get_user_cpu_milliseconds();
MR_edt_first_event = event_info->MR_event_number;
/*
@@ -2307,7 +2307,7 @@
if (event_number != MR_edt_last_event &&
MR_edt_progress_last_tick == 0 &&
(MR_edt_start_time + MR_DECL_DISPLAY_PROGRESS_DELAY
- < MR_get_user_cpu_miliseconds()))
+ < MR_get_user_cpu_milliseconds()))
{
fprintf(MR_mdb_out, MR_DECL_PROGRESS_MESSAGE_SUBTREE);
fflush(MR_mdb_out);
@@ -2343,7 +2343,7 @@
*/
if (MR_edt_progress_last_tick == 0 &&
(MR_edt_start_time + MR_DECL_DISPLAY_PROGRESS_DELAY
- < MR_get_user_cpu_miliseconds()))
+ < MR_get_user_cpu_milliseconds()))
{
fprintf(MR_mdb_out, MR_DECL_PROGRESS_MESSAGE_SUPERTREE);
fflush(MR_mdb_out);
@@ -2351,7 +2351,7 @@
} else if ((MR_edt_start_time
+ (MR_edt_progress_last_tick + 1)
* MR_DECL_DISPLAY_PROGRESS_DELAY)
- < MR_get_user_cpu_miliseconds())
+ < MR_get_user_cpu_milliseconds())
{
MR_edt_progress_last_tick++;
fprintf(MR_mdb_out, MR_DECL_PROGRESS_TICK_STRING);
@@ -2430,7 +2430,7 @@
MR_edt_stats_total_constructed_nodes);
fprintf(stderr, "Current event = %i\n", MR_trace_event_number);
fprintf(stderr, "Total CPU time = %.2f\n",
- MR_get_user_cpu_miliseconds() / 1000.0);
+ MR_get_user_cpu_milliseconds() / 1000.0);
pid = getpid();
sprintf(cmdstr, "ps -p %i -o rss,vsz | tail -1 |"
"awk '{print \"RSS = \" $1 \"\\nVSZ = \" $2}' 1>&2", pid);
--------------------------------------------------------------------------
mercury-reviews mailing list
Post messages to: mercury-reviews at csse.unimelb.edu.au
Administrative Queries: owner-mercury-reviews at csse.unimelb.edu.au
Subscriptions: mercury-reviews-request at csse.unimelb.edu.au
--------------------------------------------------------------------------
More information about the reviews
mailing list