miscutils/time.c

   1 /* vi: set sw=4 ts=4: */
   2 /* `time' utility to display resource usage of processes.
   3    Copyright (C) 1990, 91, 92, 93, 96 Free Software Foundation, Inc.
   4
   5    Licensed under GPLv2 or later, see file LICENSE in this tarball for details.
   6 */
   7 /* Originally written by David Keppel <pardo@cs.washington.edu>.
   8    Heavily modified by David MacKenzie <djm@gnu.ai.mit.edu>.
   9    Heavily modified for busybox by Erik Andersen <andersen@codepoet.org>
  10 */
  11
  12 #include "busybox.h"
  13 #include <stdlib.h>
  14 #include <stdio.h>
  15 #include <signal.h>
  16 #include <errno.h>
  17 #include <getopt.h>
  18 #include <string.h>
  19 #include <limits.h>
  20 #include <unistd.h>
  21 #include <sys/types.h>  /* For pid_t. */
  22 #include <sys/wait.h>
  23 #include <sys/param.h>  /* For getpagesize, maybe.  */
  24
  25 #define TV_MSEC tv_usec / 1000
  26 #include <sys/resource.h>
  27
  28 /* Information on the resources used by a child process.  */
  29 typedef struct {
  30         int waitstatus;
  31         struct rusage ru;
  32         struct timeval start, elapsed;  /* Wallclock time of process.  */
  33 } resource_t;
  34
  35 /* msec = milliseconds = 1/1,000 (1*10e-3) second.
  36    usec = microseconds = 1/1,000,000 (1*10e-6) second.  */
  37
  38 #ifndef TICKS_PER_SEC
  39 #define TICKS_PER_SEC 100
  40 #endif
  41
  42 /* The number of milliseconds in one `tick' used by the `rusage' structure.  */
  43 #define MSEC_PER_TICK (1000 / TICKS_PER_SEC)
  44
  45 /* Return the number of clock ticks that occur in M milliseconds.  */
  46 #define MSEC_TO_TICKS(m) ((m) / MSEC_PER_TICK)
  47
  48 #define UL unsigned long
  49
  50 static const char *const default_format = "real\t%E\nuser\t%u\nsys\t%T";
  51
  52 /* The output format for the -p option .*/
  53 static const char *const posix_format = "real %e\nuser %U\nsys %S";
  54
  55
  56 /* Format string for printing all statistics verbosely.
  57    Keep this output to 24 lines so users on terminals can see it all.*/
  58 static const char *const long_format =
  59         "\tCommand being timed: \"%C\"\n"
  60         "\tUser time (seconds): %U\n"
  61         "\tSystem time (seconds): %S\n"
  62         "\tPercent of CPU this job got: %P\n"
  63         "\tElapsed (wall clock) time (h:mm:ss or m:ss): %E\n"
  64         "\tAverage shared text size (kbytes): %X\n"
  65         "\tAverage unshared data size (kbytes): %D\n"
  66         "\tAverage stack size (kbytes): %p\n"
  67         "\tAverage total size (kbytes): %K\n"
  68         "\tMaximum resident set size (kbytes): %M\n"
  69         "\tAverage resident set size (kbytes): %t\n"
  70         "\tMajor (requiring I/O) page faults: %F\n"
  71         "\tMinor (reclaiming a frame) page faults: %R\n"
  72         "\tVoluntary context switches: %w\n"
  73         "\tInvoluntary context switches: %c\n"
  74         "\tSwaps: %W\n"
  75         "\tFile system inputs: %I\n"
  76         "\tFile system outputs: %O\n"
  77         "\tSocket messages sent: %s\n"
  78         "\tSocket messages received: %r\n"
  79         "\tSignals delivered: %k\n"
  80         "\tPage size (bytes): %Z\n" "\tExit status: %x";
  81
  82
  83   /* Wait for and fill in data on child process PID.
  84      Return 0 on error, 1 if ok.  */
  85
  86 /* pid_t is short on BSDI, so don't try to promote it.  */
  87 static int resuse_end(pid_t pid, resource_t * resp)
  88 {
  89         int status;
  90
  91         pid_t caught;
  92
  93         /* Ignore signals, but don't ignore the children.  When wait3
  94            returns the child process, set the time the command finished. */
  95         while ((caught = wait3(&status, 0, &resp->ru)) != pid) {
  96                 if (caught == -1)
  97                         return 0;
  98         }
  99
 100         gettimeofday(&resp->elapsed, (struct timezone *) 0);
 101         resp->elapsed.tv_sec -= resp->start.tv_sec;
 102         if (resp->elapsed.tv_usec < resp->start.tv_usec) {
 103                 /* Manually carry a one from the seconds field.  */
 104                 resp->elapsed.tv_usec += 1000000;
 105                 --resp->elapsed.tv_sec;
 106         }
 107         resp->elapsed.tv_usec -= resp->start.tv_usec;
 108
 109         resp->waitstatus = status;
 110
 111         return 1;
 112 }
 113
 114 /* Print ARGV to FP, with each entry in ARGV separated by FILLER.  */
 115 static void fprintargv(FILE * fp, char *const *argv, const char *filler)
 116 {
 117         char *const *av;
 118
 119         av = argv;
 120         fputs(*av, fp);
 121         while (*++av) {
 122                 fputs(filler, fp);
 123                 fputs(*av, fp);
 124         }
 125         if (ferror(fp))
 126                 bb_error_msg_and_die(bb_msg_write_error);
 127 }
 128
 129 /* Return the number of kilobytes corresponding to a number of pages PAGES.
 130    (Actually, we use it to convert pages*ticks into kilobytes*ticks.)
 131
 132    Try to do arithmetic so that the risk of overflow errors is minimized.
 133    This is funky since the pagesize could be less than 1K.
 134    Note: Some machines express getrusage statistics in terms of K,
 135    others in terms of pages.  */
 136
 137 static unsigned long ptok(unsigned long pages)
 138 {
 139         static unsigned long ps = 0;
 140         unsigned long tmp;
 141         static long size = LONG_MAX;
 142
 143         /* Initialization.  */
 144         if (ps == 0)
 145                 ps = (long) getpagesize();
 146
 147         /* Conversion.  */
 148         if (pages > (LONG_MAX / ps)) {  /* Could overflow.  */
 149                 tmp = pages / 1024;     /* Smaller first, */
 150                 size = tmp * ps;        /* then larger.  */
 151         } else {                        /* Could underflow.  */
 152                 tmp = pages * ps;       /* Larger first, */
 153                 size = tmp / 1024;      /* then smaller.  */
 154         }
 155         return size;
 156 }
 157
 158 /* summarize: Report on the system use of a command.
 159
 160    Copy the FMT argument to FP except that `%' sequences
 161    have special meaning, and `\n' and `\t' are translated into
 162    newline and tab, respectively, and `\\' is translated into `\'.
 163
 164    The character following a `%' can be:
 165    (* means the tcsh time builtin also recognizes it)
 166    % == a literal `%'
 167    C == command name and arguments
 168 *  D == average unshared data size in K (ru_idrss+ru_isrss)
 169 *  E == elapsed real (wall clock) time in [hour:]min:sec
 170 *  F == major page faults (required physical I/O) (ru_majflt)
 171 *  I == file system inputs (ru_inblock)
 172 *  K == average total mem usage (ru_idrss+ru_isrss+ru_ixrss)
 173 *  M == maximum resident set size in K (ru_maxrss)
 174 *  O == file system outputs (ru_oublock)
 175 *  P == percent of CPU this job got (total cpu time / elapsed time)
 176 *  R == minor page faults (reclaims; no physical I/O involved) (ru_minflt)
 177 *  S == system (kernel) time (seconds) (ru_stime)
 178 *  T == system time in [hour:]min:sec
 179 *  U == user time (seconds) (ru_utime)
 180 *  u == user time in [hour:]min:sec
 181 *  W == times swapped out (ru_nswap)
 182 *  X == average amount of shared text in K (ru_ixrss)
 183    Z == page size
 184 *  c == involuntary context switches (ru_nivcsw)
 185    e == elapsed real time in seconds
 186 *  k == signals delivered (ru_nsignals)
 187    p == average unshared stack size in K (ru_isrss)
 188 *  r == socket messages received (ru_msgrcv)
 189 *  s == socket messages sent (ru_msgsnd)
 190    t == average resident set size in K (ru_idrss)
 191 *  w == voluntary context switches (ru_nvcsw)
 192    x == exit status of command
 193
 194    Various memory usages are found by converting from page-seconds
 195    to kbytes by multiplying by the page size, dividing by 1024,
 196    and dividing by elapsed real time.
 197
 198    FP is the stream to print to.
 199    FMT is the format string, interpreted as described above.
 200    COMMAND is the command and args that are being summarized.
 201    RESP is resource information on the command.  */
 202
 203 static void summarize(FILE * fp, const char *fmt, char **command,
 204                                           resource_t * resp)
 205 {
 206         unsigned long r;        /* Elapsed real milliseconds.  */
 207         unsigned long v;        /* Elapsed virtual (CPU) milliseconds.  */
 208
 209         if (WIFSTOPPED(resp->waitstatus))
 210                 fprintf(fp, "Command stopped by signal %d\n",
 211                                 WSTOPSIG(resp->waitstatus));
 212         else if (WIFSIGNALED(resp->waitstatus))
 213                 fprintf(fp, "Command terminated by signal %d\n",
 214                                 WTERMSIG(resp->waitstatus));
 215         else if (WIFEXITED(resp->waitstatus) && WEXITSTATUS(resp->waitstatus))
 216                 fprintf(fp, "Command exited with non-zero status %d\n",
 217                                 WEXITSTATUS(resp->waitstatus));
 218
 219         /* Convert all times to milliseconds.  Occasionally, one of these values
 220            comes out as zero.  Dividing by zero causes problems, so we first
 221            check the time value.  If it is zero, then we take `evasive action'
 222            instead of calculating a value.  */
 223
 224         r = resp->elapsed.tv_sec * 1000 + resp->elapsed.tv_usec / 1000;
 225
 226         v = resp->ru.ru_utime.tv_sec * 1000 + resp->ru.ru_utime.TV_MSEC +
 227                 resp->ru.ru_stime.tv_sec * 1000 + resp->ru.ru_stime.TV_MSEC;
 228
 229         while (*fmt) {
 230                 switch (*fmt) {
 231                 case '%':
 232                         switch (*++fmt) {
 233                         case '%':       /* Literal '%'.  */
 234                                 putc('%', fp);
 235                                 break;
 236                         case 'C':       /* The command that got timed.  */
 237                                 fprintargv(fp, command, " ");
 238                                 break;
 239                         case 'D':       /* Average unshared data size.  */
 240                                 fprintf(fp, "%lu",
 241                                                 MSEC_TO_TICKS(v) == 0 ? 0 :
 242                                                 ptok((UL) resp->ru.ru_idrss) / MSEC_TO_TICKS(v) +
 243                                                 ptok((UL) resp->ru.ru_isrss) / MSEC_TO_TICKS(v));
 244                                 break;
 245                         case 'E':       /* Elapsed real (wall clock) time.  */
 246                                 if (resp->elapsed.tv_sec >= 3600)       /* One hour -> h:m:s.  */
 247                                         fprintf(fp, "%ldh %ldm %02lds",
 248                                                         resp->elapsed.tv_sec / 3600,
 249                                                         (resp->elapsed.tv_sec % 3600) / 60,
 250                                                         resp->elapsed.tv_sec % 60);
 251                                 else
 252                                         fprintf(fp, "%ldm %ld.%02lds",  /* -> m:s.  */
 253                                                         resp->elapsed.tv_sec / 60,
 254                                                         resp->elapsed.tv_sec % 60,
 255                                                         resp->elapsed.tv_usec / 10000);
 256                                 break;
 257                         case 'F':       /* Major page faults.  */
 258                                 fprintf(fp, "%ld", resp->ru.ru_majflt);
 259                                 break;
 260                         case 'I':       /* Inputs.  */
 261                                 fprintf(fp, "%ld", resp->ru.ru_inblock);
 262                                 break;
 263                         case 'K':       /* Average mem usage == data+stack+text.  */
 264                                 fprintf(fp, "%lu",
 265                                                 MSEC_TO_TICKS(v) == 0 ? 0 :
 266                                                 ptok((UL) resp->ru.ru_idrss) / MSEC_TO_TICKS(v) +
 267                                                 ptok((UL) resp->ru.ru_isrss) / MSEC_TO_TICKS(v) +
 268                                                 ptok((UL) resp->ru.ru_ixrss) / MSEC_TO_TICKS(v));
 269                                 break;
 270                         case 'M':       /* Maximum resident set size.  */
 271                                 fprintf(fp, "%lu", ptok((UL) resp->ru.ru_maxrss));
 272                                 break;
 273                         case 'O':       /* Outputs.  */
 274                                 fprintf(fp, "%ld", resp->ru.ru_oublock);
 275                                 break;
 276                         case 'P':       /* Percent of CPU this job got.  */
 277                                 /* % cpu is (total cpu time)/(elapsed time).  */
 278                                 if (r > 0)
 279                                         fprintf(fp, "%lu%%", (v * 100 / r));
 280                                 else
 281                                         fprintf(fp, "?%%");
 282                                 break;
 283                         case 'R':       /* Minor page faults (reclaims).  */
 284                                 fprintf(fp, "%ld", resp->ru.ru_minflt);
 285                                 break;
 286                         case 'S':       /* System time.  */
 287                                 fprintf(fp, "%ld.%02ld",
 288                                                 resp->ru.ru_stime.tv_sec,
 289                                                 resp->ru.ru_stime.TV_MSEC / 10);
 290                                 break;
 291                         case 'T':       /* System time.  */
 292                                 if (resp->ru.ru_stime.tv_sec >= 3600) /* One hour -> h:m:s.  */
 293                                         fprintf(fp, "%ldh %ldm %02lds",
 294                                                         resp->ru.ru_stime.tv_sec / 3600,
 295                                                         (resp->ru.ru_stime.tv_sec % 3600) / 60,
 296                                                         resp->ru.ru_stime.tv_sec % 60);
 297                                 else
 298                                         fprintf(fp, "%ldm %ld.%02lds",  /* -> m:s.  */
 299                                                         resp->ru.ru_stime.tv_sec / 60,
 300                                                         resp->ru.ru_stime.tv_sec % 60,
 301                                                         resp->ru.ru_stime.tv_usec / 10000);
 302                                 break;
 303                         case 'U':       /* User time.  */
 304                                 fprintf(fp, "%ld.%02ld",
 305                                                 resp->ru.ru_utime.tv_sec,
 306                                                 resp->ru.ru_utime.TV_MSEC / 10);
 307                                 break;
 308                         case 'u':       /* User time.  */
 309                                 if (resp->ru.ru_utime.tv_sec >= 3600) /* One hour -> h:m:s.  */
 310                                         fprintf(fp, "%ldh %ldm %02lds",
 311                                                         resp->ru.ru_utime.tv_sec / 3600,
 312                                                         (resp->ru.ru_utime.tv_sec % 3600) / 60,
 313                                                         resp->ru.ru_utime.tv_sec % 60);
 314                                 else
 315                                         fprintf(fp, "%ldm %ld.%02lds",  /* -> m:s.  */
 316                                                         resp->ru.ru_utime.tv_sec / 60,
 317                                                         resp->ru.ru_utime.tv_sec % 60,
 318                                                         resp->ru.ru_utime.tv_usec / 10000);
 319                                 break;
 320                         case 'W':       /* Times swapped out.  */
 321                                 fprintf(fp, "%ld", resp->ru.ru_nswap);
 322                                 break;
 323                         case 'X':       /* Average shared text size.  */
 324                                 fprintf(fp, "%lu",
 325                                                 MSEC_TO_TICKS(v) == 0 ? 0 :
 326                                                 ptok((UL) resp->ru.ru_ixrss) / MSEC_TO_TICKS(v));
 327                                 break;
 328                         case 'Z':       /* Page size.  */
 329                                 fprintf(fp, "%d", getpagesize());
 330                                 break;
 331                         case 'c':       /* Involuntary context switches.  */
 332                                 fprintf(fp, "%ld", resp->ru.ru_nivcsw);
 333                                 break;
 334                         case 'e':       /* Elapsed real time in seconds.  */
 335                                 fprintf(fp, "%ld.%02ld",
 336                                                 resp->elapsed.tv_sec, resp->elapsed.tv_usec / 10000);
 337                                 break;
 338                         case 'k':       /* Signals delivered.  */
 339                                 fprintf(fp, "%ld", resp->ru.ru_nsignals);
 340                                 break;
 341                         case 'p':       /* Average stack segment.  */
 342                                 fprintf(fp, "%lu",
 343                                                 MSEC_TO_TICKS(v) == 0 ? 0 :
 344                                                 ptok((UL) resp->ru.ru_isrss) / MSEC_TO_TICKS(v));
 345                                 break;
 346                         case 'r':       /* Incoming socket messages received.  */
 347                                 fprintf(fp, "%ld", resp->ru.ru_msgrcv);
 348                                 break;
 349                         case 's':       /* Outgoing socket messages sent.  */
 350                                 fprintf(fp, "%ld", resp->ru.ru_msgsnd);
 351                                 break;
 352                         case 't':       /* Average resident set size.  */
 353                                 fprintf(fp, "%lu",
 354                                                 MSEC_TO_TICKS(v) == 0 ? 0 :
 355                                                 ptok((UL) resp->ru.ru_idrss) / MSEC_TO_TICKS(v));
 356                                 break;
 357                         case 'w':       /* Voluntary context switches.  */
 358                                 fprintf(fp, "%ld", resp->ru.ru_nvcsw);
 359                                 break;
 360                         case 'x':       /* Exit status.  */
 361                                 fprintf(fp, "%d", WEXITSTATUS(resp->waitstatus));
 362                                 break;
 363                         case '\0':
 364                                 putc('?', fp);
 365                                 return;
 366                         default:
 367                                 putc('?', fp);
 368                                 putc(*fmt, fp);
 369                         }
 370                         ++fmt;
 371                         break;
 372
 373                 case '\\':              /* Format escape.  */
 374                         switch (*++fmt) {
 375                         case 't':
 376                                 putc('\t', fp);
 377                                 break;
 378                         case 'n':
 379                                 putc('\n', fp);
 380                                 break;
 381                         case '\\':
 382                                 putc('\\', fp);
 383                                 break;
 384                         default:
 385                                 putc('?', fp);
 386                                 putc('\\', fp);
 387                                 putc(*fmt, fp);
 388                         }
 389                         ++fmt;
 390                         break;
 391
 392                 default:
 393                         putc(*fmt++, fp);
 394                 }
 395
 396                 if (ferror(fp))
 397                         bb_error_msg_and_die(bb_msg_write_error);
 398         }
 399         putc('\n', fp);
 400
 401         if (ferror(fp))
 402                 bb_error_msg_and_die(bb_msg_write_error);
 403 }
 404
 405 /* Run command CMD and return statistics on it.
 406    Put the statistics in *RESP.  */
 407 static void run_command(char *const *cmd, resource_t * resp)
 408 {
 409         pid_t pid;                      /* Pid of child.  */
 410         __sighandler_t interrupt_signal, quit_signal;
 411
 412         gettimeofday(&resp->start, (struct timezone *) 0);
 413         pid = vfork();          /* Run CMD as child process.  */
 414         if (pid < 0)
 415                 bb_error_msg_and_die("cannot fork");
 416         else if (pid == 0) {    /* If child.  */
 417                 /* Don't cast execvp arguments; that causes errors on some systems,
 418                    versus merely warnings if the cast is left off.  */
 419                 execvp(cmd[0], cmd);
 420                 bb_error_msg("cannot run %s", cmd[0]);
 421                 _exit(errno == ENOENT ? 127 : 126);
 422         }
 423
 424         /* Have signals kill the child but not self (if possible).  */
 425         interrupt_signal = signal(SIGINT, SIG_IGN);
 426         quit_signal = signal(SIGQUIT, SIG_IGN);
 427
 428         if (resuse_end(pid, resp) == 0)
 429                 bb_error_msg("error waiting for child process");
 430
 431         /* Re-enable signals.  */
 432         signal(SIGINT, interrupt_signal);
 433         signal(SIGQUIT, quit_signal);
 434 }
 435
 436 int time_main(int argc, char **argv)
 437 {
 438         int gotone;
 439         resource_t res;
 440         const char *output_format = default_format;
 441
 442         argc--;
 443         argv++;
 444         /* Parse any options  -- don't use getopt() here so we don't
 445          * consume the args of our client application... */
 446         while (argc > 0 && **argv == '-') {
 447                 gotone = 0;
 448                 while (gotone == 0 && *++(*argv)) {
 449                         switch (**argv) {
 450                         case 'v':
 451                                 output_format = long_format;
 452                                 break;
 453                         case 'p':
 454                                 output_format = posix_format;
 455                                 break;
 456                         default:
 457                                 bb_show_usage();
 458                         }
 459                         argc--;
 460                         argv++;
 461                         gotone = 1;
 462                 }
 463         }
 464
 465         if (argv == NULL || *argv == NULL)
 466                 bb_show_usage();
 467
 468         run_command(argv, &res);
 469         summarize(stderr, output_format, argv, &res);
 470         fflush(stderr);
 471
 472         if (WIFSTOPPED(res.waitstatus))
 473                 exit(WSTOPSIG(res.waitstatus));
 474         else if (WIFSIGNALED(res.waitstatus))
 475                 exit(WTERMSIG(res.waitstatus));
 476         else if (WIFEXITED(res.waitstatus))
 477                 exit(WEXITSTATUS(res.waitstatus));
 478         return 0;
 479 }