Add wtimestats option (#127)

This option is for printing the wall-clock time in statistics on the
master. This is not applied to statistics on workers.

Command line option:
  -W

Syntax:
  #:wtimestats on

  On wtimestats;
  Off wtimestats;

sources/checkpoint.c

@@ -772,6 +772,8 @@ static void print_M()
 	MesPrint("%d", AM.ggProcessStats);
 	MesPrint("%d", AM.gOldParallelStats);
 	MesPrint("%d", AM.ggOldParallelStats);
+	MesPrint("%d", AM.gWTimeStatsFlag);
+	MesPrint("%d", AM.ggWTimeStatsFlag);
 	MesPrint("%d", AM.maxFlevels);
 	MesPrint("--MARK  6");
 	MesPrint("%d", AM.resetTimeOnClear);
@@ -1065,6 +1067,7 @@ static void print_C()
 	MesPrint("%d", AC.ThreadSortFileSynch);
 	MesPrint("%d", AC.ProcessStats);
 	MesPrint("%d", AC.OldParallelStats);
+	MesPrint("%d", AC.WTimeStatsFlag);
 	MesPrint("%d", AC.BracketNormalize);
 	MesPrint("%d", AC.maxtermlevel);
 	MesPrint("%d", AC.dumnumflag);
@@ -1491,6 +1494,7 @@ int DoRecovery(int *moduletype)
 	R_SET(AM.SizeForSpectatorFiles,int);
     R_SET(AM.gOldGCDflag,int);
     R_SET(AM.ggOldGCDflag,int);
+	R_SET(AM.gWTimeStatsFlag, int);
 
 #ifdef PRINTDEBUG
 	print_M();
@@ -2556,6 +2560,7 @@ static int DoSnapshot(int moduletype)
 	S_WRITE_B(&AM.SizeForSpectatorFiles,sizeof(int));
     S_WRITE_B(&AM.gOldGCDflag,sizeof(int));
     S_WRITE_B(&AM.ggOldGCDflag,sizeof(int));
+	S_WRITE_B(&AM.gWTimeStatsFlag, sizeof(int));
 
 	/*#] AM :*/ 
 	/*#[ AC :*/

sources/compcomm.c

@@ -127,6 +127,7 @@ static KEYWORD onoffoptions[] = {
 	,{"memdebugflag",	(TFUN)&(AC.MemDebugFlag),	1,	0}
 	,{"oldgcd", 		(TFUN)&(AC.OldGCDflag),	1,	0}
 	,{"innertest",      (TFUN)&(AC.InnerTest),  1,  0}
+	,{"wtimestats",     (TFUN)&(AC.WTimeStatsFlag),  1,  0}
 };
 
 static WORD one = 1;

sources/execute.c

@@ -283,6 +283,7 @@ WORD PopVariables()
 	AC.ThreadStats = AM.gThreadStats;
 	AC.FinalStats = AM.gFinalStats;
 	AC.OldGCDflag = AM.gOldGCDflag;
+	AC.WTimeStatsFlag = AM.gWTimeStatsFlag;
 	AC.ThreadsFlag = AM.gThreadsFlag;
 	AC.ThreadBalancing = AM.gThreadBalancing;
 	AC.ThreadSortFileSynch = AM.gThreadSortFileSynch;
@@ -415,6 +416,7 @@ VOID MakeGlobal()
 	AM.gThreadStats = AC.ThreadStats;
 	AM.gFinalStats = AC.FinalStats;
 	AM.gOldGCDflag = AC.OldGCDflag;
+	AM.gWTimeStatsFlag = AC.WTimeStatsFlag;
 	AM.gThreadsFlag = AC.ThreadsFlag;
 	AM.gThreadBalancing = AC.ThreadBalancing;
 	AM.gThreadSortFileSynch = AC.ThreadSortFileSynch;

sources/setfile.c

@@ -112,6 +112,7 @@ SETUPPARAMETERS setupparameters[] =
     ,{(UBYTE *)"threadsortfilesynch",       ONOFFVALUE, 0, (LONG)0}
 	,{(UBYTE *)"totalsize",                 ONOFFVALUE, 0, (LONG)2}
 	,{(UBYTE *)"workspace",             NUMERICALVALUE, 0, (LONG)WORKBUFFER}
+	,{(UBYTE *)"wtimestats",                ONOFFVALUE, 0, (LONG)2}
 };
 
 /*
@@ -676,6 +677,9 @@ int AllocSetups()
 	AC.OldFactArgFlag = AM.gOldFactArgFlag = AM.ggOldFactArgFlag = sp->value;
 	sp = GetSetupPar((UBYTE *)"oldgcd");
 	AC.OldGCDflag = AM.gOldGCDflag = AM.ggOldGCDflag = sp->value;
+	sp = GetSetupPar((UBYTE *)"wtimestats");
+	if ( sp->value == 2 ) sp->value = AM.ggWTimeStatsFlag;
+	AC.WTimeStatsFlag = AM.gWTimeStatsFlag = AM.ggWTimeStatsFlag = sp->value;
 	sp = GetSetupPar((UBYTE *)"sorttype");
 	if ( StrICmp((UBYTE *)"lowfirst",(UBYTE *)sp->value) == 0 ) {
 		AC.lSortType = SORTLOWFIRST;

sources/sort.c

@@ -95,6 +95,7 @@ VOID WriteStats(POSITION *plspace, WORD par)
 	WORD timepart;
 	SORTING *S;
 	POSITION pp;
+	int use_wtime;
 	if ( AT.SS == AT.S0 && AC.StatsFlag ) {
 #ifdef WITHPTHREADS
 		if ( AC.ThreadStats == 0 && identity > 0 ) return;
@@ -132,7 +133,19 @@ VOID WriteStats(POSITION *plspace, WORD par)
 			MesPrint("");
 #endif
 		}
-		millitime = TimeCPU(1);
+		/*
+		 * We define WTimeStatsFlag as a flag to print the wall-clock time on
+		 * the *master*, not in workers. This can be confusing in thread
+		 * statistics when short statistics is used. Technically,
+		 * TimeWallClock() is not thread-safe in TFORM.
+		 */
+		use_wtime = AC.WTimeStatsFlag;
+#if defined(WITHPTHREADS)
+		if ( use_wtime && identity > 0 ) use_wtime = 0;
+#elif defined(WITHMPI)
+		if ( use_wtime && PF.me != MASTER ) use_wtime = 0;
+#endif
+		millitime = use_wtime ? TimeWallClock(1) * 10 : TimeCPU(1);
 		timepart = (WORD)(millitime%1000);
 		millitime /= 1000;
 		timepart /= 10;
@@ -391,21 +404,44 @@ VOID WriteStats(POSITION *plspace, WORD par)
 		} }
 		else {
 		if ( par == 1 ) {
+			if ( use_wtime ) {
+				MesPrint("WTime = %7l.%2i sec",millitime,timepart);
+			}
+			else {
 				MesPrint("Time = %7l.%2i sec",millitime,timepart);
 			}
+		}
 		else {
 #if ( BITSINLONG > 32 )
 			if ( S->GenTerms >= 10000000000L ) {
+				if ( use_wtime ) {
+					MesPrint("WTime = %7l.%2i sec   Generated terms = %16l",
+						millitime,timepart,S->GenTerms);
+				}
+				else {
 					MesPrint("Time = %7l.%2i sec    Generated terms = %16l",
 						millitime,timepart,S->GenTerms);
 				}
+			}
+			else {
+				if ( use_wtime ) {
+					MesPrint("WTime = %7l.%2i sec   Generated terms = %10l",
+						millitime,timepart,S->GenTerms);
+				}
 				else {
 					MesPrint("Time = %7l.%2i sec    Generated terms = %10l",
 						millitime,timepart,S->GenTerms);
 				}
+			}
 #else
+			if ( use_wtime ) {
+				MesPrint("WTime = %7l.%2i sec   Generated terms = %10l",
+					millitime,timepart,S->GenTerms);
+			}
+			else {
 				MesPrint("Time = %7l.%2i sec    Generated terms = %10l",
 					millitime,timepart,S->GenTerms);
+			}
 #endif
 		}
 #if ( BITSINLONG > 32 )

sources/startup.c

@@ -279,6 +279,9 @@ int DoTail(int argc, UBYTE **argv)
 /*							if ( threadnum == 1 ) threadnum = 0; */
 							threadnum++;
 							break;
+				case 'W': /* Print the wall-clock time on the master. */
+							AM.ggWTimeStatsFlag = 1;
+							break;
 /*
 				case 'n':
 							Reserved for number of slaves without MPI
@@ -1141,6 +1144,7 @@ VOID StartVariables()
 	AC.OldParallelStats = AM.gOldParallelStats = AM.ggOldParallelStats = 0;
 	AC.OldFactArgFlag = AM.gOldFactArgFlag = AM.ggOldFactArgFlag = NEWFACTARG;
 	AC.OldGCDflag = AM.gOldGCDflag = AM.ggOldGCDflag = 1;
+	AC.WTimeStatsFlag = AM.gWTimeStatsFlag = AM.ggWTimeStatsFlag = 0;
 	AM.gcNumDollars = AP.DollarList.num;
 	AC.SizeCommuteInSet = AM.gSizeCommuteInSet = 0;
 	AC.CommuteInSet = 0;

sources/structs.h

@@ -1393,6 +1393,8 @@ struct M_const {
 	int		SizeForSpectatorFiles; /* Size in AM.spectatorfiles; */
     int     gOldGCDflag;
     int     ggOldGCDflag;
+    int     gWTimeStatsFlag;
+    int     ggWTimeStatsFlag;
     WORD    MaxTal;                /* (M) Maximum number of words in a number */
     WORD    IndDum;                /* (M) Basis value for dummy indices */
     WORD    DumInd;                /* (M) */
@@ -1451,9 +1453,9 @@ struct M_const {
     WORD    havesortdir;
     WORD    BracketFactors[8];
 #ifdef WITHPTHREADS
-	PADPOSITION(17,25,59,81,sizeof(pthread_rwlock_t)+sizeof(pthread_mutex_t)*2);
+	PADPOSITION(17,25,61,81,sizeof(pthread_rwlock_t)+sizeof(pthread_mutex_t)*2);
 #else
-	PADPOSITION(17,23,59,81,0);
+	PADPOSITION(17,23,61,81,0);
 #endif
 };
 /*
@@ -1695,6 +1697,7 @@ struct C_const {
     int     OldFactArgFlag;
     int     MemDebugFlag;          /* Only used when MALLOCDEBUG in tools.c */
     int     OldGCDflag;
+    int     WTimeStatsFlag;
 	int     doloopstacksize;
 	int     dolooplevel;
     int     CheckpointFlag;        /**< Tells preprocessor whether checkpoint code must executed.
@@ -1760,11 +1763,11 @@ struct C_const {
     UBYTE   Commercial[COMMERCIALSIZE+2]; /* (C) Message to be printed in statistics */
     UBYTE   debugFlags[MAXFLAGS+2];    /* On/Off Flag number(s) */
 #if defined(WITHPTHREADS)
-	PADPOSITION(47,8+3*MAXNEST,71,45+3*MAXNEST+MAXREPEAT,COMMERCIALSIZE+MAXFLAGS+4+sizeof(LIST)*17+sizeof(pthread_mutex_t));
+	PADPOSITION(47,8+3*MAXNEST,72,45+3*MAXNEST+MAXREPEAT,COMMERCIALSIZE+MAXFLAGS+4+sizeof(LIST)*17+sizeof(pthread_mutex_t));
 #elif defined(WITHMPI)
-	PADPOSITION(47,8+3*MAXNEST,71,46+3*MAXNEST+MAXREPEAT,COMMERCIALSIZE+MAXFLAGS+4+sizeof(LIST)*17);
+	PADPOSITION(47,8+3*MAXNEST,72,46+3*MAXNEST+MAXREPEAT,COMMERCIALSIZE+MAXFLAGS+4+sizeof(LIST)*17);
 #else
-	PADPOSITION(45,8+3*MAXNEST,69,45+3*MAXNEST+MAXREPEAT,COMMERCIALSIZE+MAXFLAGS+4+sizeof(LIST)*17);
+	PADPOSITION(45,8+3*MAXNEST,70,45+3*MAXNEST+MAXREPEAT,COMMERCIALSIZE+MAXFLAGS+4+sizeof(LIST)*17);
 #endif
 };
 /*

sources/tools.c

@@ -3213,8 +3213,17 @@ int CompArg(WORD *s1, WORD *s2)
 
 #include <sys/timeb.h>
 
+/**
+ * Returns the wall-clock time.
+ *
+ * @param   par  If zero, the wall-clock time will be reset to 0.
+ * @return       The wall-clock time in centiseconds.
+ */
 LONG TimeWallClock(WORD par)
 {
+	/*
+	 * NOTE: this function is not thread-safe. Operations on tp are not atomic.
+	 */
 	struct timeb tp;
 	ftime(&tp);
 	if ( par ) {
@@ -3245,6 +3254,12 @@ LONG TimeChildren(WORD par)
  		#[ TimeCPU :
 */
 
+/**
+ * Returns the CPU time.
+ *
+ * @param   par  If zero, the CPU time will be reset to 0.
+ * @return       The CPU time in milliseconds.
+ */
 LONG TimeCPU(WORD par)
 {
 	GETIDENTITY