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