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