miscutils/time.c

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