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