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