miscutils/time.c

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