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