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