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