From a2b4dec553405de77bbfa421927ca2ffbfbc0a9e Mon Sep 17 00:00:00 2001 From: Karel Zak Date: Tue, 16 Jun 2015 14:03:09 +0200 Subject: script: add support for SCRIPT_DEBUG= Signed-off-by: Karel Zak --- term-utils/script.c | 67 +++++++++++++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 65 insertions(+), 2 deletions(-) (limited to 'term-utils') diff --git a/term-utils/script.c b/term-utils/script.c index 99ea7293c..d8def5b82 100644 --- a/term-utils/script.c +++ b/term-utils/script.c @@ -70,6 +70,21 @@ #include "all-io.h" #include "monotonic.h" +#include "debug.h" + +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 #endif @@ -112,6 +127,11 @@ struct script_control { int sigfd; /* file descriptor for signalfd() */ }; +static void script_init_debug(void) +{ + __UL_INIT_DEBUG(script, SCRIPT_DEBUG_, 0, SCRIPT_DEBUG); +} + /* * For tests we want to be able to control time output */ @@ -167,6 +187,8 @@ static void die_if_link(const struct script_control *ctl) static void __attribute__((__noreturn__)) done(struct script_control *ctl) { + DBG(MISC, ul_debug("done!")); + if (ctl->isterm) tcsetattr(STDIN_FILENO, TCSADRAIN, &ctl->attrs); if (!ctl->quiet) @@ -192,6 +214,7 @@ static void __attribute__((__noreturn__)) done(struct script_control *ctl) static void __attribute__((__noreturn__)) fail(struct script_control *ctl) { + DBG(MISC, ul_debug("fail!")); kill(0, SIGTERM); done(ctl); } @@ -202,6 +225,8 @@ static void finish(struct script_control *ctl, int wait) 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; @@ -210,9 +235,13 @@ static void finish(struct script_control *ctl, int wait) static void write_output(struct script_control *ctl, char *obuf, ssize_t bytes) { + DBG(IO, ul_debug(" writing output")); + if (ctl->timing && ctl->timingfp) { struct timeval now, delta; + DBG(IO, ul_debug(" writing timing info")); + gettime_monotonic(&now); timersub(&now, &ctl->oldtime, &delta); fprintf(ctl->timingfp, "%ld.%06ld %zd\n", delta.tv_sec, delta.tv_usec, bytes); @@ -220,12 +249,18 @@ static void write_output(struct script_control *ctl, char *obuf, fflush(ctl->timingfp); ctl->oldtime = now; } + + DBG(IO, ul_debug(" writing to script file")); + if (fwrite_all(obuf, 1, bytes, ctl->typescriptfp)) { warn(_("cannot write script file")); fail(ctl); } if (ctl->flush) fflush(ctl->typescriptfp); + + DBG(IO, ul_debug(" writing to output")); + if (write_all(STDOUT_FILENO, obuf, bytes)) { warn(_("write failed")); fail(ctl); @@ -237,6 +272,8 @@ static void handle_io(struct script_control *ctl, int fd) char buf[BUFSIZ]; ssize_t bytes; + DBG(IO, ul_debug("%d FD active", fd)); + /* read from active FD */ bytes = read(fd, buf, sizeof(buf)); if (bytes < 0) { @@ -247,6 +284,8 @@ static void handle_io(struct script_control *ctl, int fd) /* from stdin (user) to command */ if (fd == STDIN_FILENO) { + DBG(IO, ul_debug("stdin --> master")); + if (write_all(ctl->master, buf, bytes)) { warn(_("write failed")); fail(ctl); @@ -256,12 +295,16 @@ static void handle_io(struct script_control *ctl, int fd) fdatasync(ctl->master); if (!ctl->isterm && feof(stdin)) { char c = DEF_EOF; + + DBG(IO, ul_debug("sending EOF to master")); write_all(ctl->master, &c, sizeof(char)); } /* from command (master) to stdout */ - } else if (fd == ctl->master) + } else if (fd == ctl->master) { + DBG(IO, ul_debug("master --> stdout")); write_output(ctl, buf, bytes); + } } static void handle_signal(struct script_control *ctl, int fd) @@ -269,6 +312,8 @@ 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)); assert(bytes == sizeof(info)); @@ -324,20 +369,29 @@ static void do_io(struct script_control *ctl) while (!ctl->die) { size_t i; + DBG(POLL, ul_debug("calling poll()")); + /* wait for input or signal */ ret = poll(pfd, ARRAY_SIZE(pfd), ctl->poll_timeout); + DBG(POLL, ul_debug("poll() rc=%d", ret)); + if (ret < 0) { if (errno == EAGAIN) continue; warn(_("poll failed")); fail(ctl); } - if (ret == 0) + if (ret == 0) { + DBG(POLL, ul_debug("setting die=1")); ctl->die = 1; + } for (i = 0; i < ARRAY_SIZE(pfd); i++) { if (pfd[i].revents == 0) continue; + + DBG(POLL, ul_debug(" active pfd[%zu].fd=%d", i, pfd[i].fd)); + switch (i) { case POLLFD_STDIN: case POLLFD_MASTER: @@ -354,6 +408,9 @@ static void do_io(struct script_control *ctl) } } } + + DBG(POLL, ul_debug("poll() done")); + if (!ctl->die) finish(ctl, 1); /* wait for children */ if (!ctl->quiet && ctl->typescriptfp) { @@ -412,6 +469,7 @@ static void __attribute__((__noreturn__)) doshell(struct script_control *ctl) * * Let's restore the default behavior. */ + DBG(SIGNAL, ul_debug("restore shell SIGTERM default")); signal(SIGTERM, SIG_DFL); if (access(ctl->shell, X_OK) == 0) { @@ -542,6 +600,8 @@ int main(int argc, char **argv) textdomain(PACKAGE); atexit(close_stdout); + script_init_debug(); + while ((ch = getopt_long(argc, argv, "ac:efqt::Vh", longopts, NULL)) != -1) switch (ch) { case 'a': @@ -604,9 +664,12 @@ int main(int argc, char **argv) assert(sigaddset(&ctl.sigset, SIGCHLD) == 0); assert(sigaddset(&ctl.sigset, SIGWINCH) == 0); assert(sigprocmask(SIG_BLOCK, &ctl.sigset, NULL) == 0); + if ((ctl.sigfd = signalfd(-1, &ctl.sigset, 0)) < 0) err(EXIT_FAILURE, _("cannot set signal handler")); + DBG(SIGNAL, ul_debug("signal fd=%d", ctl.sigfd)); + fflush(stdout); ctl.child = fork(); -- cgit v1.2.3-55-g7522