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