]>
Commit | Line | Data |
---|---|---|
1 | /* | |
2 | * Copyright (C) 1980 Regents of the University of California. | |
3 | * Copyright (C) 2013-2019 Karel Zak <kzak@redhat.com> | |
4 | * | |
5 | * All rights reserved. | |
6 | * | |
7 | * Redistribution and use in source and binary forms, with or without | |
8 | * modification, are permitted provided that the following conditions | |
9 | * are met: | |
10 | * 1. Redistributions of source code must retain the above copyright | |
11 | * notice, this list of conditions and the following disclaimer. | |
12 | * 2. Redistributions in binary form must reproduce the above copyright | |
13 | * notice, this list of conditions and the following disclaimer in the | |
14 | * documentation and/or other materials provided with the distribution. | |
15 | * 3. All advertising materials mentioning features or use of this software | |
16 | * must display the following acknowledgement: | |
17 | * This product includes software developed by the University of | |
18 | * California, Berkeley and its contributors. | |
19 | * 4. Neither the name of the University nor the names of its contributors | |
20 | * may be used to endorse or promote products derived from this software | |
21 | * without specific prior written permission. | |
22 | * | |
23 | * THIS SOFTWARE IS PROVIDED BY THE REGENTS AND CONTRIBUTORS ``AS IS'' AND | |
24 | * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE | |
25 | * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE | |
26 | * ARE DISCLAIMED. IN NO EVENT SHALL THE REGENTS OR CONTRIBUTORS BE LIABLE | |
27 | * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL | |
28 | * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS | |
29 | * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) | |
30 | * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT | |
31 | * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY | |
32 | * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF | |
33 | * SUCH DAMAGE. | |
34 | */ | |
35 | #include <stdio.h> | |
36 | #include <stdlib.h> | |
37 | #include <paths.h> | |
38 | #include <time.h> | |
39 | #include <sys/stat.h> | |
40 | #include <termios.h> | |
41 | #include <sys/ioctl.h> | |
42 | #include <sys/time.h> | |
43 | #include <signal.h> | |
44 | #include <errno.h> | |
45 | #include <string.h> | |
46 | #include <getopt.h> | |
47 | #include <unistd.h> | |
48 | #include <fcntl.h> | |
49 | #include <limits.h> | |
50 | #include <locale.h> | |
51 | #include <stddef.h> | |
52 | #include <sys/wait.h> | |
53 | #include <poll.h> | |
54 | #include <sys/signalfd.h> | |
55 | #include <assert.h> | |
56 | #include <inttypes.h> | |
57 | ||
58 | #include "closestream.h" | |
59 | #include "nls.h" | |
60 | #include "c.h" | |
61 | #include "cctype.h" | |
62 | #include "ttyutils.h" | |
63 | #include "all-io.h" | |
64 | #include "monotonic.h" | |
65 | #include "timeutils.h" | |
66 | #include "strutils.h" | |
67 | #include "strv.h" | |
68 | #include "xalloc.h" | |
69 | #include "optutils.h" | |
70 | #include "signames.h" | |
71 | #include "pty-session.h" | |
72 | #include "debug.h" | |
73 | ||
74 | static UL_DEBUG_DEFINE_MASK(script); | |
75 | UL_DEBUG_DEFINE_MASKNAMES(script) = UL_DEBUG_EMPTY_MASKNAMES; | |
76 | ||
77 | #define SCRIPT_DEBUG_INIT (1 << 1) | |
78 | #define SCRIPT_DEBUG_PTY (1 << 2) | |
79 | #define SCRIPT_DEBUG_IO (1 << 3) | |
80 | #define SCRIPT_DEBUG_SIGNAL (1 << 4) | |
81 | #define SCRIPT_DEBUG_MISC (1 << 5) | |
82 | #define SCRIPT_DEBUG_ALL 0xFFFF | |
83 | ||
84 | #define DBG(m, x) __UL_DBG(script, SCRIPT_DEBUG_, m, x) | |
85 | #define ON_DBG(m, x) __UL_DBG_CALL(script, SCRIPT_DEBUG_, m, x) | |
86 | ||
87 | #ifdef HAVE_LIBUTEMPTER | |
88 | # include <utempter.h> | |
89 | #endif | |
90 | ||
91 | #define DEFAULT_TYPESCRIPT_FILENAME "typescript" | |
92 | ||
93 | /* | |
94 | * Script is driven by stream (stdout/stdin) activity. It's possible to | |
95 | * associate arbitrary number of log files with the stream. We have two basic | |
96 | * types of log files: "timing file" (simple or multistream) and "data file" | |
97 | * (raw). | |
98 | * | |
99 | * The same log file maybe be shared between both streams. For example | |
100 | * multi-stream timing file is possible to use for stdin as well as for stdout. | |
101 | */ | |
102 | enum { | |
103 | SCRIPT_FMT_RAW = 1, /* raw slave/master data */ | |
104 | SCRIPT_FMT_TIMING_SIMPLE, /* (classic) in format "<delta> <offset>" */ | |
105 | SCRIPT_FMT_TIMING_MULTI, /* (advanced) multiple streams in format "<type> <delta> <offset|etc> */ | |
106 | }; | |
107 | ||
108 | struct script_log { | |
109 | FILE *fp; /* file pointer (handler) */ | |
110 | int format; /* SCRIPT_FMT_* */ | |
111 | char *filename; /* on command line specified name */ | |
112 | struct timeval oldtime; /* previous entry log time (SCRIPT_FMT_TIMING_* only) */ | |
113 | struct timeval starttime; | |
114 | ||
115 | unsigned int initialized : 1; | |
116 | }; | |
117 | ||
118 | struct script_stream { | |
119 | struct script_log **logs; /* logs where to write data from stream */ | |
120 | size_t nlogs; /* number of logs */ | |
121 | char ident; /* stream identifier */ | |
122 | }; | |
123 | ||
124 | struct script_control { | |
125 | uint64_t outsz; /* current output files size */ | |
126 | uint64_t maxsz; /* maximum output files size */ | |
127 | ||
128 | struct script_stream out; /* output */ | |
129 | struct script_stream in; /* input */ | |
130 | ||
131 | struct script_log *siglog; /* log for signal entries */ | |
132 | struct script_log *infolog; /* log for info entries */ | |
133 | ||
134 | const char *ttyname; | |
135 | const char *ttytype; | |
136 | const char *command; | |
137 | char *command_norm; /* normalized (without \n) */ | |
138 | int ttycols; | |
139 | int ttylines; | |
140 | ||
141 | struct ul_pty *pty; /* pseudo-terminal */ | |
142 | pid_t child; /* child pid */ | |
143 | int childstatus; /* child process exit value */ | |
144 | ||
145 | bool append, /* append output */ | |
146 | rc_wanted, /* return child exit value */ | |
147 | flush, /* flush after each write */ | |
148 | quiet, /* suppress most output */ | |
149 | force, /* write output to links */ | |
150 | isterm; /* is child process running as terminal */ | |
151 | }; | |
152 | ||
153 | static ssize_t log_info(struct script_control *ctl, const char *name, const char *msgfmt, ...) | |
154 | __attribute__((__format__ (__printf__, 3, 4))); | |
155 | ||
156 | static void script_init_debug(void) | |
157 | { | |
158 | __UL_INIT_DEBUG_FROM_ENV(script, SCRIPT_DEBUG_, 0, SCRIPT_DEBUG); | |
159 | } | |
160 | ||
161 | static void init_terminal_info(struct script_control *ctl) | |
162 | { | |
163 | if (ctl->ttyname || !ctl->isterm) | |
164 | return; /* already initialized */ | |
165 | ||
166 | get_terminal_dimension(&ctl->ttycols, &ctl->ttylines); | |
167 | get_terminal_name(&ctl->ttyname, NULL, NULL); | |
168 | get_terminal_type(&ctl->ttytype); | |
169 | } | |
170 | ||
171 | /* | |
172 | * For tests we want to be able to control time output | |
173 | */ | |
174 | #ifdef TEST_SCRIPT | |
175 | static inline time_t script_time(time_t *t) | |
176 | { | |
177 | const char *str = getenv("SCRIPT_TEST_SECOND_SINCE_EPOCH"); | |
178 | int64_t sec; | |
179 | ||
180 | if (!str || sscanf(str, "%"SCNi64, &sec) != 1) | |
181 | return time(t); | |
182 | if (t) | |
183 | *t = (time_t)sec; | |
184 | return (time_t)sec; | |
185 | } | |
186 | #else /* !TEST_SCRIPT */ | |
187 | # define script_time(x) time(x) | |
188 | #endif | |
189 | ||
190 | static void __attribute__((__noreturn__)) usage(void) | |
191 | { | |
192 | FILE *out = stdout; | |
193 | fputs(USAGE_HEADER, out); | |
194 | fprintf(out, _(" %s [options] [<file>] [-- <command> [<argument>...]]\n"), program_invocation_short_name); | |
195 | ||
196 | fputs(USAGE_SEPARATOR, out); | |
197 | fputs(_("Make a typescript of a terminal session.\n"), out); | |
198 | ||
199 | fputs(USAGE_OPTIONS, out); | |
200 | fputs(_(" -I, --log-in <file> log stdin to file\n"), out); | |
201 | fputs(_(" -O, --log-out <file> log stdout to file (default)\n"), out); | |
202 | fputs(_(" -B, --log-io <file> log stdin and stdout to file\n"), out); | |
203 | fputs(USAGE_SEPARATOR, out); | |
204 | ||
205 | fputs(_(" -T, --log-timing <file> log timing information to file\n"), out); | |
206 | fputs(_(" -t[<file>], --timing[=<file>] deprecated alias to -T (default file is stderr)\n"), out); | |
207 | fputs(_(" -m, --logging-format <name> force to 'classic' or 'advanced' format\n"), out); | |
208 | fputs(USAGE_SEPARATOR, out); | |
209 | ||
210 | fputs(_(" -a, --append append to the log file\n"), out); | |
211 | fputs(_(" -c, --command <command> run <command> rather than an interactive shell\n" | |
212 | " (alternative to '-- <command> [<argument...>]')\n"), out); | |
213 | fputs(_(" -e, --return return exit code of the child process\n"), out); | |
214 | fputs(_(" -f, --flush run flush after each write\n"), out); | |
215 | fputs(_(" --force use output file even when it is a link\n"), out); | |
216 | fputs(_(" -E, --echo <when> echo input in session (auto, always or never)\n"), out); | |
217 | fputs(_(" -o, --output-limit <size> terminate if output files exceed size\n"), out); | |
218 | fputs(_(" -q, --quiet be quiet\n"), out); | |
219 | ||
220 | fputs(USAGE_SEPARATOR, out); | |
221 | fprintf(out, USAGE_HELP_OPTIONS(31)); | |
222 | ||
223 | fputs(USAGE_ARGUMENTS, out); | |
224 | fprintf(out, USAGE_ARG_SIZE(_("<size>"))); | |
225 | ||
226 | fprintf(out, USAGE_MAN_TAIL("script(1)")); | |
227 | ||
228 | exit(EXIT_SUCCESS); | |
229 | } | |
230 | ||
231 | static struct script_log *get_log_by_name(struct script_stream *stream, | |
232 | const char *name) | |
233 | { | |
234 | size_t i; | |
235 | ||
236 | for (i = 0; i < stream->nlogs; i++) { | |
237 | struct script_log *log = stream->logs[i]; | |
238 | if (strcmp(log->filename, name) == 0) | |
239 | return log; | |
240 | } | |
241 | return NULL; | |
242 | } | |
243 | ||
244 | static struct script_log *log_associate(struct script_control *ctl, | |
245 | struct script_stream *stream, | |
246 | const char *filename, int format) | |
247 | { | |
248 | struct script_log *log; | |
249 | ||
250 | DBG(MISC, ul_debug("associate %s with stream", filename)); | |
251 | ||
252 | assert(ctl); | |
253 | assert(filename); | |
254 | assert(stream); | |
255 | ||
256 | log = get_log_by_name(stream, filename); | |
257 | if (log) | |
258 | return log; /* already defined */ | |
259 | ||
260 | log = get_log_by_name(stream == &ctl->out ? &ctl->in : &ctl->out, filename); | |
261 | if (!log) { | |
262 | /* create a new log */ | |
263 | log = xcalloc(1, sizeof(*log)); | |
264 | log->filename = xstrdup(filename); | |
265 | log->format = format; | |
266 | } | |
267 | ||
268 | /* add log to the stream */ | |
269 | stream->logs = xreallocarray(stream->logs, | |
270 | stream->nlogs + 1, sizeof(log)); | |
271 | stream->logs[stream->nlogs] = log; | |
272 | stream->nlogs++; | |
273 | ||
274 | /* remember where to write info about signals */ | |
275 | if (format == SCRIPT_FMT_TIMING_MULTI) { | |
276 | if (!ctl->siglog) | |
277 | ctl->siglog = log; | |
278 | if (!ctl->infolog) | |
279 | ctl->infolog = log; | |
280 | } | |
281 | ||
282 | return log; | |
283 | } | |
284 | ||
285 | static int log_close(struct script_control *ctl, | |
286 | struct script_log *log, | |
287 | const char *msg, | |
288 | int status) | |
289 | { | |
290 | int rc = 0; | |
291 | ||
292 | if (!log || !log->initialized) | |
293 | return 0; | |
294 | ||
295 | DBG(MISC, ul_debug("closing %s", log->filename)); | |
296 | ||
297 | switch (log->format) { | |
298 | case SCRIPT_FMT_RAW: | |
299 | { | |
300 | char buf[FORMAT_TIMESTAMP_MAX]; | |
301 | time_t tvec = script_time((time_t *)NULL); | |
302 | ||
303 | strtime_iso(&tvec, ISO_TIMESTAMP, buf, sizeof(buf)); | |
304 | if (msg) | |
305 | fprintf(log->fp, _("\nScript done on %s [<%s>]\n"), buf, msg); | |
306 | else | |
307 | fprintf(log->fp, _("\nScript done on %s [COMMAND_EXIT_CODE=\"%d\"]\n"), buf, status); | |
308 | break; | |
309 | } | |
310 | case SCRIPT_FMT_TIMING_MULTI: | |
311 | { | |
312 | struct timeval now = { 0 }, delta = { 0 }; | |
313 | ||
314 | gettime_monotonic(&now); | |
315 | timersub(&now, &log->starttime, &delta); | |
316 | ||
317 | log_info(ctl, "DURATION", "%"PRId64".%06"PRId64, | |
318 | (int64_t)delta.tv_sec, | |
319 | (int64_t)delta.tv_usec); | |
320 | log_info(ctl, "EXIT_CODE", "%d", status); | |
321 | break; | |
322 | } | |
323 | case SCRIPT_FMT_TIMING_SIMPLE: | |
324 | break; | |
325 | } | |
326 | ||
327 | if (close_stream(log->fp) != 0) { | |
328 | warn(_("write failed: %s"), log->filename); | |
329 | rc = -errno; | |
330 | } | |
331 | ||
332 | free(log->filename); | |
333 | memset(log, 0, sizeof(*log)); | |
334 | ||
335 | return rc; | |
336 | } | |
337 | ||
338 | static int log_flush(struct script_control *ctl __attribute__((__unused__)), struct script_log *log) | |
339 | { | |
340 | ||
341 | if (!log || !log->initialized) | |
342 | return 0; | |
343 | ||
344 | DBG(MISC, ul_debug("flushing %s", log->filename)); | |
345 | ||
346 | fflush(log->fp); | |
347 | return 0; | |
348 | } | |
349 | ||
350 | static void log_free(struct script_control *ctl, struct script_log *log) | |
351 | { | |
352 | size_t i; | |
353 | ||
354 | if (!log) | |
355 | return; | |
356 | ||
357 | /* the same log is possible to reference from more places, remove all | |
358 | * (TODO: maybe use include/list.h to make it more elegant) | |
359 | */ | |
360 | if (ctl->siglog == log) | |
361 | ctl->siglog = NULL; | |
362 | else if (ctl->infolog == log) | |
363 | ctl->infolog = NULL; | |
364 | ||
365 | for (i = 0; i < ctl->out.nlogs; i++) { | |
366 | if (ctl->out.logs[i] == log) | |
367 | ctl->out.logs[i] = NULL; | |
368 | } | |
369 | for (i = 0; i < ctl->in.nlogs; i++) { | |
370 | if (ctl->in.logs[i] == log) | |
371 | ctl->in.logs[i] = NULL; | |
372 | } | |
373 | free(log); | |
374 | } | |
375 | ||
376 | static int log_start(struct script_control *ctl, | |
377 | struct script_log *log) | |
378 | { | |
379 | if (log->initialized) | |
380 | return 0; | |
381 | ||
382 | DBG(MISC, ul_debug("opening %s", log->filename)); | |
383 | ||
384 | assert(log->fp == NULL); | |
385 | ||
386 | /* open the log */ | |
387 | log->fp = fopen(log->filename, | |
388 | ctl->append && log->format == SCRIPT_FMT_RAW ? | |
389 | "a" UL_CLOEXECSTR : | |
390 | "w" UL_CLOEXECSTR); | |
391 | if (!log->fp) { | |
392 | warn(_("cannot open %s"), log->filename); | |
393 | return -errno; | |
394 | } | |
395 | ||
396 | /* write header, etc. */ | |
397 | switch (log->format) { | |
398 | case SCRIPT_FMT_RAW: | |
399 | { | |
400 | int x = 0; | |
401 | char buf[FORMAT_TIMESTAMP_MAX]; | |
402 | time_t tvec = script_time((time_t *)NULL); | |
403 | ||
404 | strtime_iso(&tvec, ISO_TIMESTAMP, buf, sizeof(buf)); | |
405 | fprintf(log->fp, _("Script started on %s ["), buf); | |
406 | ||
407 | if (ctl->command) | |
408 | x += fprintf(log->fp, "COMMAND=\"%s\"", ctl->command_norm); | |
409 | ||
410 | if (ctl->isterm) { | |
411 | init_terminal_info(ctl); | |
412 | ||
413 | if (ctl->ttytype) | |
414 | x += fprintf(log->fp, "%*sTERM=\"%s\"", !!x, "", ctl->ttytype); | |
415 | if (ctl->ttyname) | |
416 | x += fprintf(log->fp, "%*sTTY=\"%s\"", !!x, "", ctl->ttyname); | |
417 | ||
418 | x += fprintf(log->fp, "%*sCOLUMNS=\"%d\" LINES=\"%d\"", !!x, "", | |
419 | ctl->ttycols, ctl->ttylines); | |
420 | } else | |
421 | fprintf(log->fp, _("%*s<not executed on terminal>"), !!x, ""); | |
422 | ||
423 | fputs("]\n", log->fp); | |
424 | break; | |
425 | } | |
426 | case SCRIPT_FMT_TIMING_SIMPLE: | |
427 | case SCRIPT_FMT_TIMING_MULTI: | |
428 | gettime_monotonic(&log->oldtime); | |
429 | gettime_monotonic(&log->starttime); | |
430 | break; | |
431 | } | |
432 | ||
433 | log->initialized = 1; | |
434 | return 0; | |
435 | } | |
436 | ||
437 | static int logging_start(struct script_control *ctl) | |
438 | { | |
439 | size_t i; | |
440 | ||
441 | /* start all output logs */ | |
442 | for (i = 0; i < ctl->out.nlogs; i++) { | |
443 | int rc = log_start(ctl, ctl->out.logs[i]); | |
444 | if (rc) | |
445 | return rc; | |
446 | } | |
447 | ||
448 | /* start all input logs */ | |
449 | for (i = 0; i < ctl->in.nlogs; i++) { | |
450 | int rc = log_start(ctl, ctl->in.logs[i]); | |
451 | if (rc) | |
452 | return rc; | |
453 | } | |
454 | return 0; | |
455 | } | |
456 | ||
457 | static ssize_t log_write(struct script_control *ctl, | |
458 | struct script_stream *stream, | |
459 | struct script_log *log, | |
460 | char *obuf, size_t bytes) | |
461 | { | |
462 | int rc; | |
463 | ssize_t ssz = 0; | |
464 | struct timeval now, delta; | |
465 | ||
466 | if (!log->fp) | |
467 | return 0; | |
468 | ||
469 | DBG(IO, ul_debug(" writing [file=%s]", log->filename)); | |
470 | ||
471 | switch (log->format) { | |
472 | case SCRIPT_FMT_RAW: | |
473 | DBG(IO, ul_debug(" log raw data")); | |
474 | rc = fwrite_all(obuf, 1, bytes, log->fp); | |
475 | if (rc) { | |
476 | warn(_("cannot write %s"), log->filename); | |
477 | return rc; | |
478 | } | |
479 | ssz = bytes; | |
480 | break; | |
481 | ||
482 | case SCRIPT_FMT_TIMING_SIMPLE: | |
483 | DBG(IO, ul_debug(" log timing info")); | |
484 | ||
485 | gettime_monotonic(&now); | |
486 | timersub(&now, &log->oldtime, &delta); | |
487 | ssz = fprintf(log->fp, "%"PRId64".%06"PRId64" %zd\n", | |
488 | (int64_t)delta.tv_sec, (int64_t)delta.tv_usec, bytes); | |
489 | if (ssz < 0) | |
490 | return -errno; | |
491 | ||
492 | log->oldtime = now; | |
493 | break; | |
494 | ||
495 | case SCRIPT_FMT_TIMING_MULTI: | |
496 | DBG(IO, ul_debug(" log multi-stream timing info")); | |
497 | ||
498 | gettime_monotonic(&now); | |
499 | timersub(&now, &log->oldtime, &delta); | |
500 | ssz = fprintf(log->fp, "%c %"PRId64".%06"PRId64" %zd\n", | |
501 | stream->ident, | |
502 | (int64_t)delta.tv_sec, (int64_t)delta.tv_usec, bytes); | |
503 | if (ssz < 0) | |
504 | return -errno; | |
505 | ||
506 | log->oldtime = now; | |
507 | break; | |
508 | default: | |
509 | break; | |
510 | } | |
511 | ||
512 | if (ctl->flush) | |
513 | fflush(log->fp); | |
514 | return ssz; | |
515 | } | |
516 | ||
517 | static ssize_t log_stream_activity( | |
518 | struct script_control *ctl, | |
519 | struct script_stream *stream, | |
520 | char *buf, size_t bytes) | |
521 | { | |
522 | size_t i; | |
523 | ssize_t outsz = 0; | |
524 | ||
525 | for (i = 0; i < stream->nlogs; i++) { | |
526 | ssize_t ssz = log_write(ctl, stream, stream->logs[i], buf, bytes); | |
527 | ||
528 | if (ssz < 0) | |
529 | return ssz; | |
530 | outsz += ssz; | |
531 | } | |
532 | ||
533 | return outsz; | |
534 | } | |
535 | ||
536 | static ssize_t __attribute__ ((__format__ (__printf__, 3, 4))) | |
537 | log_signal(struct script_control *ctl, int signum, const char *msgfmt, ...) | |
538 | { | |
539 | struct script_log *log; | |
540 | struct timeval now, delta; | |
541 | char msg[BUFSIZ] = {0}; | |
542 | va_list ap; | |
543 | ssize_t sz; | |
544 | ||
545 | assert(ctl); | |
546 | ||
547 | log = ctl->siglog; | |
548 | if (!log) | |
549 | return 0; | |
550 | ||
551 | assert(log->format == SCRIPT_FMT_TIMING_MULTI); | |
552 | DBG(IO, ul_debug(" writing signal to multi-stream timing")); | |
553 | ||
554 | gettime_monotonic(&now); | |
555 | timersub(&now, &log->oldtime, &delta); | |
556 | ||
557 | if (msgfmt) { | |
558 | int rc; | |
559 | va_start(ap, msgfmt); | |
560 | rc = vsnprintf(msg, sizeof(msg), msgfmt, ap); | |
561 | va_end(ap); | |
562 | if (rc < 0) | |
563 | *msg = '\0';; | |
564 | } | |
565 | ||
566 | if (*msg) | |
567 | sz = fprintf(log->fp, "S %"PRId64".%06"PRId64" SIG%s %s\n", | |
568 | (int64_t)delta.tv_sec, (int64_t)delta.tv_usec, | |
569 | signum_to_signame(signum), msg); | |
570 | else | |
571 | sz = fprintf(log->fp, "S %"PRId64".%06"PRId64" SIG%s\n", | |
572 | (int64_t)delta.tv_sec, (int64_t)delta.tv_usec, | |
573 | signum_to_signame(signum)); | |
574 | ||
575 | log->oldtime = now; | |
576 | return sz; | |
577 | } | |
578 | ||
579 | static ssize_t log_info(struct script_control *ctl, const char *name, const char *msgfmt, ...) | |
580 | { | |
581 | struct script_log *log; | |
582 | char msg[BUFSIZ] = {0}; | |
583 | va_list ap; | |
584 | ssize_t sz; | |
585 | ||
586 | assert(ctl); | |
587 | ||
588 | log = ctl->infolog; | |
589 | if (!log) | |
590 | return 0; | |
591 | ||
592 | assert(log->format == SCRIPT_FMT_TIMING_MULTI); | |
593 | DBG(IO, ul_debug(" writing info to multi-stream log")); | |
594 | ||
595 | if (msgfmt) { | |
596 | int rc; | |
597 | va_start(ap, msgfmt); | |
598 | rc = vsnprintf(msg, sizeof(msg), msgfmt, ap); | |
599 | va_end(ap); | |
600 | if (rc < 0) | |
601 | *msg = '\0';; | |
602 | } | |
603 | ||
604 | if (*msg) | |
605 | sz = fprintf(log->fp, "H %f %s %s\n", 0.0, name, msg); | |
606 | else | |
607 | sz = fprintf(log->fp, "H %f %s\n", 0.0, name); | |
608 | ||
609 | return sz; | |
610 | } | |
611 | ||
612 | ||
613 | static void logging_done(struct script_control *ctl, const char *msg) | |
614 | { | |
615 | int status; | |
616 | size_t i; | |
617 | ||
618 | DBG(MISC, ul_debug("stop logging")); | |
619 | ||
620 | if (WIFSIGNALED(ctl->childstatus)) | |
621 | status = WTERMSIG(ctl->childstatus) + 0x80; | |
622 | else | |
623 | status = WEXITSTATUS(ctl->childstatus); | |
624 | ||
625 | DBG(MISC, ul_debug(" status=%d", status)); | |
626 | ||
627 | /* close all output logs */ | |
628 | for (i = 0; i < ctl->out.nlogs; i++) { | |
629 | struct script_log *log = ctl->out.logs[i]; | |
630 | log_close(ctl, log, msg, status); | |
631 | log_free(ctl, log); | |
632 | } | |
633 | free(ctl->out.logs); | |
634 | ctl->out.logs = NULL; | |
635 | ctl->out.nlogs = 0; | |
636 | ||
637 | /* close all input logs */ | |
638 | for (i = 0; i < ctl->in.nlogs; i++) { | |
639 | struct script_log *log = ctl->in.logs[i]; | |
640 | log_close(ctl, log, msg, status); | |
641 | log_free(ctl, log); | |
642 | } | |
643 | free(ctl->in.logs); | |
644 | ctl->in.logs = NULL; | |
645 | ctl->in.nlogs = 0; | |
646 | } | |
647 | ||
648 | static void callback_child_die( | |
649 | void *data, | |
650 | pid_t child __attribute__((__unused__)), | |
651 | int status) | |
652 | { | |
653 | struct script_control *ctl = (struct script_control *) data; | |
654 | ||
655 | ctl->child = (pid_t) -1; | |
656 | ctl->childstatus = status; | |
657 | } | |
658 | ||
659 | static void callback_child_sigstop( | |
660 | void *data __attribute__((__unused__)), | |
661 | pid_t child) | |
662 | { | |
663 | DBG(SIGNAL, ul_debug(" child stop by SIGSTOP -- stop parent too")); | |
664 | kill(getpid(), SIGSTOP); | |
665 | DBG(SIGNAL, ul_debug(" resume")); | |
666 | kill(child, SIGCONT); | |
667 | } | |
668 | ||
669 | static int callback_log_stream_activity(void *data, int fd, char *buf, size_t bufsz) | |
670 | { | |
671 | struct script_control *ctl = (struct script_control *) data; | |
672 | ssize_t ssz = 0; | |
673 | ||
674 | DBG(IO, ul_debug("stream activity callback")); | |
675 | ||
676 | /* from stdin (user) to command */ | |
677 | if (fd == STDIN_FILENO) | |
678 | ssz = log_stream_activity(ctl, &ctl->in, buf, (size_t) bufsz); | |
679 | ||
680 | /* from command (master) to stdout and log */ | |
681 | else if (fd == ul_pty_get_childfd(ctl->pty)) | |
682 | ssz = log_stream_activity(ctl, &ctl->out, buf, (size_t) bufsz); | |
683 | ||
684 | if (ssz < 0) | |
685 | return (int) ssz; | |
686 | ||
687 | DBG(IO, ul_debug(" append %zd bytes [summary=%" PRIu64 ", max=%" PRIu64 "]", ssz, | |
688 | ctl->outsz, ctl->maxsz)); | |
689 | ||
690 | ctl->outsz += ssz; | |
691 | ||
692 | /* check output limit */ | |
693 | if (ctl->maxsz != 0 && ctl->outsz >= ctl->maxsz) { | |
694 | if (!ctl->quiet) | |
695 | printf(_("Script terminated, max output files size %"PRIu64" exceeded.\n"), ctl->maxsz); | |
696 | DBG(IO, ul_debug("output size %"PRIu64", exceeded limit %"PRIu64, ctl->outsz, ctl->maxsz)); | |
697 | logging_done(ctl, _("max output size exceeded")); | |
698 | return 1; | |
699 | } | |
700 | return 0; | |
701 | } | |
702 | ||
703 | static int callback_log_signal(void *data, struct signalfd_siginfo *info, void *sigdata) | |
704 | { | |
705 | struct script_control *ctl = (struct script_control *) data; | |
706 | ssize_t ssz = 0; | |
707 | ||
708 | switch (info->ssi_signo) { | |
709 | case SIGWINCH: | |
710 | { | |
711 | struct winsize *win = (struct winsize *) sigdata; | |
712 | ssz = log_signal(ctl, info->ssi_signo, "ROWS=%d COLS=%d", | |
713 | win->ws_row, win->ws_col); | |
714 | break; | |
715 | } | |
716 | case SIGTERM: | |
717 | FALLTHROUGH; | |
718 | case SIGINT: | |
719 | FALLTHROUGH; | |
720 | case SIGQUIT: | |
721 | ssz = log_signal(ctl, info->ssi_signo, NULL); | |
722 | break; | |
723 | default: | |
724 | /* no log */ | |
725 | break; | |
726 | } | |
727 | ||
728 | return ssz < 0 ? ssz : 0; | |
729 | } | |
730 | ||
731 | static int callback_flush_logs(void *data) | |
732 | { | |
733 | struct script_control *ctl = (struct script_control *) data; | |
734 | size_t i; | |
735 | ||
736 | for (i = 0; i < ctl->out.nlogs; i++) { | |
737 | int rc = log_flush(ctl, ctl->out.logs[i]); | |
738 | if (rc) | |
739 | return rc; | |
740 | } | |
741 | ||
742 | for (i = 0; i < ctl->in.nlogs; i++) { | |
743 | int rc = log_flush(ctl, ctl->in.logs[i]); | |
744 | if (rc) | |
745 | return rc; | |
746 | } | |
747 | return 0; | |
748 | } | |
749 | ||
750 | static void die_if_link(struct script_control *ctl, const char *filename) | |
751 | { | |
752 | struct stat s; | |
753 | ||
754 | if (ctl->force) | |
755 | return; | |
756 | if (lstat(filename, &s) == 0 && (S_ISLNK(s.st_mode) || s.st_nlink > 1)) | |
757 | errx(EXIT_FAILURE, | |
758 | _("output file `%s' is a link\n" | |
759 | "Use --force if you really want to use it.\n" | |
760 | "Program not started."), filename); | |
761 | } | |
762 | ||
763 | int main(int argc, char **argv) | |
764 | { | |
765 | struct script_control ctl = { | |
766 | .out = { .ident = 'O' }, | |
767 | .in = { .ident = 'I' }, | |
768 | }; | |
769 | struct ul_pty_callbacks *cb; | |
770 | int ch, format = 0, caught_signal = 0, rc = 0, echo = 1; | |
771 | const char *outfile = NULL, *infile = NULL; | |
772 | const char *timingfile = NULL, *shell = NULL; | |
773 | ||
774 | enum { FORCE_OPTION = CHAR_MAX + 1 }; | |
775 | ||
776 | static const struct option longopts[] = { | |
777 | {"append", no_argument, NULL, 'a'}, | |
778 | {"command", required_argument, NULL, 'c'}, | |
779 | {"echo", required_argument, NULL, 'E'}, | |
780 | {"return", no_argument, NULL, 'e'}, | |
781 | {"flush", no_argument, NULL, 'f'}, | |
782 | {"force", no_argument, NULL, FORCE_OPTION,}, | |
783 | {"log-in", required_argument, NULL, 'I'}, | |
784 | {"log-out", required_argument, NULL, 'O'}, | |
785 | {"log-io", required_argument, NULL, 'B'}, | |
786 | {"log-timing", required_argument, NULL, 'T'}, | |
787 | {"logging-format", required_argument, NULL, 'm'}, | |
788 | {"output-limit", required_argument, NULL, 'o'}, | |
789 | {"quiet", no_argument, NULL, 'q'}, | |
790 | {"timing", optional_argument, NULL, 't'}, | |
791 | {"version", no_argument, NULL, 'V'}, | |
792 | {"help", no_argument, NULL, 'h'}, | |
793 | {NULL, 0, NULL, 0} | |
794 | }; | |
795 | static const ul_excl_t excl[] = { /* rows and cols in ASCII order */ | |
796 | { 'T', 't' }, | |
797 | { 0 } | |
798 | }; | |
799 | int excl_st[ARRAY_SIZE(excl)] = UL_EXCL_STATUS_INIT; | |
800 | setlocale(LC_ALL, ""); | |
801 | /* | |
802 | * script -t prints time delays as floating point numbers. The example | |
803 | * program (scriptreplay) that we provide to handle this timing output | |
804 | * is a perl script, and does not handle numbers in locale format (not | |
805 | * even when "use locale;" is added). So, since these numbers are not | |
806 | * for human consumption, it seems easiest to set LC_NUMERIC here. | |
807 | */ | |
808 | setlocale(LC_NUMERIC, "C"); | |
809 | bindtextdomain(PACKAGE, LOCALEDIR); | |
810 | textdomain(PACKAGE); | |
811 | close_stdout_atexit(); | |
812 | ||
813 | script_init_debug(); | |
814 | ON_DBG(PTY, ul_pty_init_debug(0xFFFF)); | |
815 | ||
816 | ctl.isterm = isatty(STDIN_FILENO); | |
817 | ||
818 | while ((ch = getopt_long(argc, argv, "+aB:c:eE:fI:O:o:qm:T:t::Vh", longopts, NULL)) != -1) { | |
819 | ||
820 | err_exclusive_options(ch, longopts, excl, excl_st); | |
821 | ||
822 | switch (ch) { | |
823 | case 'a': | |
824 | ctl.append = 1; | |
825 | break; | |
826 | case 'c': | |
827 | ctl.command = optarg; | |
828 | ctl.command_norm = xstrdup(ctl.command); | |
829 | ul_strrep(ctl.command_norm, '\n', ' '); | |
830 | break; | |
831 | case 'E': | |
832 | if (strcmp(optarg, "auto") == 0) | |
833 | ; /* keep default */ | |
834 | else if (strcmp(optarg, "never") == 0) | |
835 | echo = 0; | |
836 | else if (strcmp(optarg, "always") == 0) | |
837 | echo = 1; | |
838 | else | |
839 | errx(EXIT_FAILURE, _("unsupported echo mode: '%s'"), optarg); | |
840 | break; | |
841 | case 'e': | |
842 | ctl.rc_wanted = 1; | |
843 | break; | |
844 | case 'f': | |
845 | ctl.flush = 1; | |
846 | break; | |
847 | case FORCE_OPTION: | |
848 | ctl.force = 1; | |
849 | break; | |
850 | case 'B': | |
851 | log_associate(&ctl, &ctl.in, optarg, SCRIPT_FMT_RAW); | |
852 | log_associate(&ctl, &ctl.out, optarg, SCRIPT_FMT_RAW); | |
853 | infile = outfile = optarg; | |
854 | break; | |
855 | case 'I': | |
856 | log_associate(&ctl, &ctl.in, optarg, SCRIPT_FMT_RAW); | |
857 | infile = optarg; | |
858 | break; | |
859 | case 'O': | |
860 | log_associate(&ctl, &ctl.out, optarg, SCRIPT_FMT_RAW); | |
861 | outfile = optarg; | |
862 | break; | |
863 | case 'o': | |
864 | ctl.maxsz = strtosize_or_err(optarg, _("failed to parse output limit size")); | |
865 | break; | |
866 | case 'q': | |
867 | ctl.quiet = 1; | |
868 | break; | |
869 | case 'm': | |
870 | if (c_strcasecmp(optarg, "classic") == 0) | |
871 | format = SCRIPT_FMT_TIMING_SIMPLE; | |
872 | else if (c_strcasecmp(optarg, "advanced") == 0) | |
873 | format = SCRIPT_FMT_TIMING_MULTI; | |
874 | else | |
875 | errx(EXIT_FAILURE, _("unsupported logging format: '%s'"), optarg); | |
876 | break; | |
877 | case 't': | |
878 | if (optarg && *optarg == '=') | |
879 | optarg++; | |
880 | timingfile = optarg ? optarg : "/dev/stderr"; | |
881 | break; | |
882 | case 'T' : | |
883 | timingfile = optarg; | |
884 | break; | |
885 | case 'V': | |
886 | print_version(EXIT_SUCCESS); | |
887 | case 'h': | |
888 | usage(); | |
889 | default: | |
890 | errtryhelp(EXIT_FAILURE); | |
891 | } | |
892 | } | |
893 | ||
894 | argc -= optind; | |
895 | argv += optind; | |
896 | ||
897 | /* | |
898 | * Note that "--" separates non-option arguments. The script can be | |
899 | * used with an <outfile> name as well as with a <command>. The | |
900 | * <outfile> is always before "--" and <command> is always after "--". | |
901 | * Possible combinations are: | |
902 | * | |
903 | * script [options] <outfile> | |
904 | * script [options] -- <command ...> | |
905 | * script [options] <outfile> -- <command ...> | |
906 | */ | |
907 | ||
908 | /* default if no --log-* specified */ | |
909 | if (!outfile && !infile) { | |
910 | /* if argv[0] is not after --, use argv[0] as outfile */ | |
911 | if (argc > 0 && strcmp(argv[-1], "--") != 0) { | |
912 | outfile = argv[0]; | |
913 | argc--; | |
914 | argv++; | |
915 | } else { | |
916 | die_if_link(&ctl, DEFAULT_TYPESCRIPT_FILENAME); | |
917 | outfile = DEFAULT_TYPESCRIPT_FILENAME; | |
918 | } | |
919 | ||
920 | /* associate stdout with typescript file */ | |
921 | log_associate(&ctl, &ctl.out, outfile, SCRIPT_FMT_RAW); | |
922 | } | |
923 | ||
924 | /* skip -- to non-option arguments */ | |
925 | if (argc > 0 && strcmp(argv[0], "--") == 0) { | |
926 | argc--; | |
927 | argv++; | |
928 | } | |
929 | ||
930 | /* concat non-option arguments as command */ | |
931 | if (argc > 0 && strcmp(argv[-1], "--") == 0) { | |
932 | if (ctl.command != NULL) { | |
933 | warnx(_("option --command and a command after '--' cannot be combined")); | |
934 | errtryhelp(EXIT_FAILURE); | |
935 | } | |
936 | ||
937 | ctl.command = ul_strv_join(argv, " "); | |
938 | if (!ctl.command) | |
939 | errx(EXIT_FAILURE, _("failed to concatenate arguments")); | |
940 | ||
941 | ctl.command_norm = xstrdup(ctl.command); | |
942 | ul_strrep(ctl.command_norm, '\n', ' '); | |
943 | argc = 0; | |
944 | } | |
945 | ||
946 | if (argc > 0) { | |
947 | warnx(_("unexpected number of arguments")); | |
948 | errtryhelp(EXIT_FAILURE); | |
949 | } | |
950 | ||
951 | if (timingfile) { | |
952 | /* the old SCRIPT_FMT_TIMING_SIMPLE should be used when | |
953 | * recoding output only (just for backward compatibility), | |
954 | * otherwise switch to new format. */ | |
955 | if (!format) | |
956 | format = infile || (outfile && infile) ? | |
957 | SCRIPT_FMT_TIMING_MULTI : | |
958 | SCRIPT_FMT_TIMING_SIMPLE; | |
959 | ||
960 | else if (format == SCRIPT_FMT_TIMING_SIMPLE && outfile && infile) | |
961 | errx(EXIT_FAILURE, _("log multiple streams is mutually " | |
962 | "exclusive with 'classic' format")); | |
963 | if (outfile) | |
964 | log_associate(&ctl, &ctl.out, timingfile, format); | |
965 | if (infile) | |
966 | log_associate(&ctl, &ctl.in, timingfile, format); | |
967 | } | |
968 | ||
969 | shell = getenv("SHELL"); | |
970 | if (!shell) | |
971 | shell = _PATH_BSHELL; | |
972 | ||
973 | ctl.pty = ul_new_pty(ctl.isterm); | |
974 | if (!ctl.pty) | |
975 | err(EXIT_FAILURE, "failed to allocate PTY handler"); | |
976 | ||
977 | ul_pty_slave_echo(ctl.pty, echo); | |
978 | ||
979 | ul_pty_set_callback_data(ctl.pty, (void *) &ctl); | |
980 | cb = ul_pty_get_callbacks(ctl.pty); | |
981 | cb->child_die = callback_child_die; | |
982 | cb->child_sigstop = callback_child_sigstop; | |
983 | cb->log_stream_activity = callback_log_stream_activity; | |
984 | cb->log_signal = callback_log_signal; | |
985 | cb->flush_logs = callback_flush_logs; | |
986 | ||
987 | if (!ctl.quiet) { | |
988 | printf(_("Script started")); | |
989 | if (outfile) | |
990 | printf(_(", output log file is '%s'"), outfile); | |
991 | if (infile) | |
992 | printf(_(", input log file is '%s'"), infile); | |
993 | if (timingfile) | |
994 | printf(_(", timing file is '%s'"), timingfile); | |
995 | printf(_(".\n")); | |
996 | } | |
997 | ||
998 | ||
999 | if (ul_pty_setup(ctl.pty)) | |
1000 | err(EXIT_FAILURE, _("failed to create pseudo-terminal")); | |
1001 | ||
1002 | #ifdef HAVE_LIBUTEMPTER | |
1003 | utempter_add_record(ul_pty_get_childfd(ctl.pty), NULL); | |
1004 | #endif | |
1005 | ||
1006 | if (ul_pty_signals_setup(ctl.pty)) | |
1007 | err(EXIT_FAILURE, _("failed to initialize signals handler")); | |
1008 | fflush(stdout); | |
1009 | ||
1010 | /* | |
1011 | * We have terminal, do not use err() from now, use "goto done" | |
1012 | */ | |
1013 | ||
1014 | switch ((int) (ctl.child = fork())) { | |
1015 | case -1: /* error */ | |
1016 | warn(_("cannot create child process")); | |
1017 | rc = -errno; | |
1018 | goto done; | |
1019 | ||
1020 | case 0: /* child */ | |
1021 | { | |
1022 | const char *shname; | |
1023 | ||
1024 | ul_pty_init_slave(ctl.pty); | |
1025 | ||
1026 | signal(SIGTERM, SIG_DFL); /* because /etc/csh.login */ | |
1027 | ||
1028 | shname = strrchr(shell, '/'); | |
1029 | shname = shname ? shname + 1 : shell; | |
1030 | ||
1031 | if (access(shell, X_OK) == 0) { | |
1032 | if (ctl.command) | |
1033 | execl(shell, shname, "-c", ctl.command, (char *)NULL); | |
1034 | else | |
1035 | execl(shell, shname, "-i", (char *)NULL); | |
1036 | } else { | |
1037 | if (ctl.command) | |
1038 | execlp(shname, shname, "-c", ctl.command, (char *)NULL); | |
1039 | else | |
1040 | execlp(shname, shname, "-i", (char *)NULL); | |
1041 | } | |
1042 | ||
1043 | err(EXIT_FAILURE, "failed to execute %s", shell); | |
1044 | break; | |
1045 | } | |
1046 | default: | |
1047 | break; | |
1048 | } | |
1049 | ||
1050 | /* parent */ | |
1051 | ul_pty_set_child(ctl.pty, ctl.child); | |
1052 | ||
1053 | rc = logging_start(&ctl); | |
1054 | if (rc) | |
1055 | goto done; | |
1056 | ||
1057 | /* add extra info to advanced timing file */ | |
1058 | if (timingfile && format == SCRIPT_FMT_TIMING_MULTI) { | |
1059 | char buf[FORMAT_TIMESTAMP_MAX]; | |
1060 | time_t tvec = script_time((time_t *)NULL); | |
1061 | ||
1062 | strtime_iso(&tvec, ISO_TIMESTAMP, buf, sizeof(buf)); | |
1063 | log_info(&ctl, "START_TIME", "%s", buf); | |
1064 | ||
1065 | if (ctl.isterm) { | |
1066 | init_terminal_info(&ctl); | |
1067 | log_info(&ctl, "TERM", "%s", ctl.ttytype); | |
1068 | log_info(&ctl, "TTY", "%s", ctl.ttyname); | |
1069 | log_info(&ctl, "COLUMNS", "%d", ctl.ttycols); | |
1070 | log_info(&ctl, "LINES", "%d", ctl.ttylines); | |
1071 | } | |
1072 | log_info(&ctl, "SHELL", "%s", shell); | |
1073 | if (ctl.command) | |
1074 | log_info(&ctl, "COMMAND", "%s", ctl.command_norm); | |
1075 | log_info(&ctl, "TIMING_LOG", "%s", timingfile); | |
1076 | if (outfile) | |
1077 | log_info(&ctl, "OUTPUT_LOG", "%s", outfile); | |
1078 | if (infile) | |
1079 | log_info(&ctl, "INPUT_LOG", "%s", infile); | |
1080 | } | |
1081 | ||
1082 | /* this is the main loop */ | |
1083 | rc = ul_pty_proxy_master(ctl.pty); | |
1084 | ||
1085 | /* all done; cleanup and kill */ | |
1086 | caught_signal = ul_pty_get_delivered_signal(ctl.pty); | |
1087 | ||
1088 | if (!caught_signal && ctl.child != (pid_t)-1) | |
1089 | ul_pty_wait_for_child(ctl.pty); /* final wait */ | |
1090 | ||
1091 | if (caught_signal && ctl.child != (pid_t)-1) { | |
1092 | fprintf(stderr, "\nSession terminated, killing shell..."); | |
1093 | kill(ctl.child, SIGTERM); | |
1094 | sleep(2); | |
1095 | kill(ctl.child, SIGKILL); | |
1096 | fprintf(stderr, " ...killed.\n"); | |
1097 | } | |
1098 | ||
1099 | done: | |
1100 | ul_pty_cleanup(ctl.pty); | |
1101 | logging_done(&ctl, NULL); | |
1102 | ||
1103 | if (!ctl.quiet) | |
1104 | printf(_("Script done.\n")); | |
1105 | ||
1106 | #ifdef HAVE_LIBUTEMPTER | |
1107 | if (ul_pty_get_childfd(ctl.pty) >= 0) | |
1108 | utempter_remove_record(ul_pty_get_childfd(ctl.pty)); | |
1109 | #endif | |
1110 | ul_free_pty(ctl.pty); | |
1111 | ||
1112 | /* default exit code */ | |
1113 | rc = rc ? EXIT_FAILURE : EXIT_SUCCESS; | |
1114 | ||
1115 | /* exit code based on child status */ | |
1116 | if (ctl.rc_wanted && rc == EXIT_SUCCESS) { | |
1117 | if (WIFSIGNALED(ctl.childstatus)) | |
1118 | rc = WTERMSIG(ctl.childstatus) + 0x80; | |
1119 | else | |
1120 | rc = WEXITSTATUS(ctl.childstatus); | |
1121 | } | |
1122 | ||
1123 | DBG(MISC, ul_debug("done [rc=%d]", rc)); | |
1124 | return rc; | |
1125 | } |