I have found myself unable to replicate the bogus time issue you have
observed.
I have tried using multiple tests on my linux box, along with the
27.stringbuf.virtuals test on both Solaris 10 and Solaris 9. Perhaps
automated testing will provide a replication of the issue.
Attached is another revised patch that moves the columns as proposed.
I'm not certain if the revised output looks as good for examples, but I
have no preference either way.
--Andrew Black
Martin Sebor wrote:
Andrew Black wrote:
How does a tweaked patch (and changelog) sound instead of a follow up
patch?
It sounds good except for the bogus times. I think we should fix
it before committing the changes. Also, wouldn't displaying the
times as the last two columns work better? I'm kind of used to
seeing the status and assertions together.
Martin
Index: display.h
===================================================================
--- display.h (revision 446647)
+++ display.h (working copy)
@@ -27,7 +27,39 @@
#ifndef RW_DISPLAY_H
#define RW_DISPLAY_H
+#if !defined (_WIN32) && !defined (_WIN64)
+# include <unistd.h> /* for _XOPEN_UNIX */
+#endif
+
+#ifdef _XOPEN_UNIX
+# include <sys/time.h> /* for struct timeval */
/**
+ Abstraction typedef for struct timeval using real struct
+*/
+typedef struct timeval rw_timeval;
+#else
+/**
+ Placeholder time_t for use in rw_timeval
+*/
+typedef long rw_time_t;
+/**
+ Placeholder suseconds_t for use in rw_timeval
+*/
+typedef long rw_suseconds_t;
+/**
+ Placeholder struct timeval to use if _XOPEN_UNIX isn't defined
+*/
+struct rw_timeval {
+ rw_time_t tv_sec;
+ rw_suseconds_t tv_usec;
+};
+/**
+ Abstraction typedef for struct timeval using placeholder struct
+*/
+typedef struct rw_timeval rw_timeval;
+#endif
+
+/**
Output format mode enumeration.
Used to determine the mode used in producing output.
@@ -74,7 +106,10 @@
char** argv; /**< Target argv array. */
int exit; /**< exit code for process. */
int signal; /**< Termination signal for process. */
+ int run; /**< Flag indicating if the process executed. */
enum ProcessStatus status; /**< Textual process status. */
+ rw_timeval user; /**< Elapsed user time spent in execution. */
+ rw_timeval sys; /**< Elapsed system time spent in execution. */
unsigned warn; /**< Number of (test) warnings. */
unsigned assert; /**< Number of (test) assertions. */
unsigned failed; /**< Number of failed (test) assertions. */
Index: exec.cpp
===================================================================
--- exec.cpp (revision 446647)
+++ exec.cpp (working copy)
@@ -51,6 +51,7 @@
#include <sys/types.h>
#include "cmdopt.h"
+#include "display.h" /* for struct target_status */
#include "util.h"
#include "exec.h"
@@ -697,6 +698,62 @@
#endif /* _XOPEN_UNIX */
/**
+ Calculates the amount of resources used by the child processes.
+
+ This method uses the getrusage() system call to calculate the resources
+ used by the child process. However, getrusage() only is able to calcualte
+ agragate usage by all child processes, not usage by a specific child process.
+ Therefore, we must keep a running tally of how many resources had been used
+ the previous time we calculated the usage. This difference is the resources
+ that were used by the process that just completed.
+
+ @param result target_status structure to populate with process usage.
+*/
+static void
+calculate_usage (struct target_status* result)
+{
+#ifdef _XOPEN_UNIX
+ static bool init = 0;
+ static struct rusage history;
+ struct rusage now;
+
+ assert (0 != result);
+
+ if (!init) {
+ memset (&history, 0, sizeof history);
+ init = 1;
+ }
+
+ if (0 != getrusage (RUSAGE_CHILDREN, &now)) {
+ warn ("Failed to retrieve child resource usage: %s", strerror (errno));
+ return;
+ }
+
+ /* time calculations */
+ result->user.tv_sec = now.ru_utime.tv_sec - history.ru_utime.tv_sec;
+ result->user.tv_usec = now.ru_utime.tv_usec - history.ru_utime.tv_usec;
+ result->sys.tv_sec = now.ru_stime.tv_sec - history.ru_stime.tv_sec;
+ result->sys.tv_usec = now.ru_stime.tv_usec - history.ru_stime.tv_usec;
+
+ /* Adjust seconds/microseconds */
+ if (now.ru_utime.tv_usec < history.ru_utime.tv_usec) {
+ --result->user.tv_sec;
+ result->user.tv_usec += 1000000;
+ }
+ if (now.ru_stime.tv_usec < history.ru_stime.tv_usec) {
+ --result->sys.tv_sec;
+ result->sys.tv_usec += 1000000;
+ }
+
+ /* Tag result as having run */
+ result->run = 1;
+
+ /* Cache the values retrieved */
+ memcpy (&history, &now, sizeof (struct rusage));
+#endif /* _XOPEN_UNIX */
+}
+
+/**
Entry point to the child process (watchdog) subsystem.
This method fork ()s, creating a child process. This child process becomes
@@ -712,15 +769,17 @@
@see wait_for_child ()
*/
struct exec_attrs
-exec_file (char** argv)
+exec_file (struct target_status* result)
{
const pid_t child_pid = fork ();
+ assert (0 != result);
+ assert (0 != result->argv);
+ assert (0 != result->argv [0]);
+
if (0 == child_pid) { /* child */
FILE* error_file;
- assert (0 != argv);
- assert (0 != argv [0]);
assert (0 != target_name);
/* Set process group ID (so entire group can be killed)*/
@@ -752,7 +811,7 @@
/* Redirect stdout */
{
- char* const tmp_name = output_name (argv [0]);
+ char* const tmp_name = output_name (result->argv [0]);
int intermit;
intermit = open (tmp_name, O_WRONLY | O_CREAT | O_TRUNC,
@@ -776,10 +835,10 @@
limit_process ();
#endif /* _XOPEN_UNIX */
- execv (argv [0], argv);
+ execv (result->argv [0], result->argv);
fprintf (error_file, "%s (%s): execv (\"%s\", ...) error: %s\n",
- exe_name, target_name, argv [0], strerror (errno));
+ exe_name, target_name, result->argv [0], strerror (errno));
exit (1);
}
@@ -787,13 +846,15 @@
if (-1 == child_pid) {
/* Fake a failue to execute status return structure */
struct exec_attrs state = {127, -1};
- warn ("Unable to create child process for %s: %s\n", argv [0],
+ warn ("Unable to create child process for %s: %s\n", result->argv [0],
strerror (errno));
return state;
+ } else {
+ /* parent */
+ struct exec_attrs state = wait_for_child (child_pid);
+ calculate_usage (result);
+ return state;
}
-
- /* parent */
- return wait_for_child (child_pid);
}
#else /* _WIN{32,64} */
/**
@@ -950,7 +1011,7 @@
@see wait_for_child ()
*/
struct exec_attrs
-exec_file (char** argv)
+exec_file (struct target_status* result)
{
char* merged;
PROCESS_INFORMATION child;
@@ -962,7 +1023,9 @@
const DWORD real_timeout = (timeout > 0) ? timeout * 1000 : INFINITE;
DWORD wait_code;
- assert (0 != argv);
+ assert (0 != result);
+ assert (0 != result->argv);
+ assert (0 != result->argv [0]);
memset (&status, 0, sizeof status);
@@ -979,7 +1042,7 @@
/* Create I/O handles */
{
/* Output redirection */
- char* const tmp_name = output_name (argv [0]);
+ char* const tmp_name = output_name (result->argv [0]);
context.hStdOutput = CreateFile (tmp_name, GENERIC_WRITE,
FILE_SHARE_WRITE, &child_sa, CREATE_ALWAYS,
@@ -1003,7 +1066,7 @@
}
}
- merged = merge_argv (argv);
+ merged = merge_argv (result->argv);
/* set appropriate error mode (the child process inherits this
error mode) to disable displaying the critical-error-handler
@@ -1011,7 +1074,7 @@
UINT old_mode = SetErrorMode (SEM_FAILCRITICALERRORS
| SEM_NOGPFAULTERRORBOX);
/* Create the child process */
- if (0 == CreateProcess (argv [0], merged, 0, 0, 1,
+ if (0 == CreateProcess (result->argv [0], merged, 0, 0, 1,
CREATE_NEW_PROCESS_GROUP, 0, 0, &context, &child)) {
/* record the status if we failed to create the process */
status.status = -1;
Index: display.cpp
===================================================================
--- display.cpp (revision 446647)
+++ display.cpp (working copy)
@@ -26,6 +26,9 @@
#include <assert.h>
#include <stdio.h> /* for fflush(), printf(), puts(), ... */
+#if !defined (_WIN32) && !defined (_WIN64)
+# include <unistd.h> /* for _XOPEN_UNIX */
+#endif
#include "cmdopt.h" /* for target_name -should this be moved? */
#include "exec.h" /* for get_signame */
@@ -34,7 +37,8 @@
void print_header_plain ()
{
- puts ("NAME STATUS ASSERTS FAILED PERCNT");
+ puts ("NAME STATUS ASSERTS FAILED PERCNT USER "
+ "SYS");
}
void print_target_plain (const struct target_status*)
@@ -45,23 +49,38 @@
void print_status_plain (const struct target_status* status)
{
+ unsigned valid_timing;
+ assert (0 != status);
assert (ST_OK <= status->status && ST_LAST > status->status);
+ valid_timing = status->run && ST_NOT_KILLED != status->status;
+
if (status->status) /* if status is set, print it */
- printf ("%6s\n", short_st_name [status->status]);
+ printf ("%6s", short_st_name [status->status]);
else if (status->exit) /* if exit code is non-zero, print it */
- printf ("%6d\n", status->exit);
+ printf ("%6d", status->exit);
else if (status->signal) /* if exit signal is non-zero, print it */
- printf ("%6s\n", get_signame (status->signal));
- else if (!status->assert) /* if the assertion count is 0, it's an example */
- puts (" 0");
+ printf ("%6s", get_signame (status->signal));
+ else
+ printf (" 0");
+
+ /* Print assetions, if any registered */
+ if (status->assert) {
+ printf (" %7u %6u %5d%%", status->assert, status->failed,
+ 100 * (status->assert - status->failed) / status->assert);
+ }
+ else if (valid_timing)
+ printf (" ");
+
+ /* Print timings, if available */
+ if (valid_timing)
+ printf (" %3ld.%03ld %3ld.%03ld\n", status->user.tv_sec,
+ status->user.tv_usec/1000, status->sys.tv_sec,
+ status->sys.tv_usec/1000);
else {
- unsigned pcnt = 0;
- if (status->assert) {
- pcnt = 100 * (status->assert - status->failed) / status->assert;
- }
- printf (" 0 %7u %6u %5d%%\n", status->assert, status->failed, pcnt);
+ puts ("");
}
+
}
void print_footer_plain () {}
Index: exec.h
===================================================================
--- exec.h (revision 446647)
+++ exec.h (working copy)
@@ -42,6 +42,6 @@
const char* get_signame (int signo);
-struct exec_attrs exec_file (char** argv);
+struct exec_attrs exec_file (struct target_status* result);
#endif // RW_EXEC_H
Index: runall.cpp
===================================================================
--- runall.cpp (revision 446647)
+++ runall.cpp (working copy)
@@ -415,7 +415,7 @@
print_target (&results);
if (check_target_ok (&results)) {
- struct exec_attrs status = exec_file (results.argv);
+ struct exec_attrs status = exec_file (&results);
process_results (&status, &results);
}
