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
wait3(int * status,int options,struct rusage * rusage)37 static 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. */
44 typedef 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
55 static const char default_format[] ALIGN1 = "real\t%E\nuser\t%u\nsys\t%T";
56
57 /* The output format for the -p option .*/
58 static 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.*/
62 static 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. */
resuse_end(pid_t pid,resource_t * resp)90 static 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
printargv(char * const * argv)105 static 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
ptok(const unsigned pagesize,const unsigned long pages)125 static 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
summarize(const char * fmt,char ** command,resource_t * resp)188 static 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. */
run_command(char * const * cmd,resource_t * resp)402 static 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
427 int time_main(int argc, char **argv) MAIN_EXTERNALLY_VISIBLE;
time_main(int argc UNUSED_PARAM,char ** argv)428 int 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