From: grafikrobot_at_[hidden]
Date: 2007-11-28 02:21:50
Author: grafik
Date: 2007-11-28 02:21:49 EST (Wed, 28 Nov 2007)
New Revision: 41431
URL: http://svn.boost.org/trac/boost/changeset/41431
Log:
build-system.jam
* Reflect added start/end timestamps for actions in xml output. And update action rules for new args.
execcmd.h
* Add start/end timestamps to action timing info.
execnt.c
* Fix filetime_seconds calculation when time is larger than low 32 bit value.
* Add calc of C time_t from Windows FILETIME.
* Add start/end timestamps recording to action timing info.
execunix.c
* Add start/end timestamps recording to action timing info.
jam.c
* Change JAMDATE to use common ISO date format.
make1.c
* Redo __TIMING_RULE__ and __ACTION__RULE__ invocations to new argument ordering and added end/result timestamp values.
Text files modified:
trunk/tools/build/v2/build-system.jam | 10 ++--
trunk/tools/jam/src/execcmd.h | 24 +++++++---
trunk/tools/jam/src/execnt.c | 43 +++++++++++++++----
trunk/tools/jam/src/execunix.c | 13 ++++-
trunk/tools/jam/src/jam.c | 15 ------
trunk/tools/jam/src/make1.c | 85 +++++++++++++++++++++------------------
6 files changed, 111 insertions(+), 79 deletions(-)
Modified: trunk/tools/build/v2/build-system.jam
==============================================================================
--- trunk/tools/build/v2/build-system.jam (original)
+++ trunk/tools/build/v2/build-system.jam 2007-11-28 02:21:49 EST (Wed, 28 Nov 2007)
@@ -578,8 +578,8 @@
# actions clause we would have to form a valid command line
# containing the result of @(...) below (the name of the XML file).
rule out-xml.generate-action (
- xml-file args * :
- status : user : system : command : output ? )
+ args * : xml-file :
+ command status start end user system : output ? )
{
local contents =
[ on $(xml-file) return $(.header) $(.contents) $(.footer) ] ;
@@ -598,14 +598,14 @@
# statistics about each actual target in a variable "on" the
# --out-xml target.
rule out-xml.collect (
- xml-file target :
- status : user : system : command : output ? )
+ xml-file : target :
+ command status start end user system : output ? )
{
local nl = "
" ;
# Open the action with some basic info.
.contents on $(xml-file) +=
- "$(nl) <action status=\"$(status)\" user=\"$(user)\" system=\"$(system)\">"
+ "$(nl) <action status=\"$(status)\" start=\"$(start)\" end=\"$(end)\" user=\"$(user)\" system=\"$(system)\">"
;
# If we have an action object we can print out more detailed info.
Modified: trunk/tools/jam/src/execcmd.h
==============================================================================
--- trunk/tools/jam/src/execcmd.h (original)
+++ trunk/tools/jam/src/execcmd.h 2007-11-28 02:21:49 EST (Wed, 28 Nov 2007)
@@ -10,23 +10,31 @@
* 05/04/94 (seiwald) - async multiprocess interface
*/
+#ifndef EXECCMD_H
+#define EXECCMD_H
+
+#include <time.h>
+
typedef struct timing_info
{
- /* double elapsed; */ /* We don't know how to get this number on Unix */
double system;
double user;
+ time_t start;
+ time_t end;
} timing_info;
void execcmd(
- char *string,
- void (*func)( void *closure, int status, timing_info*, char *, char * ),
- void *closure,
- LIST *shell,
+ char *string,
+ void (*func)( void *closure, int status, timing_info*, char *, char * ),
+ void *closure,
+ LIST *shell,
char *action,
char *target);
int execwait();
-# define EXEC_CMD_OK 0
-# define EXEC_CMD_FAIL 1
-# define EXEC_CMD_INTR 2
+# define EXEC_CMD_OK 0
+# define EXEC_CMD_FAIL 1
+# define EXEC_CMD_INTR 2
+
+#endif
Modified: trunk/tools/jam/src/execnt.c
==============================================================================
--- trunk/tools/jam/src/execnt.c (original)
+++ trunk/tools/jam/src/execnt.c 2007-11-28 02:21:49 EST (Wed, 28 Nov 2007)
@@ -21,6 +21,7 @@
# include <assert.h>
# include <ctype.h>
# include <time.h>
+# include <math.h>
# ifdef USE_EXECNT
@@ -758,7 +759,35 @@
/* Convert a FILETIME to a number of seconds */
static double filetime_seconds(FILETIME t)
{
- return t.dwHighDateTime * (double)(1UL << 31) * 2 + t.dwLowDateTime * 1.0e-7;
+ return t.dwHighDateTime * ((double)(1UL << 31) * 2.0 * 1.0e-7) + t.dwLowDateTime * 1.0e-7;
+}
+
+/* What should be a simple conversion, turns out to be horribly
+ complicated by the defficiencies of MSVC and the Win32 API. */
+static time_t filetime_dt(FILETIME t_utc)
+{
+ static int calc_time_diff = 1;
+ static double time_diff;
+ if ( calc_time_diff )
+ {
+ struct tm t0_;
+ FILETIME f0_local,f0_;
+ SYSTEMTIME s0_;
+ GetSystemTime(&s0_);
+ t0_.tm_year = s0_.wYear-1900;
+ t0_.tm_mon = s0_.wMonth-1;
+ t0_.tm_wday = s0_.wDayOfWeek;
+ t0_.tm_mday = s0_.wDay;
+ t0_.tm_hour = s0_.wHour;
+ t0_.tm_min = s0_.wMinute;
+ t0_.tm_sec = s0_.wSecond;
+ t0_.tm_isdst = 0;
+ SystemTimeToFileTime(&s0_,&f0_local);
+ LocalFileTimeToFileTime(&f0_local,&f0_);
+ time_diff = filetime_seconds(f0_)-((double)mktime(&t0_));
+ calc_time_diff = 0;
+ }
+ return ceil(filetime_seconds(t_utc)-time_diff);
}
static void record_times(HANDLE process, timing_info* time)
@@ -767,17 +796,11 @@
if (GetProcessTimes(process, &creation, &exit, &kernel, &user))
{
- /* Compute the elapsed time */
- #if 0 /* We don't know how to get this number on Unix */
- time->elapsed = filetime_seconds(
- add_FILETIME( exit, negate_FILETIME(creation) )
- );
- #endif
time->system = filetime_seconds(kernel);
- time->user = filetime_seconds(user);
+ time->user = filetime_seconds(user);
+ time->start = filetime_dt(creation);
+ time->end = filetime_dt(exit);
}
-
- /* CloseHandle((HANDLE)pid); */
}
#define IO_BUFFER_SIZE (16*1024)
Modified: trunk/tools/jam/src/execunix.c
==============================================================================
--- trunk/tools/jam/src/execunix.c (original)
+++ trunk/tools/jam/src/execunix.c 2007-11-28 02:21:49 EST (Wed, 28 Nov 2007)
@@ -85,6 +85,7 @@
char *buffer[2]; /* buffer to hold stdout and stderr, if any */
void (*func)( void *closure, int status, timing_info*, char *, char * );
void *closure;
+ time_t start_dt; /* start of command timestamp */
} cmdtab[ MAXJOBS ] = {{0}};
/*
@@ -194,6 +195,8 @@
/* Start the command */
+ cmdtab[ slot ].start_dt = time(0);
+
if (0 < globs.timeout) {
/*
* handle hung processes by manually tracking elapsed
@@ -418,7 +421,7 @@
int i, ret, fd_max;
int pid, status, finished;
int rstat;
- timing_info time;
+ timing_info time_info;
fd_set fds;
struct tms new_time;
@@ -491,8 +494,10 @@
times(&new_time);
- time.system = (double)(new_time.tms_cstime - old_time.tms_cstime) / CLOCKS_PER_SEC;
- time.user = (double)(new_time.tms_cutime - old_time.tms_cutime) / CLOCKS_PER_SEC;
+ time_info.system = (double)(new_time.tms_cstime - old_time.tms_cstime) / CLOCKS_PER_SEC;
+ time_info.user = (double)(new_time.tms_cutime - old_time.tms_cutime) / CLOCKS_PER_SEC;
+ time_info.start = cmdtab[i].start_dt;
+ time_info.end = time(0);
old_time = new_time;
@@ -508,7 +513,7 @@
rstat = EXEC_CMD_OK;
/* assume -p0 in effect so only pass buffer[0] containing merged output */
- (*cmdtab[ i ].func)( cmdtab[ i ].closure, rstat, &time, cmdtab[i].command, cmdtab[i].buffer[0] );
+ (*cmdtab[ i ].func)( cmdtab[ i ].closure, rstat, &time_info, cmdtab[i].command, cmdtab[i].buffer[0] );
BJAM_FREE(cmdtab[i].buffer[OUT]);
cmdtab[i].buffer[OUT] = 0;
Modified: trunk/tools/jam/src/jam.c
==============================================================================
--- trunk/tools/jam/src/jam.c (original)
+++ trunk/tools/jam/src/jam.c 2007-11-28 02:21:49 EST (Wed, 28 Nov 2007)
@@ -122,6 +122,7 @@
# include "strings.h"
# include "expand.h"
# include "filesys.h"
+# include "output.h"
/* Macintosh is "special" */
@@ -372,19 +373,7 @@
/* Set JAMDATE first */
- {
- char *date;
- time_t clock;
- time( &clock );
- date = newstr( ctime( &clock ) );
-
- /* Trim newline from date */
-
- if( strlen( date ) == 25 )
- date[ 24 ] = 0;
-
- var_set( "JAMDATE", list_new( L0, newstr( date ) ), VAR_SET );
- }
+ var_set( "JAMDATE", list_new( L0, outf_time(time(0)) ), VAR_SET );
var_set( "JAM_VERSION",
Modified: trunk/tools/jam/src/make1.c
==============================================================================
--- trunk/tools/jam/src/make1.c (original)
+++ trunk/tools/jam/src/make1.c 2007-11-28 02:21:49 EST (Wed, 28 Nov 2007)
@@ -664,16 +664,6 @@
}
}
-/* To l, append a 1-element list containing the string representation
- * of x
- */
-static void append_double_string( LOL *l, double x )
-{
- char buffer[50];
- sprintf(buffer, "%f", x);
- lol_add( l, list_new( L0, newstr( buffer ) ) );
-}
-
/* Look up the __TIMING_RULE__ variable on the given target, and if
* non-empty, invoke the rule it names, passing the given
* timing_info
@@ -688,33 +678,37 @@
if (timing_rule)
{
- /* We'll prepend $(__TIMING_RULE__[2-]) to the first argument */
- LIST* initial_args = list_copy( L0, timing_rule->next );
-
+ /* rule timing-rule (
+ args * :
+ target :
+ start end user system ) */
+
/* Prepare the argument list */
FRAME frame[1];
frame_init( frame );
- /* First argument is the name of the timed target */
- lol_add( frame->args, list_new( initial_args, target->name ) );
- append_double_string(frame->args, time->user);
- append_double_string(frame->args, time->system);
-
- if( lol_get( frame->args, 2 ) )
- evaluate_rule( timing_rule->string, frame );
-
+ /* args * :: $(__ACTION_RULE__[2-]) */
+ lol_add( frame->args, list_copy( L0, timing_rule->next ) );
+
+ /* target :: the name of the target */
+ lol_add( frame->args, list_new( L0, target->name ) );
+
+ /* start end user system :: info about the action command */
+ lol_add( frame->args,
+ list_new( list_new( list_new( list_new( L0,
+ outf_time(time->start) ),
+ outf_time(time->end) ),
+ outf_double(time->user) ),
+ outf_double(time->system) ) );
+
+ /* Call the rule. */
+ evaluate_rule( timing_rule->string, frame );
+
/* Clean up */
frame_free( frame );
}
}
-static void append_int_string(LOL *l, int x)
-{
- char buffer[50];
- sprintf(buffer, "%i", x);
- lol_add(l, list_new(L0, newstr(buffer)));
-}
-
/* Look up the __ACTION_RULE__ variable on the given target, and if
* non-empty, invoke the rule it names, passing the given info,
* timing_info, executed command and command output
@@ -730,27 +724,40 @@
if (action_rule)
{
- /* We'll prepend $(__ACTION_RULE__[2-]) to the first argument */
- LIST* initial_args = list_copy( L0, action_rule->next );
-
+ /* rule action-rule (
+ args * :
+ target :
+ command status start end user system :
+ output ? ) */
+
/* Prepare the argument list */
FRAME frame[1];
frame_init( frame );
- /* First argument is the name of the target */
- lol_add( frame->args, list_new( initial_args, target->name ) );
- append_int_string(frame->args, status);
- append_double_string(frame->args, time->user);
- append_double_string(frame->args, time->system);
- lol_add(frame->args, list_new(L0, newstr(executed_command)));
+ /* args * :: $(__ACTION_RULE__[2-]) */
+ lol_add( frame->args, list_copy( L0, action_rule->next ) );
+
+ /* target :: the name of the target */
+ lol_add( frame->args, list_new( L0, target->name ) );
+
+ /* command status start end user system :: info about the action command */
+ lol_add( frame->args,
+ list_new( list_new( list_new( list_new( list_new( list_new( L0,
+ newstr(executed_command) ),
+ outf_int(status) ),
+ outf_time(time->start) ),
+ outf_time(time->end) ),
+ outf_double(time->user) ),
+ outf_double(time->system) ) );
+ /* output ? :: the output of the action command */
if (command_output)
lol_add(frame->args, list_new(L0, newstr(command_output)));
else
lol_add(frame->args, L0);
- if( lol_get( frame->args, 2 ) )
- evaluate_rule( action_rule->string, frame );
+ /* Call the rule. */
+ evaluate_rule( action_rule->string, frame );
/* Clean up */
frame_free( frame );