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