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