Re: csh(1), ksh(1), time(1): print durations with millisecond precision
Todd C. Miller wrote: > Other implementations of "time -p" (both builtin and standalone) > only display two digits after the radix point. I'm a little concerned > about breaking scripts that consume out the output of "time -p". I share that concern.
Re: csh(1), ksh(1), time(1): print durations with millisecond precision
Other implementations of "time -p" (both builtin and standalone) only display two digits after the radix point. I'm a little concerned about breaking scripts that consume out the output of "time -p". Changing the precission of the non-portable output format is fine. - todd
Re: csh(1), ksh(1), time(1): print durations with millisecond precision
On Tue, Jun 13, 2023 at 10:59:53PM -0500, Scott Cheloha wrote:
> This patch bumps the precision of durations printed by csh(1), ksh(1),
> and time(1) from centiseconds to milliseconds. The csh(1) and ksh(1)
> builtins "time" and "times" are affected.
>
> My thinking is:
>
> - All practical OpenBSD platforms have a timecounter with at least
> millisecond precision.
>
> - It's not uncommon for people to run a custom HZ=1000 kernel.
> At HZ=1000, the profiled user and system durations offered by
> getrusage(2) are (arguably) millisecond precision.
>
> Yes, I know those numbers are profiled and thus not especially
> trustworthy, but it's no different from the situation on a
> HZ=100 kernel.
>
> - The timing commands offered in other shells like bash and dash
> provide (at least) millisecond precision.
>
> - Centiseconds are a bit odd. They don't align with the tidy
> "thousands" separation typical of metric units.
>
> - The POSIX standard for time(1) and the "times" builtin specifies
> that the durations are formatted as a floating point value of
> seconds, i.e. "%f". This means millisecond precision is okay:
>
> https://pubs.opengroup.org/onlinepubs/9699919799/utilities/time.html
> https://pubs.opengroup.org/onlinepubs/9699919799/utilities/V3_chap02.html#times
One week bump.
Index: bin/csh/time.c
===
RCS file: /cvs/src/bin/csh/time.c,v
retrieving revision 1.18
diff -u -p -r1.18 time.c
--- bin/csh/time.c 8 Mar 2023 04:43:04 - 1.18
+++ bin/csh/time.c 14 Jun 2023 15:30:01 -
@@ -40,6 +40,7 @@
* C Shell - routines handling process timing and niceing
*/
static voidpdeltat(struct timeval *, struct timeval *);
+static voidpdelta_hms(const struct timespec *, const struct timespec *);
void
settimes(void)
@@ -145,7 +146,7 @@ prusage(struct rusage *r0, struct rusage
break;
case 'E': /* elapsed (wall-clock) time */
- pcsecs((long) ms);
+ pdelta_hms(e, b);
break;
case 'P': /* percent time spent running */
@@ -227,8 +228,7 @@ pdeltat(struct timeval *t1, struct timev
struct timeval td;
timersub(t1, t0, );
-(void) fprintf(cshout, "%lld.%01ld", (long long)td.tv_sec,
- td.tv_usec / 10);
+fprintf(cshout, "%lld.%03ld", (long long)td.tv_sec, td.tv_usec / 1000);
}
#define P2DIG(i) (void) fprintf(cshout, "%d%d", (i) / 10, (i) % 10)
@@ -254,23 +254,18 @@ minsec:
}
void
-pcsecs(long l) /* PWP: print mm:ss.dd, l is in sec*100 */
+pdelta_hms(const struct timespec *t1, const struct timespec *t0)
{
-int i;
+struct timespec elapsed;
+long long hours, minutes, seconds;
-i = l / 36;
-if (i) {
- (void) fprintf(cshout, "%d:", i);
- i = (l % 36) / 100;
- P2DIG(i / 60);
- goto minsec;
-}
-i = l / 100;
-(void) fprintf(cshout, "%d", i / 60);
-minsec:
-i %= 60;
-(void) fputc(':', cshout);
-P2DIG(i);
-(void) fputc('.', cshout);
-P2DIG((int) (l % 100));
+timespecsub(t1, t0, );
+hours = elapsed.tv_sec / 3600;
+minutes = (elapsed.tv_sec % 3600) / 60;
+seconds = elapsed.tv_sec % 60;
+if (hours != 0)
+ fprintf(cshout, "%lld:%02lld:", hours, minutes);
+else
+ fprintf(cshout, "%lld:", minutes);
+fprintf(cshout, "%02lld.%03ld", seconds, elapsed.tv_nsec / 100);
}
Index: bin/ksh/c_sh.c
===
RCS file: /cvs/src/bin/ksh/c_sh.c,v
retrieving revision 1.64
diff -u -p -r1.64 c_sh.c
--- bin/ksh/c_sh.c 22 May 2020 07:50:07 - 1.64
+++ bin/ksh/c_sh.c 14 Jun 2023 15:30:01 -
@@ -681,13 +681,13 @@ p_tv(struct shf *shf, int posix, struct
char *suffix)
{
if (posix)
- shf_fprintf(shf, "%s%*lld.%02ld%s", prefix ? prefix : "",
- width, (long long)tv->tv_sec, tv->tv_usec / 1, suffix);
+ shf_fprintf(shf, "%s%*lld.%03ld%s", prefix ? prefix : "",
+ width, (long long)tv->tv_sec, tv->tv_usec / 1000, suffix);
else
- shf_fprintf(shf, "%s%*lldm%02lld.%02lds%s", prefix ? prefix :
"",
+ shf_fprintf(shf, "%s%*lldm%02lld.%03lds%s", prefix ? prefix :
"",
width, (long long)tv->tv_sec / 60,
(long long)tv->tv_sec % 60,
- tv->tv_usec / 1, suffix);
+ tv->tv_usec / 1000, suffix);
}
static void
@@ -695,14 +695,14 @@ p_ts(struct shf *shf, int posix, struct
char *suffix)
{
if (posix)
- shf_fprintf(shf, "%s%*lld.%02ld%s", prefix ? prefix : "",
- width, (long long)ts->tv_sec, ts->tv_nsec / 1000,
+ shf_fprintf(shf, "%s%*lld.%03ld%s", prefix ? prefix : "",
+ width, (long long)ts->tv_sec, ts->tv_nsec / 100,
Re: csh(1), ksh(1), time(1): print durations with millisecond precision
On Wed, Jun 14, 2023 at 10:34:20AM -0400, Josiah Frentsos wrote:
> On Tue, Jun 13, 2023 at 10:59:53PM -0500, Scott Cheloha wrote:
> > Index: usr.bin/time/time.c
> > ===
> > RCS file: /cvs/src/usr.bin/time/time.c,v
> > retrieving revision 1.25
> > diff -u -p -r1.25 time.c
> > --- usr.bin/time/time.c 21 Aug 2017 13:38:02 - 1.25
> > +++ usr.bin/time/time.c 14 Jun 2023 03:23:29 -
> > @@ -100,19 +100,19 @@ main(int argc, char *argv[])
> > timespecsub(, , );
> >
> > if (portableflag) {
> > - fprintf(stderr, "real %9lld.%02ld\n",
> > - (long long)during.tv_sec, during.tv_nsec/1000);
> > - fprintf(stderr, "user %9lld.%02ld\n",
> > - (long long)ru.ru_utime.tv_sec,
> > ru.ru_utime.tv_usec/1);
> > - fprintf(stderr, "sys %9lld.%02ld\n",
> > - (long long)ru.ru_stime.tv_sec,
> > ru.ru_stime.tv_usec/1);
> > + fprintf(stderr, "real %9lld.%03ld\n",
> > + (long long)during.tv_sec, during.tv_nsec / 100);
> > + fprintf(stderr, "user %9lld.%03ld\n",
> > + (long long)ru.ru_utime.tv_sec, ru.ru_utime.tv_usec / 1000);
> > + fprintf(stderr, "sys %9lld.%03ld\n",
> > + (long long)ru.ru_stime.tv_sec, ru.ru_stime.tv_usec / 1000);
> > } else {
> > - fprintf(stderr, "%9lld.%02ld real ",
> > - (long long)during.tv_sec, during.tv_nsec/1000);
> > - fprintf(stderr, "%9lld.%02ld user ",
> > - (long long)ru.ru_utime.tv_sec,
> > ru.ru_utime.tv_usec/1);
> > - fprintf(stderr, "%9lld.%02ld sys\n",
> > - (long long)ru.ru_stime.tv_sec,
> > ru.ru_stime.tv_usec/1);
> > + fprintf(stderr, "%9lld.%03ld real ",
> > + (long long)during.tv_sec, during.tv_nsec / 100);
> > + fprintf(stderr, "%9lld.%0ld user ",
>
>
> Should this be "%03ld"?
Whoops, yep, good catch.
Index: bin/csh/time.c
===
RCS file: /cvs/src/bin/csh/time.c,v
retrieving revision 1.18
diff -u -p -r1.18 time.c
--- bin/csh/time.c 8 Mar 2023 04:43:04 - 1.18
+++ bin/csh/time.c 14 Jun 2023 15:30:01 -
@@ -40,6 +40,7 @@
* C Shell - routines handling process timing and niceing
*/
static voidpdeltat(struct timeval *, struct timeval *);
+static voidpdelta_hms(const struct timespec *, const struct timespec *);
void
settimes(void)
@@ -145,7 +146,7 @@ prusage(struct rusage *r0, struct rusage
break;
case 'E': /* elapsed (wall-clock) time */
- pcsecs((long) ms);
+ pdelta_hms(e, b);
break;
case 'P': /* percent time spent running */
@@ -227,8 +228,7 @@ pdeltat(struct timeval *t1, struct timev
struct timeval td;
timersub(t1, t0, );
-(void) fprintf(cshout, "%lld.%01ld", (long long)td.tv_sec,
- td.tv_usec / 10);
+fprintf(cshout, "%lld.%03ld", (long long)td.tv_sec, td.tv_usec / 1000);
}
#define P2DIG(i) (void) fprintf(cshout, "%d%d", (i) / 10, (i) % 10)
@@ -254,23 +254,18 @@ minsec:
}
void
-pcsecs(long l) /* PWP: print mm:ss.dd, l is in sec*100 */
+pdelta_hms(const struct timespec *t1, const struct timespec *t0)
{
-int i;
+struct timespec elapsed;
+long long hours, minutes, seconds;
-i = l / 36;
-if (i) {
- (void) fprintf(cshout, "%d:", i);
- i = (l % 36) / 100;
- P2DIG(i / 60);
- goto minsec;
-}
-i = l / 100;
-(void) fprintf(cshout, "%d", i / 60);
-minsec:
-i %= 60;
-(void) fputc(':', cshout);
-P2DIG(i);
-(void) fputc('.', cshout);
-P2DIG((int) (l % 100));
+timespecsub(t1, t0, );
+hours = elapsed.tv_sec / 3600;
+minutes = (elapsed.tv_sec % 3600) / 60;
+seconds = elapsed.tv_sec % 60;
+if (hours != 0)
+ fprintf(cshout, "%lld:%02lld:", hours, minutes);
+else
+ fprintf(cshout, "%lld:", minutes);
+fprintf(cshout, "%02lld.%03ld", seconds, elapsed.tv_nsec / 100);
}
Index: bin/ksh/c_sh.c
===
RCS file: /cvs/src/bin/ksh/c_sh.c,v
retrieving revision 1.64
diff -u -p -r1.64 c_sh.c
--- bin/ksh/c_sh.c 22 May 2020 07:50:07 - 1.64
+++ bin/ksh/c_sh.c 14 Jun 2023 15:30:01 -
@@ -681,13 +681,13 @@ p_tv(struct shf *shf, int posix, struct
char *suffix)
{
if (posix)
- shf_fprintf(shf, "%s%*lld.%02ld%s", prefix ? prefix : "",
- width, (long long)tv->tv_sec, tv->tv_usec / 1, suffix);
+ shf_fprintf(shf, "%s%*lld.%03ld%s", prefix ? prefix : "",
+ width, (long long)tv->tv_sec, tv->tv_usec / 1000, suffix);
else
-
Re: csh(1), ksh(1), time(1): print durations with millisecond precision
On Tue, Jun 13, 2023 at 10:59:53PM -0500, Scott Cheloha wrote:
> Index: usr.bin/time/time.c
> ===
> RCS file: /cvs/src/usr.bin/time/time.c,v
> retrieving revision 1.25
> diff -u -p -r1.25 time.c
> --- usr.bin/time/time.c 21 Aug 2017 13:38:02 - 1.25
> +++ usr.bin/time/time.c 14 Jun 2023 03:23:29 -
> @@ -100,19 +100,19 @@ main(int argc, char *argv[])
> timespecsub(, , );
>
> if (portableflag) {
> - fprintf(stderr, "real %9lld.%02ld\n",
> - (long long)during.tv_sec, during.tv_nsec/1000);
> - fprintf(stderr, "user %9lld.%02ld\n",
> - (long long)ru.ru_utime.tv_sec,
> ru.ru_utime.tv_usec/1);
> - fprintf(stderr, "sys %9lld.%02ld\n",
> - (long long)ru.ru_stime.tv_sec,
> ru.ru_stime.tv_usec/1);
> + fprintf(stderr, "real %9lld.%03ld\n",
> + (long long)during.tv_sec, during.tv_nsec / 100);
> + fprintf(stderr, "user %9lld.%03ld\n",
> + (long long)ru.ru_utime.tv_sec, ru.ru_utime.tv_usec / 1000);
> + fprintf(stderr, "sys %9lld.%03ld\n",
> + (long long)ru.ru_stime.tv_sec, ru.ru_stime.tv_usec / 1000);
> } else {
> - fprintf(stderr, "%9lld.%02ld real ",
> - (long long)during.tv_sec, during.tv_nsec/1000);
> - fprintf(stderr, "%9lld.%02ld user ",
> - (long long)ru.ru_utime.tv_sec,
> ru.ru_utime.tv_usec/1);
> - fprintf(stderr, "%9lld.%02ld sys\n",
> - (long long)ru.ru_stime.tv_sec,
> ru.ru_stime.tv_usec/1);
> + fprintf(stderr, "%9lld.%03ld real ",
> + (long long)during.tv_sec, during.tv_nsec / 100);
> + fprintf(stderr, "%9lld.%0ld user ",
Should this be "%03ld"?
> + (long long)ru.ru_utime.tv_sec, ru.ru_utime.tv_usec / 1000);
> + fprintf(stderr, "%9lld.%03ld sys\n",
> + (long long)ru.ru_stime.tv_sec, ru.ru_stime.tv_usec / 1000);
> }
>
> if (lflag) {
