script: support multi-stream logging

* allow to use --log-in <infile> and --log-out <outfile> in the same time
* add --log-io <file> to log stdout and stdin to the one log file
* introduce a new timing file format with entry type identifirs

   I <delay> <size>   : info about input stream
   O <delay> <size>   : info about output stream

in the next commits it's possible to add 'S' for signals and 'H' for
extra (header) information.

* the new file format is optional and enabled only if multiple streams
  logging is requested.

Signed-off-by: Karel Zak <kzak@redhat.com>
This commit is contained in:
Karel Zak 2019-04-12 16:27:54 +02:00
parent 70062aad13
commit c1c2ee0b3a
2 changed files with 84 additions and 13 deletions

View File

@ -44,6 +44,10 @@ makes a typescript of everything displayed on your terminal. It is useful for
students who need a hardcopy record of an interactive session as proof of an
assignment, as the typescript file can be printed out later with
.BR lpr (1).
Since version 2.35
.B script
supports multiple streams and allows to log input and output to separate
files or all the one file.
.PP
If the argument
.I file
@ -87,6 +91,12 @@ being done using `cat foo'.
Allow the default output destination, i.e. the typescript file, to be a hard
or symbolic link. The command will follow a symbolic link.
.TP
\fB\-B\fR, \fB\-\-log\-io\fR \fIfile\fR
Log input and output to the same
\fIfile\fR. Note, this option makes sense only if \fB\-\-log\-timing\fR is
also specified, otherwise it's impossible to separate output and input streams from
the log \fIfile\fR.
.TP
\fB\-I\fR, \fB\-\-log\-in\fR \fIfile\fR
Log input to the \fIfile\fR. The log output is disabled if only \fB\-\-log\-in\fR
specified.
@ -100,12 +110,23 @@ name 'typescript' if the option \fB\-\-log\-out\fR or \fB\-\-log\-in\fR is not
given. The log output is disabled if only \fB\-\-log\-in\fR specified.
.TP
\fB\-T\fR, \fB\-\-log\-timing\fR \fIfile\fR
Log timing information to the \fIfile\fR.
Log timing information to the \fIfile\fR. Two timing file formats are supporte
now. The classic format is used when only one stream (input or output) logging
is enabled. The multi-stream format is used on \fB\-\-log\-io\fR or when
\fB\-\-log\-in\fR and \fB\-\-log\-out\fR are used together.
.sp
This log data contains two fields, separated by a space. The first
.RS
.B Classic format
.PP
The log contains two fields, separated by a space. The first
field indicates how much time elapsed since the previous output. The second
field indicates how many characters were output this time. This information
can be used to replay typescripts with realistic typing and output delays.
field indicates how many characters were output this time.
.sp
.B Multi-stream format
.PP
The first field is entry type itentifier ('I'nput, 'O'utput, 'H'eader, 'S'ignal).
The socond field is how much time elapsed since the previous entry, and rest of the entry is type specific data.
.RE
.TP
\fB\-o\fR, \fB\-\-output-limit\fR \fIsize\fR
Limit the size of the typescript and timing files to

View File

@ -102,7 +102,8 @@ UL_DEBUG_DEFINE_MASKNAMES(script) = UL_DEBUG_EMPTY_MASKNAMES;
enum {
SCRIPT_FMT_RAW = 1, /* raw slave/master data */
SCRIPT_FMT_TIMING_SIMPLE, /* timing info in classic "<time> <delta>" format */
SCRIPT_FMT_TIMING_SIMPLE, /* timing info in classic "<delta> <offset>" format */
SCRIPT_FMT_TIMING_MULTI, /* multiple streams in format "<type> <delta> <offset|etc> */
};
struct script_log {
@ -110,12 +111,15 @@ struct script_log {
int format; /* SCRIPT_FMT_* */
char *filename; /* on command line specified name */
struct timeval oldtime; /* previous entry log time */
unsigned int initialized : 1;
};
struct script_stream {
struct timeval oldtime; /* last update */
struct script_log **logs; /* logs where to write data from stream */
size_t nlogs; /* number of logs */
char ident; /* stream identifier */
};
struct script_control {
@ -191,6 +195,7 @@ static void __attribute__((__noreturn__)) usage(void)
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(_(" -T, --log-timing <file> log timing information to file\n"), out);
fputs(_(" -a, --append append the output\n"), out);
fputs(_(" -c, --command <command> run command rather than interactive shell\n"), out);
@ -227,6 +232,8 @@ static struct script_log *log_associate(struct script_control *ctl,
{
struct script_log *log;
DBG(MISC, ul_debug("associate %s with stream", filename));
assert(ctl);
assert(filename);
assert(stream);
@ -257,6 +264,9 @@ static void log_close(struct script_control *ctl __attribute__((unused)),
const char *msg,
int status)
{
if (!log->initialized)
return;
DBG(MISC, ul_debug("closing %s", log->filename));
switch (log->format) {
@ -280,21 +290,24 @@ static void log_close(struct script_control *ctl __attribute__((unused)),
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)
{
assert(log->fp == NULL);
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);
"a" UL_CLOEXECSTR :
"w" UL_CLOEXECSTR);
if (!log->fp) {
restore_tty(ctl, TCSANOW);
warn(_("cannot open %s"), log->filename);
@ -335,9 +348,12 @@ static void log_start(struct script_control *ctl,
gettime_monotonic(&log->oldtime);
break;
}
log->initialized = 1;
}
static size_t log_write(struct script_control *ctl,
struct script_stream *stream,
struct script_log *log,
char *obuf, size_t bytes)
{
@ -368,6 +384,21 @@ static size_t log_write(struct script_control *ctl,
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;
}
@ -387,7 +418,7 @@ static uint64_t log_stream_activity(
uint64_t outsz = 0;
for (i = 0; i < stream->nlogs; i++)
outsz += log_write(ctl, stream->logs[i], buf, bytes);
outsz += log_write(ctl, stream, stream->logs[i], buf, bytes);
return outsz;
}
@ -885,9 +916,12 @@ int main(int argc, char **argv)
.master = -1,
.slave = -1,
.out = { .ident = 'O' },
.in = { .ident = 'I' },
.poll_timeout = -1
};
int ch;
int ch, format = 0;
const char *outfile = NULL, *infile = NULL;
const char *timingfile = NULL;
@ -901,6 +935,7 @@ int main(int argc, char **argv)
{"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'},
{"output-limit", required_argument, NULL, 'o'},
{"quiet", no_argument, NULL, 'q'},
@ -929,7 +964,7 @@ int main(int argc, char **argv)
script_init_debug();
while ((ch = getopt_long(argc, argv, "ac:efI:O:o:qT:t::Vh", longopts, NULL)) != -1) {
while ((ch = getopt_long(argc, argv, "aB:c:efI:O:o:qT:t::Vh", longopts, NULL)) != -1) {
err_exclusive_options(ch, longopts, excl, excl_st);
@ -949,6 +984,11 @@ int main(int argc, char **argv)
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;
@ -973,7 +1013,6 @@ int main(int argc, char **argv)
timingfile = optarg ? optarg : "stderr";
break;
case 'T' :
log_associate(&ctl, &ctl.out, optarg, SCRIPT_FMT_TIMING_SIMPLE);
timingfile = optarg;
break;
case 'V':
@ -1000,6 +1039,17 @@ int main(int argc, char **argv)
log_associate(&ctl, &ctl.out, outfile, SCRIPT_FMT_RAW);
}
if (timingfile) {
if (!format)
format = outfile && infile ?
SCRIPT_FMT_TIMING_MULTI :
SCRIPT_FMT_TIMING_SIMPLE;
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;