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 "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[] = "real\t%E\nuser\t%u\nsys\t%T";
  27
  28 /* The output format for the -p option .*/
  29 static const char posix_format[] = "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[] =
  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         cpu_ticks = vv_ms * TICKS_PER_SEC / 1000;
 184         if (!cpu_ticks) cpu_ticks = 1; /* we divide by it, must be nonzero */
 185
 186         /* putchar() != putc(stdout) in glibc! */
 187
 188         while (*fmt) {
 189                 /* Handle leading literal part */
 190                 int n = strcspn(fmt, "%\\");
 191                 if (n) {
 192                         printf("%.*s", n, fmt);
 193                         fmt += n;
 194                         continue;
 195                 }
 196
 197                 switch (*fmt) {
 198 #ifdef NOT_NEEDED
 199                 /* Handle literal char */
 200                 /* Usually we optimize for size, but there is a limit
 201                  * for everything. With this we do a lot of 1-byte writes */
 202                 default:
 203                         putc(*fmt, stdout);
 204                         break;
 205 #endif
 206
 207                 case '%':
 208                         switch (*++fmt) {
 209 #ifdef NOT_NEEDED_YET
 210                 /* Our format strings do not have these */
 211                 /* and we do not take format str from user */
 212                         default:
 213                                 putc('%', stdout);
 214                                 /*FALLTHROUGH*/
 215                         case '%':
 216                                 if (!*fmt) goto ret;
 217                                 putc(*fmt, stdout);
 218                                 break;
 219 #endif
 220                         case 'C':       /* The command that got timed.  */
 221                                 printargv(command, " ");
 222                                 break;
 223                         case 'D':       /* Average unshared data size.  */
 224                                 printf("%lu",
 225                                                 ptok((UL) resp->ru.ru_idrss) / cpu_ticks +
 226                                                 ptok((UL) resp->ru.ru_isrss) / cpu_ticks);
 227                                 break;
 228                         case 'E': {     /* Elapsed real (wall clock) time.  */
 229                                 unsigned seconds = resp->elapsed_ms / 1000;
 230                                 if (seconds >= 3600)    /* One hour -> h:m:s.  */
 231                                         printf("%uh %um %02us",
 232                                                         seconds / 3600,
 233                                                         (seconds % 3600) / 60,
 234                                                         seconds % 60);
 235                                 else
 236                                         printf("%um %u.%02us",  /* -> m:s.  */
 237                                                         seconds / 60,
 238                                                         seconds % 60,
 239                                                         (unsigned)(resp->elapsed_ms / 10) % 100);
 240                                 break;
 241                         }
 242                         case 'F':       /* Major page faults.  */
 243                                 printf("%lu", resp->ru.ru_majflt);
 244                                 break;
 245                         case 'I':       /* Inputs.  */
 246                                 printf("%lu", resp->ru.ru_inblock);
 247                                 break;
 248                         case 'K':       /* Average mem usage == data+stack+text.  */
 249                                 printf("%lu",
 250                                                 ptok((UL) resp->ru.ru_idrss) / cpu_ticks +
 251                                                 ptok((UL) resp->ru.ru_isrss) / cpu_ticks +
 252                                                 ptok((UL) resp->ru.ru_ixrss) / cpu_ticks);
 253                                 break;
 254                         case 'M':       /* Maximum resident set size.  */
 255                                 printf("%lu", ptok((UL) resp->ru.ru_maxrss));
 256                                 break;
 257                         case 'O':       /* Outputs.  */
 258                                 printf("%lu", resp->ru.ru_oublock);
 259                                 break;
 260                         case 'P':       /* Percent of CPU this job got.  */
 261                                 /* % cpu is (total cpu time)/(elapsed time).  */
 262                                 if (resp->elapsed_ms > 0)
 263                                         printf("%u%%", (unsigned)(vv_ms * 100 / resp->elapsed_ms));
 264                                 else
 265                                         printf("?%%");
 266                                 break;
 267                         case 'R':       /* Minor page faults (reclaims).  */
 268                                 printf("%lu", resp->ru.ru_minflt);
 269                                 break;
 270                         case 'S':       /* System time.  */
 271                                 printf("%u.%02u",
 272                                                 (unsigned)resp->ru.ru_stime.tv_sec,
 273                                                 (unsigned)(resp->ru.ru_stime.tv_usec / 10000));
 274                                 break;
 275                         case 'T':       /* System time.  */
 276                                 if (resp->ru.ru_stime.tv_sec >= 3600) /* One hour -> h:m:s.  */
 277                                         printf("%uh %um %02us",
 278                                                         (unsigned)(resp->ru.ru_stime.tv_sec / 3600),
 279                                                         (unsigned)(resp->ru.ru_stime.tv_sec % 3600) / 60,
 280                                                         (unsigned)(resp->ru.ru_stime.tv_sec % 60));
 281                                 else
 282                                         printf("%um %u.%02us",  /* -> m:s.  */
 283                                                         (unsigned)(resp->ru.ru_stime.tv_sec / 60),
 284                                                         (unsigned)(resp->ru.ru_stime.tv_sec % 60),
 285                                                         (unsigned)(resp->ru.ru_stime.tv_usec / 10000));
 286                                 break;
 287                         case 'U':       /* User time.  */
 288                                 printf("%u.%02u",
 289                                                 (unsigned)resp->ru.ru_utime.tv_sec,
 290                                                 (unsigned)(resp->ru.ru_utime.tv_usec / 10000));
 291                                 break;
 292                         case 'u':       /* User time.  */
 293                                 if (resp->ru.ru_utime.tv_sec >= 3600) /* One hour -> h:m:s.  */
 294                                         printf("%uh %um %02us",
 295                                                         (unsigned)(resp->ru.ru_utime.tv_sec / 3600),
 296                                                         (unsigned)(resp->ru.ru_utime.tv_sec % 3600) / 60,
 297                                                         (unsigned)(resp->ru.ru_utime.tv_sec % 60));
 298                                 else
 299                                         printf("%um %u.%02us",  /* -> m:s.  */
 300                                                         (unsigned)(resp->ru.ru_utime.tv_sec / 60),
 301                                                         (unsigned)(resp->ru.ru_utime.tv_sec % 60),
 302                                                         (unsigned)(resp->ru.ru_utime.tv_usec / 10000));
 303                                 break;
 304                         case 'W':       /* Times swapped out.  */
 305                                 printf("%lu", resp->ru.ru_nswap);
 306                                 break;
 307                         case 'X':       /* Average shared text size.  */
 308                                 printf("%lu", ptok((UL) resp->ru.ru_ixrss) / cpu_ticks);
 309                                 break;
 310                         case 'Z':       /* Page size.  */
 311                                 printf("%u", getpagesize());
 312                                 break;
 313                         case 'c':       /* Involuntary context switches.  */
 314                                 printf("%lu", resp->ru.ru_nivcsw);
 315                                 break;
 316                         case 'e':       /* Elapsed real time in seconds.  */
 317                                 printf("%u.%02u",
 318                                                 (unsigned)resp->elapsed_ms / 1000,
 319                                                 (unsigned)(resp->elapsed_ms / 10) % 100);
 320                                 break;
 321                         case 'k':       /* Signals delivered.  */
 322                                 printf("%lu", resp->ru.ru_nsignals);
 323                                 break;
 324                         case 'p':       /* Average stack segment.  */
 325                                 printf("%lu", ptok((UL) resp->ru.ru_isrss) / cpu_ticks);
 326                                 break;
 327                         case 'r':       /* Incoming socket messages received.  */
 328                                 printf("%lu", resp->ru.ru_msgrcv);
 329                                 break;
 330                         case 's':       /* Outgoing socket messages sent.  */
 331                                 printf("%lu", resp->ru.ru_msgsnd);
 332                                 break;
 333                         case 't':       /* Average resident set size.  */
 334                                 printf("%lu", ptok((UL) resp->ru.ru_idrss) / cpu_ticks);
 335                                 break;
 336                         case 'w':       /* Voluntary context switches.  */
 337                                 printf("%lu", resp->ru.ru_nvcsw);
 338                                 break;
 339                         case 'x':       /* Exit status.  */
 340                                 printf("%u", WEXITSTATUS(resp->waitstatus));
 341                                 break;
 342                         }
 343                         break;
 344
 345 #ifdef NOT_NEEDED_YET
 346                 case '\\':              /* Format escape.  */
 347                         switch (*++fmt) {
 348                         default:
 349                                 putc('\\', stdout);
 350                                 /*FALLTHROUGH*/
 351                         case '\\':
 352                                 if (!*fmt) goto ret;
 353                                 putc(*fmt, stdout);
 354                                 break;
 355                         case 't':
 356                                 putc('\t', stdout);
 357                                 break;
 358                         case 'n':
 359                                 putc('\n', stdout);
 360                                 break;
 361                         }
 362                         break;
 363 #endif
 364                 }
 365                 ++fmt;
 366         }
 367  /* ret: */
 368         putc('\n', stdout);
 369 }
 370
 371 /* Run command CMD and return statistics on it.
 372    Put the statistics in *RESP.  */
 373 static void run_command(char *const *cmd, resource_t * resp)
 374 {
 375         pid_t pid;                      /* Pid of child.  */
 376         __sighandler_t interrupt_signal, quit_signal;
 377
 378         resp->elapsed_ms = monotonic_us() / 1000;
 379         pid = vfork();          /* Run CMD as child process.  */
 380         if (pid < 0)
 381                 bb_error_msg_and_die("cannot fork");
 382         else if (pid == 0) {    /* If child.  */
 383                 /* Don't cast execvp arguments; that causes errors on some systems,
 384                    versus merely warnings if the cast is left off.  */
 385                 BB_EXECVP(cmd[0], cmd);
 386                 bb_error_msg("cannot run %s", cmd[0]);
 387                 _exit(errno == ENOENT ? 127 : 126);
 388         }
 389
 390         /* Have signals kill the child but not self (if possible).  */
 391         interrupt_signal = signal(SIGINT, SIG_IGN);
 392         quit_signal = signal(SIGQUIT, SIG_IGN);
 393
 394         if (resuse_end(pid, resp) == 0)
 395                 bb_error_msg("error waiting for child process");
 396
 397         /* Re-enable signals.  */
 398         signal(SIGINT, interrupt_signal);
 399         signal(SIGQUIT, quit_signal);
 400 }
 401
 402 int time_main(int argc, char **argv);
 403 int time_main(int argc, char **argv)
 404 {
 405         resource_t res;
 406         const char *output_format = default_format;
 407         char c;
 408
 409         goto next;
 410         /* Parse any options  -- don't use getopt() here so we don't
 411          * consume the args of our client application... */
 412         while (argc > 0 && argv[0][0] == '-') {
 413                 while ((c = *++*argv)) {
 414                         switch (c) {
 415                         case 'v':
 416                                 output_format = long_format;
 417                                 break;
 418                         case 'p':
 419                                 output_format = posix_format;
 420                                 break;
 421                         default:
 422                                 bb_show_usage();
 423                         }
 424                 }
 425  next:
 426                 argv++;
 427                 argc--;
 428                 if (!argc)
 429                         bb_show_usage();
 430         }
 431
 432         run_command(argv, &res);
 433
 434         /* Cheat. printf's are shorter :) */
 435         stdout = stderr;
 436         dup2(2, 1); /* just in case libc does something silly :( */
 437         summarize(output_format, argv, &res);
 438
 439         if (WIFSTOPPED(res.waitstatus))
 440                 return WSTOPSIG(res.waitstatus);
 441         if (WIFSIGNALED(res.waitstatus))
 442                 return WTERMSIG(res.waitstatus);
 443         if (WIFEXITED(res.waitstatus))
 444                 return WEXITSTATUS(res.waitstatus);
 445         fflush_stdout_and_exit(0);
 446 }