Fix the max precision of the 'time' keyword (#72)

This commit backports the required fixes from ksh2020 for using
millisecond precision with the 'time' keyword. The bugfix refactors
a decent amount of code to rely on the BSD 'timeradd' and
'timersub' macros for calculating the total amount of time elapsed
(as these aren't standard, they are selectively implemented in an
iffe feature test for platforms without them). getrusage(3) is now
preferred since it usually has higher precision than times(3) (the
latter is used as a fallback).

There are three other fixes as well:

src/lib/libast/features/time:
- Test for getrusage with an iffe feature test rather than
  assume _sys_times == _lib_getrusage.

src/cmd/ksh93/sh/xec.c:
- A single percent at the end of a format specifier is now
  treated as a literal '%' (like in Bash).
- Zero-pad seconds if seconds < 10. This was already done for
  the times builtin in commit 5c677a4c, although it wasn't
  applied to the time keyword.
- Backport the ksh2020 bugfix for the time keyword by using
  timeradd and timersub with gettimeofday (which is used with
  a timeofday macro). Prefer getrusage when it is available.
- Allow compiling without the 'timeofday' ifdef for better
  portability.
  This is the order of priority for getting the elapsed time:
  1) getrusage (most precise)
  2) times + gettimeofday (best fallback)
  3) only times (doesn't support millisecond precision)
  This was tested by using debug '#undef' statements in xec.c.

src/cmd/ksh93/features/time:
- Implement feature tests for the 'timeradd' and 'timersub'
  macros.
- Do a feature test for getrusage like in the libast time test.

src/cmd/ksh93/tests/basic.sh:
- Add test for millisecond precision.
- Add test for handling of '%' at the end of a format specifier.
- Add test for locale-specific radix point.

NEWS

@@ -12,6 +12,18 @@ Any uppercase BUG_* names are modernish shell bug IDs.
 - Fixed a fork bomb that could occur when the vi editor was sent SIGTSTP
   while running in a ksh script.
 
+- Appending a lone percent to the end of a format specifier no longer
+  causes a syntax error. The extra percent will be treated as a literal
+  '%', like in Bash and zsh.
+
+- The 'time' keyword now has proper support for millisecond precision.
+  Although this feature was previously documented, the 'time' keyword
+  only supported up to centisecond precision, which caused a command
+  like the one below to return '0.000' on certain operating systems:
+  $ TIMEFORMAT='%3R'; time sleep .003
+
+- The 'time' keyword now zero-pads seconds less than ten (like mksh).
+
 2020-07-10:
 
 - Fixed a bug that caused types created with 'typeset -T' to throw an error

src/cmd/ksh93/features/time

@@ -1,5 +1,5 @@
-hdr	utime
+hdr	utime,sys/resource
-lib	gettimeofday,setitimer
+lib	getrusage,gettimeofday,setitimer
 mem	timeval.tv_usec sys/time.h
 tst	lib_2_timeofday note{ 2 arg gettimeofday() }end link{
 	#include <sys/types.h>
@@ -23,6 +23,7 @@ tst	lib_1_timeofday note{ 1 arg gettimeofday() }end link{
 cat{
 	#undef _def_time
 	#include	<times.h>
+	#include	<sys/time.h>
 	#define _def_time	1
 	#undef timeofday
 	#if _lib_2_timeofday
@@ -32,4 +33,27 @@ cat{
 	#define timeofday(p)	gettimeofday(p)
 	#endif
 	#endif
+	/* BSD timeradd and timersub macros */
+	#if !defined(timeradd)
+	#define	timeradd(tvp, uvp, vvp)						\
+	do {								\
+		(vvp)->tv_sec = (tvp)->tv_sec + (uvp)->tv_sec;		\
+		(vvp)->tv_usec = (tvp)->tv_usec + (uvp)->tv_usec;	\
+		if ((vvp)->tv_usec >= 1000000) {			\
+			(vvp)->tv_sec++;				\
+			(vvp)->tv_usec -= 1000000;			\
+		}							\
+	} while(0)
+	#endif
+	#if !defined(timersub)
+	#define	timersub(tvp, uvp, vvp)						\
+	do {								\
+		(vvp)->tv_sec = (tvp)->tv_sec - (uvp)->tv_sec;		\
+		(vvp)->tv_usec = (tvp)->tv_usec - (uvp)->tv_usec;	\
+		if ((vvp)->tv_usec < 0) {				\
+			(vvp)->tv_sec--;				\
+			(vvp)->tv_usec += 1000000;			\
+		}							\
+	} while(0)
+	#endif
 }end

src/cmd/ksh93/sh/xec.c

@@ -95,6 +95,56 @@ struct funenv
     }
 #endif /* !SHOPT_DEVFD */
 
+#if _lib_getrusage
+/* getrusage tends to have higher precision */
+static void get_cpu_times(Shell_t *shp, struct timeval *tv_usr, struct timeval *tv_sys)
+{
+	NOT_USED(shp);
+	struct rusage usage_self, usage_child;
+
+	getrusage(RUSAGE_SELF, &usage_self);
+	getrusage(RUSAGE_CHILDREN, &usage_child);
+	timeradd(&usage_self.ru_utime, &usage_child.ru_utime, tv_usr);
+	timeradd(&usage_self.ru_stime, &usage_child.ru_stime, tv_sys);
+}
+#else
+#ifdef timeofday
+static void get_cpu_times(Shell_t *shp, struct timeval *tv_usr, struct timeval *tv_sys)
+{
+	struct tms cpu_times;
+	struct timeval tv1, tv2;
+	double dtime;
+
+	if(times(&cpu_times) == (clock_t)-1)
+		errormsg(SH_DICT, ERROR_exit(1), "times(3) failed: %s", strerror(errno));
+
+	dtime = (double)cpu_times.tms_utime / shp->gd->lim.clk_tck;
+	tv1.tv_sec = dtime / 60;
+	tv1.tv_usec = 1000000 * (dtime - tv1.tv_sec);
+	dtime = (double)cpu_times.tms_cutime / shp->gd->lim.clk_tck;
+	tv2.tv_sec = dtime / 60;
+	tv2.tv_usec = 1000000 * (dtime - tv2.tv_sec);
+	timeradd(&tv1, &tv2, tv_usr);
+
+	dtime = (double)cpu_times.tms_stime / shp->gd->lim.clk_tck;
+	tv1.tv_sec = dtime / 60;
+	tv1.tv_usec = 1000000 * (dtime - tv1.tv_sec);
+	dtime = (double)cpu_times.tms_cstime / shp->gd->lim.clk_tck;
+	tv2.tv_sec = dtime / 60;
+	tv2.tv_usec = 1000000 * (dtime - tv2.tv_sec);
+	timeradd(&tv1, &tv2, tv_sys);
+}
+#endif /* timeofday */
+#endif /* _lib_getrusage */
+
+#ifdef timeofday
+/* 'inline' is commented out because C89 doesn't have it */
+static /*inline*/ double timeval_to_double(struct timeval tv)
+{
+	return (double)tv.tv_sec + ((double)tv.tv_usec / 1000000.0);
+}
+#endif
+
 /*
  * The following two functions allow command substitution for non-builtins
  * to use a pipe and to wait for the pipe to close before restoring to a
@@ -182,11 +232,25 @@ static void iounpipe(Shell_t *shp)
 /*
  * print time <t> in h:m:s format with precision <p>
  */
-static void     l_time(Sfio_t *outfile,register clock_t t,int p)
+#ifdef timeofday
+static void l_time(Sfio_t *outfile, struct timeval *tv, int precision)
 {
-	register int  min, sec, frac;
+	int hr = tv->tv_sec / (60 * 60);
+	int min = (tv->tv_sec / 60) % 60;
+	int sec = tv->tv_sec % 60;
+	int frac = tv->tv_usec;
+
+	/* scale fraction from micro to milli, centi, or deci second according to precision */
+	int n;
+	for(n = 3 + (3 - precision); n > 0; --n)
+		frac /= 10;
+#else
+/* fallback */
+static void l_time(Sfio_t *outfile,register clock_t t,int precision)
+{
+	register int min, sec, frac;
 	register int hr;
-	if(p)
+	if(precision)
 	{
 		frac = t%shgd->lim.clk_tck;
 		frac = (frac*100)/shgd->lim.clk_tck;
@@ -195,49 +259,113 @@ static void     l_time(Sfio_t *outfile,register clock_t t,int p)
 	sec = t%60;
 	t /= 60;
 	min = t%60;
-	if(hr=t/60)
+	hr = t/60;
+#endif
+	if(hr)
 		sfprintf(outfile,"%dh",hr);
-	if(p)
+	if(precision)
-		sfprintf(outfile,"%dm%d%c%0*ds",min,sec,GETDECIMAL(0),p,frac);
+		sfprintf(outfile,"%dm%02d%c%0*ds",min,sec,GETDECIMAL(0),precision,frac);
 	else
-		sfprintf(outfile,"%dm%ds",min,sec);
+		sfprintf(outfile,"%dm%02ds",min,sec);
 }
 
-static int p_time(Shell_t *shp, Sfio_t *out, const char *format, clock_t *tm)
+#define TM_REAL_IDX 0
+#define TM_USR_IDX 1
+#define TM_SYS_IDX 2
+
+#ifdef timeofday
+static void p_time(Shell_t *shp, Sfio_t *out, const char *format, struct timeval tm[3])
+#else
+static void p_time(Shell_t *shp, Sfio_t *out, const char *format, clock_t *tm)
+#endif
 {
-	int		c,p,l,n,offset = staktell();
+	int		c,n,offset = staktell();
 	const char	*first;
-	double		d;
 	Stk_t		*stkp = shp->stk;
-	for(first=format ; c= *format; format++)
+#ifdef timeofday
+	struct timeval tv_cpu_sum;
+	struct timeval *tvp;
+#else
+	double d;
+#endif
+	for(first=format; *format; format++)
 	{
+		c = *format;
 		if(c!='%')
 			continue;
+		unsigned char l_modifier = 0;
+		int precision = 3;
+#ifndef timeofday
+		n = 0;
+#endif
+
 		sfwrite(stkp, first, format-first);
-		n = l = 0;
+		c = *++format;
-		p = 3;
+		if(c=='\0')
-		if((c= *++format) == '%')
+		{
+			/* If a lone percent is the last character of the format pretend
+			   the user had written `%%` for a literal percent */
+			sfwrite(stkp, "%", 1);
+			first = format + 1;
+			break;
+		}
+		else if(c=='%')
 		{
 			first = format;
 			continue;
 		}
 		if(c>='0' && c <='9')
 		{
-			p = (c>'3')?3:(c-'0');
+			precision = (c>'3')?3:(c-'0');
 			c = *++format;
 		}
-		else if(c=='P')
+		if(c=='P')
 		{
+#ifdef timeofday
+			struct timeval tv_real = tm[TM_REAL_IDX];
+			struct timeval tv_cpu;
+			timeradd(&tm[TM_USR_IDX], &tm[TM_SYS_IDX], &tv_cpu);
+
+			double d = timeval_to_double(tv_real);
+			if(d)
+				d = 100.0 * timeval_to_double(tv_cpu) / d;
+			sfprintf(stkp, "%.*f", precision, d);
+			first = format + 1;
+			continue;
+#else
 			if(d=tm[0])
 				d = 100.*(((double)(tm[1]+tm[2]))/d);
-			p = 2;
+			precision = 2;
 			goto skip;
+#endif
 		}
 		if(c=='l')
 		{
-			l = 1;
+			l_modifier = 1;
 			c = *++format;
 		}
+#ifdef timeofday
+		if(c=='R')
+			tvp = &tm[TM_REAL_IDX];
+		else if(c=='U')
+			tvp = &tm[TM_USR_IDX];
+		else if(c=='S')
+			tvp = &tm[TM_SYS_IDX];
+		else
+		{
+			errormsg(SH_DICT,ERROR_exit(0),e_badtformat,c);
+			continue;
+		}
+		if(l_modifier)
+			l_time(stkp, tvp, precision);
+		else
+		{
+			/* scale fraction from micro to milli, centi, or deci second according to precision */
+			int n, frac = tvp->tv_usec;
+			for(n = 3 + (3 - precision); n > 0; --n) frac /= 10;
+			sfprintf(stkp, "%d%c%0*d", tvp->tv_sec, GETDECIMAL(0), precision, frac);
+		}
+#else
 		if(c=='U')
 			n = 1;
 		else if(c=='S')
@@ -246,14 +374,15 @@ static int p_time(Shell_t *shp, Sfio_t *out, const char *format, clock_t *tm)
 		{
 			stkseek(stkp,offset);
 			errormsg(SH_DICT,ERROR_exit(0),e_badtformat,c);
-			return(0);
+			return;
 		}
 		d = (double)tm[n]/shp->gd->lim.clk_tck;
 	skip:
-		if(l)
+		if(l_modifier)
-			l_time(stkp, tm[n], p);
+			l_time(stkp, tm[n], precision);
 		else
-			sfprintf(stkp,"%.*f",p, d);
+			sfprintf(stkp,"%.*f",precision, d);
+#endif
 		first = format+1;
 	}
 	if(format>first)
@@ -262,7 +391,6 @@ static int p_time(Shell_t *shp, Sfio_t *out, const char *format, clock_t *tm)
 	n = stktell(stkp)-offset;
 	sfwrite(out,stkptr(stkp,offset),n);
 	stkseek(stkp,offset);
-	return(n);
 }
 
 #if SHOPT_OPTIMIZE
@@ -2577,14 +2705,14 @@ int sh_exec(register const Shnode_t *t, int flags)
 		    case TTIME:
 		    {
 			/* time the command */
-			struct tms before,after;
 			const char *format = e_timeformat;
-			clock_t at, tm[3];
+			struct timeval ta, tb;
 #ifdef timeofday
-			struct timeval tb,ta;
+			struct timeval before_usr, before_sys, after_usr, after_sys, tm[3];
 #else
-			clock_t bt;
+			struct tms before,after;
-#endif	/* timeofday */
+			clock_t at, bt, tm[3];
+#endif
 #if SHOPT_COSHELL
 			if(shp->inpool)
 			{
@@ -2601,16 +2729,18 @@ int sh_exec(register const Shnode_t *t, int flags)
 			}
 			if(t->par.partre)
 			{
-				long timer_on;
 				if(shp->subshell && shp->comsub==1)
 					sh_subfork();
-				timer_on = sh_isstate(SH_TIMING);
+				long timer_on = sh_isstate(SH_TIMING);
 #ifdef timeofday
+				/* must be run after forking a subshell */
 				timeofday(&tb);
-				times(&before);
+				get_cpu_times(shp, &before_usr, &before_sys);
 #else
 				bt = times(&before);
-#endif	/* timeofday */
+				if(bt == (clock_t)-1)
+					errormsg(SH_DICT, ERROR_exit(1), "times(3) failed: %s", strerror(errno));
+#endif
 				job.waitall = 1;
 				sh_onstate(SH_TIMING);
 				sh_exec(t->par.partre,OPTIMIZE);
@@ -2620,21 +2750,28 @@ int sh_exec(register const Shnode_t *t, int flags)
 			}
 			else
 			{
-#ifndef timeofday
+#ifdef timeofday
+				before_usr.tv_sec = before_usr.tv_usec = 0;
+				before_sys.tv_sec = before_sys.tv_usec = 0;
+#else
 				bt = 0;
-#endif	/* timeofday */
 				before.tms_utime = before.tms_cutime = 0;
 				before.tms_stime = before.tms_cstime = 0;
+#endif
 			}
-#ifdef timeofday
+#ifndef timeofday
-			times(&after);
-			timeofday(&ta);
-			at = shp->gd->lim.clk_tck*(ta.tv_sec-tb.tv_sec);
-			at +=  ((shp->gd->lim.clk_tck*(((1000000L/2)/shp->gd->lim.clk_tck)+(ta.tv_usec-tb.tv_usec)))/1000000L);
-#else
 			at = times(&after) - bt;
-#endif	/* timeofday */
+			if(at == (clock_t)-1)
+				errormsg(SH_DICT, ERROR_exit(1), "times(3) failed: %s", strerror(errno));
 			tm[0] = at;
+#else
+			get_cpu_times(shp, &after_usr, &after_sys);
+			timeofday(&ta);
+			timersub(&ta, &tb, &tm[TM_REAL_IDX]); /* calculate elapsed real-time */
+			timersub(&after_usr, &before_usr, &tm[TM_USR_IDX]);
+			timersub(&after_sys, &before_sys, &tm[TM_SYS_IDX]);
+#endif
+
 			if(t->par.partre)
 			{
 				Namval_t *np = nv_open("TIMEFORMAT",shp->var_tree,NV_NOADD);
@@ -2648,10 +2785,12 @@ int sh_exec(register const Shnode_t *t, int flags)
 			}
 			else
 				format = strchr(format+1,'\n')+1;
+#ifndef timeofday
 			tm[1] = after.tms_utime - before.tms_utime;
 			tm[1] += after.tms_cutime - before.tms_cutime;
 			tm[2] = after.tms_stime - before.tms_stime;
 			tm[2] += after.tms_cstime - before.tms_cstime;
+#endif
 			if(format && *format)
 				p_time(shp,sfstderr,sh_translate(format),tm);
 			break;

src/cmd/ksh93/tests/basic.sh

@@ -552,5 +552,41 @@ $SHELL 2> /dev/null -c $'for i;\ndo :;done' || err_exit 'for i ; <newline> not v
 	"$SHELL" main.ksh 2>/dev/null
 ) || err_exit "crash when sourcing multiple files (exit status $?)"
 
+# ======
+# The time keyword should correctly handle millisecond precision.
+# This can be checked by verifying the last digit is not a zero
+# when 'time sleep .002' is run.
+result=$(
+	TIMEFORMAT=$'\%3R'
+	redirect 2>&1
+	time sleep .002
+)
+[[ ${result: -1} == 0 ]] && err_exit "the 'time' keyword doesn't properly support millisecond precision"
+
+# A single '%' after a format specifier should not be a syntax
+# error (it should be treated as a literal '%').
+IFS=' '
+result=( $(
+	TIMEFORMAT=$'%0S%'
+	redirect 2>&1
+	time :
+) )
+[[ ${result[4]} == bad ]] && err_exit "'%' is not treated literally when placed after a format specifier"
+
+# The locale's radix point shouldn't be ignored
+us=$(
+	LC_ALL='C.UTF-8' # radix point '.'
+	TIMEFORMAT='%1U' # catch -1.99 bug as well by getting user time
+	redirect 2>&1
+	time sleep 0
+)
+eu=$(
+	LC_ALL='C_EU.UTF-8' # radix point ','
+	TIMEFORMAT='%1U'
+	redirect 2>&1
+	time sleep 0
+)
+[[ ${us:1:1} == ${eu:1:1} ]] && err_exit "The time keyword ignores the locale's radix point (both are ${eu:1:1})"
+
 # ======
 exit $((Errors<125?Errors:125))

src/lib/libast/features/time

@@ -1,8 +1,13 @@
 set	prototyped
-lib	nanosleep,usleep,_strftime
+lib	getrusage,nanosleep,usleep,_strftime
 typ	clock_t = uint32_t
 typ	time_t = uint32_t
 
+if sys resource {
+	#include <sys/resource.h>
+}
+endif
+
 if sys time {
 	#include <sys/time.h>
 }

src/lib/libast/misc/debug.c

@@ -27,6 +27,7 @@
 #include <ast.h>
 #include <error.h>
 #include <debug.h>
+#include "FEATURE/time"
 
 void
 debug_fatal(const char* file, int line)
@@ -35,11 +36,9 @@ debug_fatal(const char* file, int line)
 	abort();
 }
 
-#if _sys_times
+#if defined(_sys_times) && defined(_lib_getrusage)
 
 #include <times.h>
-#include <sys/resource.h>
-
 double
 debug_elapsed(int set)
 {