cript: always use decimal point numbers in logs

[thirdparty/util-linux.git] / term-utils / script.c

/*
 * Copyright (c) 1980 Regents of the University of California.
 * All rights reserved.
 *
 * Redistribution and use in source and binary forms, with or without
 * modification, are permitted provided that the following conditions
 * are met:
 * 1. Redistributions of source code must retain the above copyright
 *    notice, this list of conditions and the following disclaimer.
 * 2. Redistributions in binary form must reproduce the above copyright
 *    notice, this list of conditions and the following disclaimer in the
 *    documentation and/or other materials provided with the distribution.
 * 3. All advertising materials mentioning features or use of this software
 *    must display the following acknowledgement:
 *      This product includes software developed by the University of
 *      California, Berkeley and its contributors.
 * 4. Neither the name of the University nor the names of its contributors
 *    may be used to endorse or promote products derived from this software
 *    without specific prior written permission.
 *
 * THIS SOFTWARE IS PROVIDED BY THE REGENTS AND CONTRIBUTORS ``AS IS'' AND
 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
 * ARE DISCLAIMED.  IN NO EVENT SHALL THE REGENTS OR CONTRIBUTORS BE LIABLE
 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
 * SUCH DAMAGE.
 */

/*
 * 1999-02-22 Arkadiusz Miśkiewicz <misiek@pld.ORG.PL>
 * - added Native Language Support
 *
 * 2000-07-30 Per Andreas Buer <per@linpro.no> - added "q"-option
 *
 * 2014-05-30 Csaba Kos <csaba.kos@gmail.com>
 * - fixed a rare deadlock after child termination
 */

#include <stdio.h>
#include <stdlib.h>
#include <paths.h>
#include <time.h>
#include <sys/stat.h>
#include <termios.h>
#include <sys/ioctl.h>
#include <sys/time.h>
#include <signal.h>
#include <errno.h>
#include <string.h>
#include <getopt.h>
#include <unistd.h>
#include <fcntl.h>
#include <limits.h>
#include <locale.h>
#include <stddef.h>
#include <sys/wait.h>
#include <poll.h>
#include <sys/signalfd.h>
#include <assert.h>
#include <inttypes.h>

#include "closestream.h"
#include "nls.h"
#include "c.h"
#include "ttyutils.h"
#include "all-io.h"
#include "monotonic.h"
#include "timeutils.h"
#include "strutils.h"
#include "xalloc.h"
#include "optutils.h"
#include "signames.h"

#include "debug.h"

static UL_DEBUG_DEFINE_MASK(script);
UL_DEBUG_DEFINE_MASKNAMES(script) = UL_DEBUG_EMPTY_MASKNAMES;

#define SCRIPT_DEBUG_INIT       (1 << 1)
#define SCRIPT_DEBUG_POLL       (1 << 2)
#define SCRIPT_DEBUG_SIGNAL     (1 << 3)
#define SCRIPT_DEBUG_IO         (1 << 4)
#define SCRIPT_DEBUG_MISC       (1 << 5)
#define SCRIPT_DEBUG_ALL        0xFFFF

#define DBG(m, x)       __UL_DBG(script, SCRIPT_DEBUG_, m, x)
#define ON_DBG(m, x)    __UL_DBG_CALL(script, SCRIPT_DEBUG_, m, x)

#if defined(HAVE_LIBUTIL) && defined(HAVE_PTY_H)
# include <pty.h>
#endif

#ifdef HAVE_LIBUTEMPTER
# include <utempter.h>
#endif

#define DEFAULT_TYPESCRIPT_FILENAME "typescript"

/*
 * Script is driven by stream (stdout/stdin) activity. It's possible to
 * associate arbitrary number of log files with the stream. We have two basic
 * types of log files: "timing file" (simple or multistream) and "data file"
 * (raw).
 *
 * The same log file maybe be shared between both streams. For exmaple
 * multi-stream timing file is possible to use for stdin as well as for stdout.
 */
enum {
        SCRIPT_FMT_RAW = 1,             /* raw slave/master data */
        SCRIPT_FMT_TIMING_SIMPLE,       /* (classic) in format "<delta> <offset>" */
        SCRIPT_FMT_TIMING_MULTI,        /* (advanced) multiple streams in format "<type> <delta> <offset|etc> */
};

struct script_log {
        FILE    *fp;                    /* file pointer (handler) */
        int     format;                 /* SCRIPT_FMT_* */
        char    *filename;              /* on command line specified name */
        struct timeval oldtime;         /* previous entry log time (SCRIPT_FMT_TIMING_* only) */
        struct timeval starttime;

        unsigned int    initialized : 1;
};

struct script_stream {
        struct script_log **logs;       /* logs where to write data from stream */
        size_t nlogs;                   /* number of logs */
        char ident;                     /* stream identifier */
};

struct script_control {
        char *shell;            /* shell to be executed */
        char *command;          /* command to be executed */
        uint64_t outsz;         /* current output files size */
        uint64_t maxsz;         /* maximum output files size */

        int master;             /* pseudoterminal master file descriptor */
        int slave;              /* pseudoterminal slave file descriptor */

        struct script_stream    out;    /* output */
        struct script_stream    in;     /* input */

        struct script_log       *siglog;        /* log for signal entries */
        struct script_log       *infolog;       /* log for info entries */

        const char *ttyname;
        const char *ttytype;
        int ttycols;
        int ttylines;

        int poll_timeout;       /* poll() timeout, used in end of execution */
        pid_t child;            /* child pid */
        int childstatus;        /* child process exit value */
        struct termios attrs;   /* slave terminal runtime attributes */
        struct winsize win;     /* terminal window size */
#if !HAVE_LIBUTIL || !HAVE_PTY_H
        char *line;             /* terminal line */
#endif
        unsigned int
         append:1,              /* append output */
         rc_wanted:1,           /* return child exit value */
         flush:1,               /* flush after each write */
         quiet:1,               /* suppress most output */
         force:1,               /* write output to links */
         isterm:1,              /* is child process running as terminal */
         die:1;                 /* terminate program */

        sigset_t sigset;        /* catch SIGCHLD and SIGWINCH with signalfd() */
        sigset_t sigorg;        /* original signal mask */
        int sigfd;              /* file descriptor for signalfd() */
};

static void restore_tty(struct script_control *ctl, int mode);
static void __attribute__((__noreturn__)) fail(struct script_control *ctl);
static uint64_t log_info(struct script_control *ctl, const char *name, const char *msgfmt, ...);

static void script_init_debug(void)
{
        __UL_INIT_DEBUG_FROM_ENV(script, SCRIPT_DEBUG_, 0, SCRIPT_DEBUG);
}

static void init_terminal_info(struct script_control *ctl)
{
        if (ctl->ttyname || !ctl->isterm)
                return;         /* already initialized */

        get_terminal_dimension(&ctl->ttycols, &ctl->ttylines);
        get_terminal_name(&ctl->ttyname, NULL, NULL);
        get_terminal_type(&ctl->ttytype);
}

/*
 * For tests we want to be able to control time output
 */
#ifdef TEST_SCRIPT
static inline time_t script_time(time_t *t)
{
        const char *str = getenv("SCRIPT_TEST_SECOND_SINCE_EPOCH");
        int64_t sec;

        if (!str || sscanf(str, "%"SCNi64, &sec) != 1)
                return time(t);
        if (t)
                *t = (time_t)sec;
        return (time_t)sec;
}
#else   /* !TEST_SCRIPT */
# define script_time(x) time(x)
#endif

static void __attribute__((__noreturn__)) usage(void)
{
        FILE *out = stdout;
        fputs(USAGE_HEADER, out);
        fprintf(out, _(" %s [options] [file]\n"), program_invocation_short_name);

        fputs(USAGE_SEPARATOR, out);
        fputs(_("Make a typescript of a terminal session.\n"), out);

        fputs(USAGE_OPTIONS, out);
        fputs(_(" -I, --log-in <file>           log stdin to file\n"), out);
        fputs(_(" -O, --log-out <file>          log stdout to file (default)\n"), out);
        fputs(_(" -B, --log-io <file>           log stdin and stdout to file\n"), out);
        fputs(USAGE_SEPARATOR, out);

        fputs(_(" -T, --log-timing <file>       log timing information to file\n"), out);
        fputs(_(" -t[<file>], --timing[=<file>] deprecated alias to -T (default file is stderr)\n"), out);
        fputs(_(" -m, --logging-format <name>   force to 'classic' or 'advanced' format\n"), out);
        fputs(USAGE_SEPARATOR, out);

        fputs(_(" -a, --append                  append to the log file\n"), out);
        fputs(_(" -c, --command <command>       run command rather than interactive shell\n"), out);
        fputs(_(" -e, --return                  return exit code of the child process\n"), out);
        fputs(_(" -f, --flush                   run flush after each write\n"), out);
        fputs(_("     --force                   use output file even when it is a link\n"), out);
        fputs(_(" -o, --output-limit <size>     terminate if output files exceed size\n"), out);
        fputs(_(" -q, --quiet                   be quiet\n"), out);

        fputs(USAGE_SEPARATOR, out);
        printf(USAGE_HELP_OPTIONS(31));
        printf(USAGE_MAN_TAIL("script(1)"));

        exit(EXIT_SUCCESS);
}

static struct script_log *get_log_by_name(struct script_stream *stream,
                                          const char *name)
{
        size_t i;

        for (i = 0; i < stream->nlogs; i++) {
                struct script_log *log = stream->logs[i];
                if (strcmp(log->filename, name) == 0)
                        return log;
        }
        return NULL;
}

static struct script_log *log_associate(struct script_control *ctl,
                                        struct script_stream *stream,
                                        const char *filename, int format)
{
        struct script_log *log;

        DBG(MISC, ul_debug("associate %s with stream", filename));

        assert(ctl);
        assert(filename);
        assert(stream);

        log = get_log_by_name(stream, filename);
        if (log)
                return log;     /* already defined */

        log = get_log_by_name(stream == &ctl->out ? &ctl->in : &ctl->out, filename);
        if (!log) {
                /* create a new log */
                log = xcalloc(1, sizeof(*log));
                log->filename = xstrdup(filename);
                log->format = format;
        }

        /* add log to the stream */
        stream->logs = xrealloc(stream->logs,
                        (stream->nlogs + 1) * sizeof(log));
        stream->logs[stream->nlogs] = log;
        stream->nlogs++;

        /* remember where to write info about signals */
        if (format == SCRIPT_FMT_TIMING_MULTI) {
                if (!ctl->siglog)
                        ctl->siglog = log;
                if (!ctl->infolog)
                        ctl->infolog = log;
        }

        return log;
}

static void log_close(struct script_control *ctl,
                      struct script_log *log,
                      const char *msg,
                      int status)
{
        if (!log->initialized)
                return;

        DBG(MISC, ul_debug("closing %s", log->filename));

        switch (log->format) {
        case SCRIPT_FMT_RAW:
        {
                char buf[FORMAT_TIMESTAMP_MAX];
                time_t tvec = script_time((time_t *)NULL);

                strtime_iso(&tvec, ISO_TIMESTAMP, buf, sizeof(buf));
                if (msg)
                        fprintf(log->fp, _("\nScript done on %s [<%s>]\n"), buf, msg);
                else
                        fprintf(log->fp, _("\nScript done on %s [COMMAND_EXIT_CODE=\"%d\"]\n"), buf, status);
                break;
        }
        case SCRIPT_FMT_TIMING_MULTI:
        {
                struct timeval now, delta;

                gettime_monotonic(&now);
                timersub(&now, &log->starttime, &delta);

                log_info(ctl, "DURATION", "%ld.%06ld",
                        (long)delta.tv_sec, (long)delta.tv_usec);
                log_info(ctl, "EXIT_CODE", "%d", status);
                break;
        }
        case SCRIPT_FMT_TIMING_SIMPLE:
                break;
        }

        if (close_stream(log->fp) != 0)
                err(EXIT_FAILURE, "write failed: %s", log->filename);

        log->fp = NULL;
        log->initialized = 0;
}

static void log_start(struct script_control *ctl,
                      struct script_log *log)
{
        if (log->initialized)
                return;

        DBG(MISC, ul_debug("opening %s", log->filename));

        assert(log->fp == NULL);

        /* open the log */
        log->fp = fopen(log->filename,
                        ctl->append && log->format == SCRIPT_FMT_RAW ?
                        "a" UL_CLOEXECSTR :
                        "w" UL_CLOEXECSTR);
        if (!log->fp) {
                restore_tty(ctl, TCSANOW);
                warn(_("cannot open %s"), log->filename);
                fail(ctl);
        }

        /* write header, etc. */
        switch (log->format) {
        case SCRIPT_FMT_RAW:
        {
                char buf[FORMAT_TIMESTAMP_MAX];
                time_t tvec = script_time((time_t *)NULL);

                strtime_iso(&tvec, ISO_TIMESTAMP, buf, sizeof(buf));
                fprintf(log->fp, _("Script started on %s ["), buf);

                if (ctl->isterm) {
                        init_terminal_info(ctl);

                        if (ctl->ttytype)
                                fprintf(log->fp, "TERM=\"%s\" ", ctl->ttytype);
                        if (ctl->ttyname)
                                fprintf(log->fp, "TTY=\"%s\" ", ctl->ttyname);

                        fprintf(log->fp, "COLUMNS=\"%d\" LINES=\"%d\"", ctl->ttycols, ctl->ttylines);
                } else
                        fprintf(log->fp, _("<not executed on terminal>"));

                fputs("]\n", log->fp);
                break;
        }
        case SCRIPT_FMT_TIMING_SIMPLE:
        case SCRIPT_FMT_TIMING_MULTI:
                gettime_monotonic(&log->oldtime);
                gettime_monotonic(&log->starttime);
                break;
        }

        log->initialized = 1;
}

static void start_logging(struct script_control *ctl)
{
        size_t i;

        /* start all output logs */
        for (i = 0; i < ctl->out.nlogs; i++)
                log_start(ctl, ctl->out.logs[i]);

        /* start all input logs */
        for (i = 0; i < ctl->in.nlogs; i++)
                log_start(ctl, ctl->in.logs[i]);
}

static size_t log_write(struct script_control *ctl,
                      struct script_stream *stream,
                      struct script_log *log,
                      char *obuf, size_t bytes)
{
        if (!log->fp)
                return 0;

        DBG(IO, ul_debug("  writining %s", log->filename));

        switch (log->format) {
        case SCRIPT_FMT_RAW:
                if (fwrite_all(obuf, 1, bytes, log->fp)) {
                        warn(_("cannot write %s"), log->filename);
                        fail(ctl);
                }
                break;
        case SCRIPT_FMT_TIMING_SIMPLE:
        {
                struct timeval now, delta;
                int sz;

                DBG(IO, ul_debug("  writing timing info"));

                gettime_monotonic(&now);
                timersub(&now, &log->oldtime, &delta);
                sz = fprintf(log->fp, "%ld.%06ld %zd\n",
                        (long)delta.tv_sec, (long)delta.tv_usec, bytes);
                log->oldtime = now;
                bytes = sz > 0 ? sz : 0;
                break;
        }
        case SCRIPT_FMT_TIMING_MULTI:
        {
                struct timeval now, delta;
                int sz;

                DBG(IO, ul_debug("  writing multi-stream timing info"));

                gettime_monotonic(&now);
                timersub(&now, &log->oldtime, &delta);
                sz = fprintf(log->fp, "%c %ld.%06ld %zd\n",
                        stream->ident,
                        (long)delta.tv_sec, (long)delta.tv_usec, bytes);
                log->oldtime = now;
                bytes = sz > 0 ? sz : 0;
        }
        default:
                break;
        }

        if (ctl->flush)
                fflush(log->fp);

        return bytes;
}

static uint64_t log_stream_activity(
                        struct script_control *ctl,
                        struct script_stream *stream,
                        char *buf, size_t bytes)
{
        size_t i;
        uint64_t outsz = 0;

        for (i = 0; i < stream->nlogs; i++)
                outsz += log_write(ctl, stream, stream->logs[i], buf, bytes);

        return outsz;
}

static uint64_t log_signal(struct script_control *ctl, int signum, char *msgfmt, ...)
{
        struct script_log *log;
        struct timeval now, delta;
        char msg[BUFSIZ] = {0};
        va_list ap;
        int sz;

        assert(ctl);

        log = ctl->siglog;
        if (!log)
                return 0;

        assert(log->format == SCRIPT_FMT_TIMING_MULTI);
        DBG(IO, ul_debug("  writing signal to multi-stream timing"));

        gettime_monotonic(&now);
        timersub(&now, &log->oldtime, &delta);

        if (msgfmt) {
                int rc;
                va_start(ap, msgfmt);
                rc = vsnprintf(msg, sizeof(msg), msgfmt, ap);
                va_end(ap);
                if (rc < 0)
                        *msg = '\0';;
        }

        if (*msg)
                sz = fprintf(log->fp, "S %ld.%06ld SIG%s %s\n",
                        (long)delta.tv_sec, (long)delta.tv_usec,
                        signum_to_signame(signum), msg);
        else
                sz = fprintf(log->fp, "S %ld.%06ld SIG%s\n",
                        (long)delta.tv_sec, (long)delta.tv_usec,
                        signum_to_signame(signum));

        log->oldtime = now;
        return sz > 0 ? sz : 0;
}

static uint64_t log_info(struct script_control *ctl, const char *name, const char *msgfmt, ...)
{
        struct script_log *log;
        char msg[BUFSIZ] = {0};
        va_list ap;
        int sz;

        assert(ctl);

        log = ctl->infolog;
        if (!log)
                return 0;

        assert(log->format == SCRIPT_FMT_TIMING_MULTI);
        DBG(IO, ul_debug("  writing info to multi-stream log"));

        if (msgfmt) {
                int rc;
                va_start(ap, msgfmt);
                rc = vsnprintf(msg, sizeof(msg), msgfmt, ap);
                va_end(ap);
                if (rc < 0)
                        *msg = '\0';;
        }

        if (*msg)
                sz = fprintf(log->fp, "H %f %s %s\n", 0.0, name, msg);
        else
                sz = fprintf(log->fp, "H %f %s\n", 0.0, name);

        return sz > 0 ? sz : 0;
}

static void die_if_link(struct script_control *ctl, const char *filename)
{
        struct stat s;

        if (ctl->force)
                return;
        if (lstat(filename, &s) == 0 && (S_ISLNK(s.st_mode) || s.st_nlink > 1))
                errx(EXIT_FAILURE,
                     _("output file `%s' is a link\n"
                       "Use --force if you really want to use it.\n"
                       "Program not started."), filename);
}

static void restore_tty(struct script_control *ctl, int mode)
{
        struct termios rtt;

        if (!ctl->isterm)
                return;

        rtt = ctl->attrs;
        tcsetattr(STDIN_FILENO, mode, &rtt);
}

static void enable_rawmode_tty(struct script_control *ctl)
{
        struct termios rtt;

        if (!ctl->isterm)
                return;

        rtt = ctl->attrs;
        cfmakeraw(&rtt);
        rtt.c_lflag &= ~ECHO;
        tcsetattr(STDIN_FILENO, TCSANOW, &rtt);
}

static void __attribute__((__noreturn__)) done_log(struct script_control *ctl, const char *msg)
{
        int status;
        size_t i;

        DBG(MISC, ul_debug("done!"));

        restore_tty(ctl, TCSADRAIN);

        if (WIFSIGNALED(ctl->childstatus))
                status = WTERMSIG(ctl->childstatus) + 0x80;
        else
                status = WEXITSTATUS(ctl->childstatus);


        DBG(MISC, ul_debug(" status=%d", status));

        /* close all output logs */
        for (i = 0; i < ctl->out.nlogs; i++)
                log_close(ctl, ctl->out.logs[i], msg, status);

        /* close all input logs */
        for (i = 0; i < ctl->in.nlogs; i++)
                log_close(ctl, ctl->in.logs[i], msg, status);

        if (!ctl->quiet)
                printf(_("Script done.\n"));

#ifdef HAVE_LIBUTEMPTER
        if (ctl->master >= 0)
                utempter_remove_record(ctl->master);
#endif
        kill(ctl->child, SIGTERM);      /* make sure we don't create orphans */

        exit(ctl->rc_wanted ? status : EXIT_SUCCESS);
}

static void __attribute__((__noreturn__)) done(struct script_control *ctl)
{
        done_log(ctl, NULL);
}

static void __attribute__((__noreturn__)) fail(struct script_control *ctl)
{
        DBG(MISC, ul_debug("fail!"));
        kill(0, SIGTERM);
        done(ctl);
}

static void wait_for_child(struct script_control *ctl, int wait)
{
        int status;
        pid_t pid;
        int options = wait ? 0 : WNOHANG;

        DBG(MISC, ul_debug("waiting for child"));

        while ((pid = wait3(&status, options, NULL)) > 0)
                if (pid == ctl->child)
                        ctl->childstatus = status;
}

/* data from master to stdout */
static void write_output(struct script_control *ctl, char *obuf,
                            ssize_t bytes)
{
        DBG(IO, ul_debug("  writing to output"));

        if (write_all(STDOUT_FILENO, obuf, bytes)) {
                DBG(IO, ul_debug("  writing output *failed*"));
                warn(_("write failed"));
                fail(ctl);
        }
}

static int write_to_shell(struct script_control *ctl,
                          char *buf, size_t bufsz)
{
        return write_all(ctl->master, buf, bufsz);
}

/*
 * The script(1) is usually faster than shell, so it's a good idea to wait until
 * the previous message has been already read by shell from slave before we
 * write to master. This is necessary especially for EOF situation when we can
 * send EOF to master before shell is fully initialized, to workaround this
 * problem we wait until slave is empty. For example:
 *
 *   echo "date" | script
 *
 * Unfortunately, the child (usually shell) can ignore stdin at all, so we
 * don't wait forever to avoid dead locks...
 *
 * Note that script is primarily designed for interactive sessions as it
 * maintains master+slave tty stuff within the session. Use pipe to write to
 * script(1) and assume non-interactive (tee-like) behavior is NOT well
 * supported.
 */
static void write_eof_to_shell(struct script_control *ctl)
{
        unsigned int tries = 0;
        struct pollfd fds[] = {
                   { .fd = ctl->slave, .events = POLLIN }
        };
        char c = DEF_EOF;

        DBG(IO, ul_debug(" waiting for empty slave"));
        while (poll(fds, 1, 10) == 1 && tries < 8) {
                DBG(IO, ul_debug("   slave is not empty"));
                xusleep(250000);
                tries++;
        }
        if (tries < 8)
                DBG(IO, ul_debug("   slave is empty now"));

        DBG(IO, ul_debug(" sending EOF to master"));
        write_to_shell(ctl, &c, sizeof(char));
}

static void handle_io(struct script_control *ctl, int fd, int *eof)
{
        char buf[BUFSIZ];
        ssize_t bytes;
        DBG(IO, ul_debug("%d FD active", fd));
        *eof = 0;

        /* read from active FD */
        bytes = read(fd, buf, sizeof(buf));
        if (bytes < 0) {
                if (errno == EAGAIN || errno == EINTR)
                        return;
                fail(ctl);
        }

        if (bytes == 0) {
                *eof = 1;
                return;
        }

        /* from stdin (user) to command */
        if (fd == STDIN_FILENO) {
                DBG(IO, ul_debug(" stdin --> master %zd bytes", bytes));

                if (write_to_shell(ctl, buf, bytes)) {
                        warn(_("write failed"));
                        fail(ctl);
                }
                /* without sync write_output() will write both input &
                 * shell output that looks like double echoing */
                fdatasync(ctl->master);
                ctl->outsz += log_stream_activity(ctl, &ctl->in, buf, (size_t) bytes);

        /* from command (master) to stdout and log */
        } else if (fd == ctl->master) {
                DBG(IO, ul_debug(" master --> stdout %zd bytes", bytes));
                write_output(ctl, buf, bytes);
                ctl->outsz += log_stream_activity(ctl, &ctl->out, buf, (size_t) bytes);
        }

        /* check output limit */
        if (ctl->maxsz != 0 && ctl->outsz >= ctl->maxsz) {
                if (!ctl->quiet)
                        printf(_("Script terminated, max output files size %"PRIu64" exceeded.\n"), ctl->maxsz);
                DBG(IO, ul_debug("output size %"PRIu64", exceeded limit %"PRIu64, ctl->outsz, ctl->maxsz));
                done_log(ctl, _("max output size exceeded"));
        }
}

static void handle_signal(struct script_control *ctl, int fd)
{
        struct signalfd_siginfo info;
        ssize_t bytes;

        DBG(SIGNAL, ul_debug("signal FD %d active", fd));

        bytes = read(fd, &info, sizeof(info));
        if (bytes != sizeof(info)) {
                if (bytes < 0 && (errno == EAGAIN || errno == EINTR))
                        return;
                fail(ctl);
        }

        switch (info.ssi_signo) {
        case SIGCHLD:
                DBG(SIGNAL, ul_debug(" get signal SIGCHLD [ssi_code=%d, ssi_status=%d]",
                                                        info.ssi_code, info.ssi_status));
                if (info.ssi_code == CLD_EXITED
                    || info.ssi_code == CLD_KILLED
                    || info.ssi_code == CLD_DUMPED) {
                        wait_for_child(ctl, 0);
                        ctl->poll_timeout = 10;

                /* In case of ssi_code is CLD_TRAPPED, CLD_STOPPED, or CLD_CONTINUED */
                } else if (info.ssi_status == SIGSTOP && ctl->child) {
                        DBG(SIGNAL, ul_debug(" child stop by SIGSTOP -- stop parent too"));
                        kill(getpid(), SIGSTOP);
                        DBG(SIGNAL, ul_debug(" resume"));
                        kill(ctl->child, SIGCONT);
                }
                return;
        case SIGWINCH:
                DBG(SIGNAL, ul_debug(" get signal SIGWINCH"));
                if (ctl->isterm) {
                        ioctl(STDIN_FILENO, TIOCGWINSZ, (char *)&ctl->win);
                        ioctl(ctl->slave, TIOCSWINSZ, (char *)&ctl->win);
                        log_signal(ctl, info.ssi_signo,
                                        "ROWS=%d COLS=%d",
                                        ctl->win.ws_row,
                                        ctl->win.ws_col);
                }
                break;
        case SIGTERM:
                /* fallthrough */
        case SIGINT:
                /* fallthrough */
        case SIGQUIT:
                log_signal(ctl, info.ssi_signo, NULL);
                DBG(SIGNAL, ul_debug(" get signal SIG{TERM,INT,QUIT}"));
                fprintf(stderr, _("\nSession terminated.\n"));
                /* Child termination is going to generate SIGCHILD (see above) */
                kill(ctl->child, SIGTERM);
                return;
        default:
                abort();
        }
        DBG(SIGNAL, ul_debug("signal handle on FD %d done", fd));
}

static void do_io(struct script_control *ctl)
{
        int ret, eof = 0;
        enum {
                POLLFD_SIGNAL = 0,
                POLLFD_MASTER,
                POLLFD_STDIN

        };
        struct pollfd pfd[] = {
                [POLLFD_SIGNAL] = { .fd = ctl->sigfd,   .events = POLLIN | POLLERR | POLLHUP },
                [POLLFD_MASTER] = { .fd = ctl->master,  .events = POLLIN | POLLERR | POLLHUP },
                [POLLFD_STDIN]  = { .fd = STDIN_FILENO, .events = POLLIN | POLLERR | POLLHUP }
        };

        while (!ctl->die) {
                size_t i;
                int errsv;

                DBG(POLL, ul_debug("calling poll()"));

                /* wait for input or signal */
                ret = poll(pfd, ARRAY_SIZE(pfd), ctl->poll_timeout);
                errsv = errno;
                DBG(POLL, ul_debug("poll() rc=%d", ret));

                if (ret < 0) {
                        if (errsv == EAGAIN)
                                continue;
                        warn(_("poll failed"));
                        fail(ctl);
                }
                if (ret == 0) {
                        DBG(POLL, ul_debug("setting die=1"));
                        ctl->die = 1;
                        break;
                }

                for (i = 0; i < ARRAY_SIZE(pfd); i++) {
                        if (pfd[i].revents == 0)
                                continue;

                        DBG(POLL, ul_debug(" active pfd[%s].fd=%d %s %s %s",
                                                i == POLLFD_STDIN  ? "stdin" :
                                                i == POLLFD_MASTER ? "master" :
                                                i == POLLFD_SIGNAL ? "signal" : "???",
                                                pfd[i].fd,
                                                pfd[i].revents & POLLIN  ? "POLLIN" : "",
                                                pfd[i].revents & POLLHUP ? "POLLHUP" : "",
                                                pfd[i].revents & POLLERR ? "POLLERR" : ""));
                        switch (i) {
                        case POLLFD_STDIN:
                        case POLLFD_MASTER:
                                /* data */
                                if (pfd[i].revents & POLLIN)
                                        handle_io(ctl, pfd[i].fd, &eof);
                                /* EOF maybe detected by two ways:
                                 *      A) poll() return POLLHUP event after close()
                                 *      B) read() returns 0 (no data) */
                                if ((pfd[i].revents & POLLHUP) || eof) {
                                        DBG(POLL, ul_debug(" ignore FD"));
                                        pfd[i].fd = -1;
                                        if (i == POLLFD_STDIN) {
                                                write_eof_to_shell(ctl);
                                                DBG(POLL, ul_debug("  ignore STDIN"));
                                        }
                                }
                                continue;
                        case POLLFD_SIGNAL:
                                handle_signal(ctl, pfd[i].fd);
                                break;
                        }
                }
        }

        DBG(POLL, ul_debug("poll() done"));

        if (!ctl->die)
                wait_for_child(ctl, 1);

        done(ctl);
}

static void getslave(struct script_control *ctl)
{
#ifndef HAVE_LIBUTIL
        ctl->line[strlen("/dev/")] = 't';
        ctl->slave = open(ctl->line, O_RDWR | O_CLOEXEC);
        if (ctl->slave < 0) {
                warn(_("cannot open %s"), ctl->line);
                fail(ctl);
        }
        if (ctl->isterm) {
                tcsetattr(ctl->slave, TCSANOW, &ctl->attrs);
                ioctl(ctl->slave, TIOCSWINSZ, (char *)&ctl->win);
        }
#endif
        setsid();
        ioctl(ctl->slave, TIOCSCTTY, 0);
}

/* don't use DBG() stuff here otherwise it will be in  the typescript file */
static void __attribute__((__noreturn__)) do_shell(struct script_control *ctl)
{
        char *shname;

        getslave(ctl);

        /* close things irrelevant for this process */
        close(ctl->master);
        close(ctl->sigfd);

        dup2(ctl->slave, STDIN_FILENO);
        dup2(ctl->slave, STDOUT_FILENO);
        dup2(ctl->slave, STDERR_FILENO);
        close(ctl->slave);

        ctl->master = -1;

        shname = strrchr(ctl->shell, '/');
        if (shname)
                shname++;
        else
                shname = ctl->shell;

        sigprocmask(SIG_SETMASK, &ctl->sigorg, NULL);

        /*
         * When invoked from within /etc/csh.login, script spawns a csh shell
         * that spawns programs that cannot be killed with a SIGTERM. This is
         * because csh has a documented behavior wherein it disables all
         * signals when processing the /etc/csh.* files.
         *
         * Let's restore the default behavior.
         */
        signal(SIGTERM, SIG_DFL);

        if (access(ctl->shell, X_OK) == 0) {
                if (ctl->command)
                        execl(ctl->shell, shname, "-c", ctl->command, NULL);
                else
                        execl(ctl->shell, shname, "-i", NULL);
        } else {
                if (ctl->command)
                        execlp(shname, "-c", ctl->command, NULL);
                else
                        execlp(shname, "-i", NULL);
        }
        warn(_("failed to execute %s"), ctl->shell);
        fail(ctl);
}


static void getmaster(struct script_control *ctl)
{
#if defined(HAVE_LIBUTIL) && defined(HAVE_PTY_H)
        int rc;

        ctl->isterm = isatty(STDIN_FILENO);

        if (ctl->isterm) {
                if (tcgetattr(STDIN_FILENO, &ctl->attrs) != 0)
                        err(EXIT_FAILURE, _("failed to get terminal attributes"));
                ioctl(STDIN_FILENO, TIOCGWINSZ, (char *)&ctl->win);
                rc = openpty(&ctl->master, &ctl->slave, NULL, &ctl->attrs, &ctl->win);
        } else
                rc = openpty(&ctl->master, &ctl->slave, NULL, NULL, NULL);

        if (rc < 0) {
                warn(_("openpty failed"));
                fail(ctl);
        }
#else
        char *pty, *bank, *cp;

        ctl->isterm = isatty(STDIN_FILENO);

        pty = &ctl->line[strlen("/dev/ptyp")];
        for (bank = "pqrs"; *bank; bank++) {
                ctl->line[strlen("/dev/pty")] = *bank;
                *pty = '0';
                if (access(ctl->line, F_OK) != 0)
                        break;
                for (cp = "0123456789abcdef"; *cp; cp++) {
                        *pty = *cp;
                        ctl->master = open(ctl->line, O_RDWR | O_CLOEXEC);
                        if (ctl->master >= 0) {
                                char *tp = &ctl->line[strlen("/dev/")];
                                int ok;

                                /* verify slave side is usable */
                                *tp = 't';
                                ok = access(ctl->line, R_OK | W_OK) == 0;
                                *tp = 'p';
                                if (ok) {
                                        if (ctl->isterm) {
                                                tcgetattr(STDIN_FILENO, &ctl->attrs);
                                                ioctl(STDIN_FILENO, TIOCGWINSZ, (char *)&ctl->win);
                                        }
                                        return;
                                }
                                close(ctl->master);
                                ctl->master = -1;
                        }
                }
        }
        ctl->master = -1;
        warn(_("out of pty's"));
        fail(ctl);
#endif                          /* not HAVE_LIBUTIL */

        DBG(IO, ul_debug("master fd: %d", ctl->master));
}

int main(int argc, char **argv)
{
        struct script_control ctl = {
#if !HAVE_LIBUTIL || !HAVE_PTY_H
                .line = "/dev/ptyXX",
#endif
                .master = -1,
                .slave  = -1,

                .out = { .ident = 'O' },
                .in  = { .ident = 'I' },

                .poll_timeout = -1
        };
        int ch, format = 0;
        const char *outfile = NULL, *infile = NULL;
        const char *timingfile = NULL;

        enum { FORCE_OPTION = CHAR_MAX + 1 };

        static const struct option longopts[] = {
                {"append", no_argument, NULL, 'a'},
                {"command", required_argument, NULL, 'c'},
                {"return", no_argument, NULL, 'e'},
                {"flush", no_argument, NULL, 'f'},
                {"force", no_argument, NULL, FORCE_OPTION,},
                {"log-in", required_argument, NULL, 'I'},
                {"log-out", required_argument, NULL, 'O'},
                {"log-io", required_argument, NULL, 'B'},
                {"log-timing", required_argument, NULL, 'T'},
                {"logging-format", required_argument, NULL, 'm'},
                {"output-limit", required_argument, NULL, 'o'},
                {"quiet", no_argument, NULL, 'q'},
                {"timing", optional_argument, NULL, 't'},
                {"version", no_argument, NULL, 'V'},
                {"help", no_argument, NULL, 'h'},
                {NULL, 0, NULL, 0}
        };
        static const ul_excl_t excl[] = {       /* rows and cols in ASCII order */
                { 'T', 't' },
                { 0 }
        };
        int excl_st[ARRAY_SIZE(excl)] = UL_EXCL_STATUS_INIT;
        setlocale(LC_ALL, "");
        /*
         * script -t prints time delays as floating point numbers.  The example
         * program (scriptreplay) that we provide to handle this timing output
         * is a perl script, and does not handle numbers in locale format (not
         * even when "use locale;" is added).  So, since these numbers are not
         * for human consumption, it seems easiest to set LC_NUMERIC here.
         */
        setlocale(LC_NUMERIC, "C");
        bindtextdomain(PACKAGE, LOCALEDIR);
        textdomain(PACKAGE);
        close_stdout_atexit();

        script_init_debug();

        while ((ch = getopt_long(argc, argv, "aB:c:efI:O:o:qm:T:t::Vh", longopts, NULL)) != -1) {

                err_exclusive_options(ch, longopts, excl, excl_st);

                switch (ch) {
                case 'a':
                        ctl.append = 1;
                        break;
                case 'c':
                        ctl.command = optarg;
                        break;
                case 'e':
                        ctl.rc_wanted = 1;
                        break;
                case 'f':
                        ctl.flush = 1;
                        break;
                case FORCE_OPTION:
                        ctl.force = 1;
                        break;
                case 'B':
                        log_associate(&ctl, &ctl.in, optarg, SCRIPT_FMT_RAW);
                        log_associate(&ctl, &ctl.out, optarg, SCRIPT_FMT_RAW);
                        infile = outfile = optarg;
                        break;
                case 'I':
                        log_associate(&ctl, &ctl.in, optarg, SCRIPT_FMT_RAW);
                        infile = optarg;
                        break;
                case 'O':
                        log_associate(&ctl, &ctl.out, optarg, SCRIPT_FMT_RAW);
                        outfile = optarg;
                        break;
                case 'o':
                        ctl.maxsz = strtosize_or_err(optarg, _("failed to parse output limit size"));
                        break;
                case 'q':
                        ctl.quiet = 1;
                        break;
                case 'm':
                        if (strcasecmp(optarg, "classic") == 0)
                                format = SCRIPT_FMT_TIMING_SIMPLE;
                        else if (strcasecmp(optarg, "advanced") == 0)
                                format = SCRIPT_FMT_TIMING_MULTI;
                        else
                                errx(EXIT_FAILURE, _("unssuported logging format: '%s'"), optarg);
                        break;
                case 't':
                        if (optarg && *optarg == '=')
                                optarg++;
                        log_associate(&ctl, &ctl.out,
                                optarg ? optarg : "/dev/stderr",
                                SCRIPT_FMT_TIMING_SIMPLE);
                        /* used for message only */
                        timingfile = optarg ? optarg : "stderr";
                        break;
                case 'T' :
                        timingfile = optarg;
                        break;
                case 'V':
                        print_version(EXIT_SUCCESS);
                case 'h':
                        usage();
                default:
                        errtryhelp(EXIT_FAILURE);
                }
        }
        argc -= optind;
        argv += optind;

        /* default if no --log-* specified */
        if (!outfile && !infile) {
                if (argc > 0)
                        outfile = argv[0];
                else {
                        die_if_link(&ctl, DEFAULT_TYPESCRIPT_FILENAME);
                        outfile = DEFAULT_TYPESCRIPT_FILENAME;
                }

                /* associate stdout with typescript file */
                log_associate(&ctl, &ctl.out, outfile, SCRIPT_FMT_RAW);
        }

        if (timingfile) {
                /* the old SCRIPT_FMT_TIMING_SIMPLE should be used when
                 * recoding output only (just for backward compatibility),
                 * otherwise switch to new format. */
                if (!format)
                        format = infile || (outfile && infile) ?
                                        SCRIPT_FMT_TIMING_MULTI :
                                        SCRIPT_FMT_TIMING_SIMPLE;

                else if (format == SCRIPT_FMT_TIMING_SIMPLE && outfile && infile)
                        errx(EXIT_FAILURE, _("log multiple streams is mutually "
                                             "exclusive with 'classic' format"));
                if (outfile)
                        log_associate(&ctl, &ctl.out, timingfile, format);
                if (infile)
                        log_associate(&ctl, &ctl.in, timingfile, format);
        }

        ctl.shell = getenv("SHELL");
        if (ctl.shell == NULL)
                ctl.shell = _PATH_BSHELL;

        getmaster(&ctl);

        if (!ctl.quiet) {
                printf(_("Script started"));
                if (outfile)
                        printf(_(", output log file is '%s'"), outfile);
                if (infile)
                        printf(_(", input log file is '%s'"), infile);
                if (timingfile)
                        printf(_(", timing file is '%s'"), timingfile);
                printf(_(".\n"));
        }
        enable_rawmode_tty(&ctl);

#ifdef HAVE_LIBUTEMPTER
        utempter_add_record(ctl.master, NULL);
#endif
        /* setup signal handler */
        sigemptyset(&ctl.sigset);
        sigaddset(&ctl.sigset, SIGCHLD);
        sigaddset(&ctl.sigset, SIGWINCH);
        sigaddset(&ctl.sigset, SIGTERM);
        sigaddset(&ctl.sigset, SIGINT);
        sigaddset(&ctl.sigset, SIGQUIT);

        /* block signals used for signalfd() to prevent the signals being
         * handled according to their default dispositions */
        sigprocmask(SIG_BLOCK, &ctl.sigset, &ctl.sigorg);

        if ((ctl.sigfd = signalfd(-1, &ctl.sigset, SFD_CLOEXEC)) < 0)
                err(EXIT_FAILURE, _("cannot set signal handler"));

        DBG(SIGNAL, ul_debug("signal fd=%d", ctl.sigfd));

        fflush(stdout);
        ctl.child = fork();

        switch (ctl.child) {
        case -1: /* error */
                warn(_("fork failed"));
                fail(&ctl);
                break;
        case 0: /* child */
                do_shell(&ctl);
                break;
        default: /* parent */
                start_logging(&ctl);

                if (timingfile && format == SCRIPT_FMT_TIMING_MULTI) {
                        char buf[FORMAT_TIMESTAMP_MAX];
                        time_t tvec = script_time((time_t *)NULL);

                        strtime_iso(&tvec, ISO_TIMESTAMP, buf, sizeof(buf));
                        log_info(&ctl, "START_TIME", buf);

                        if (ctl.isterm) {
                                init_terminal_info(&ctl);
                                log_info(&ctl, "TERM", ctl.ttytype);
                                log_info(&ctl, "TTY", ctl.ttyname);
                                log_info(&ctl, "COLUMNS", "%d", ctl.ttycols);
                                log_info(&ctl, "LINES", "%d", ctl.ttylines);
                        }
                        log_info(&ctl, "SHELL", ctl.shell);
                        log_info(&ctl, "TIMING_LOG", timingfile);
                        if (outfile)
                                log_info(&ctl, "OUTPUT_LOG", outfile);
                        if (infile)
                                log_info(&ctl, "INPUT_LOG", infile);
                }
                do_io(&ctl);
                break;
        }

        /* should not happen, all used functions are non-return */
        return EXIT_FAILURE;
}