tlog_grc
tlog_source_read(struct tlog_source *source, struct tlog_pkt *pkt)
{
tlog_grc grc;
struct tlog_msg *msg;
assert(tlog_source_is_valid(source));
assert(tlog_pkt_is_valid(pkt));
assert(tlog_pkt_is_void(pkt));
msg = &source->msg;
while (true) {
if (tlog_msg_is_void(msg)) {
grc = tlog_source_read_msg(source);
if (grc != TLOG_RC_OK)
return grc;
if (tlog_msg_is_void(msg))
return TLOG_RC_OK;
if (source->got_msg) {
if (msg->id != (source->last_msg_id + 1)) {
tlog_msg_cleanup(msg);
return TLOG_RC_SOURCE_MSG_ID_OUT_OF_ORDER;
}
} else {
source->got_msg = true;
}
source->last_msg_id = msg->id;
}
grc = tlog_msg_read(msg, pkt, source->io_buf, source->io_size);
if (grc != TLOG_RC_OK) {
tlog_msg_cleanup(msg);
return grc;
}
if (tlog_pkt_is_void(pkt)) {
tlog_msg_cleanup(msg);
} else {
if (source->got_pkt) {
if (tlog_timespec_cmp(&pkt->timestamp,
&source->last_pkt_ts) < 0) {
tlog_pkt_cleanup(pkt);
tlog_msg_cleanup(msg);
return TLOG_RC_SOURCE_PKT_TS_OUT_OF_ORDER;
}
} else {
source->got_pkt = true;
}
source->last_pkt_ts = pkt->timestamp;
return TLOG_RC_OK;
}
}
}
static tlog_grc
tlog_json_sink_write(struct tlog_sink *sink,
const struct tlog_pkt *pkt,
struct tlog_pkt_pos *ppos,
const struct tlog_pkt_pos *end)
{
struct tlog_json_sink *json_sink = (struct tlog_json_sink *)sink;
tlog_grc grc;
assert(!tlog_pkt_is_void(pkt));
if (json_sink->started) {
#ifndef NDEBUG
struct timespec diff;
tlog_timespec_sub(&pkt->timestamp, &json_sink->start, &diff);
assert(tlog_timespec_cmp(&diff, &tlog_timespec_zero) >= 0);
assert(tlog_timespec_cmp(&diff, &tlog_delay_max_timespec) <= 0);
#endif
} else {
json_sink->started = true;
json_sink->start = pkt->timestamp;
}
/* While the packet is not yet written completely */
while (!tlog_json_chunk_write(&json_sink->chunk, pkt, ppos, end)) {
grc = tlog_json_sink_flush(sink);
if (grc != TLOG_RC_OK) {
return grc;
}
}
return TLOG_RC_OK;
}
/** Get log data set item code for a (non-void) packet */
static enum tlog_log_item
tlog_log_item_from_pkt(const struct tlog_pkt *pkt)
{
assert(tlog_pkt_is_valid(pkt));
assert(!tlog_pkt_is_void(pkt));
return pkt->type == TLOG_PKT_TYPE_WINDOW
? TLOG_LOG_ITEM_WINDOW
: (pkt->data.io.output
? TLOG_LOG_ITEM_OUTPUT
: TLOG_LOG_ITEM_INPUT);
}
tlog_grc
tlog_json_msg_read(struct tlog_json_msg *msg, struct tlog_pkt *pkt,
uint8_t *io_buf, size_t io_size)
{
const char *timing_ptr;
size_t io_len = 0;
bool io_full = false;
bool pkt_output;
assert(tlog_json_msg_is_valid(msg));
assert(!tlog_json_msg_is_void(msg));
assert(tlog_pkt_is_valid(pkt));
assert(tlog_pkt_is_void(pkt));
assert(io_buf != NULL);
assert(io_size >= TLOG_JSON_MSG_IO_SIZE_MIN);
/* Until the I/O buffer (io_buf/io_size) is full */
do {
/*
* Read next timing record if the current one is spent
*/
if (msg->rem == 0) {
char type_buf[2];
char type;
int read;
uint64_t first_val;
uint64_t second_val;
struct timespec delay;
/* Skip leading whitespace */
while (true) {
switch (*msg->timing_ptr) {
case ' ':
case '\f':
case '\n':
case '\r':
case '\t':
case '\v':
msg->timing_ptr++;
continue;
}
break;
}
/* Modify timing pointer on the side to be able to rollback */
timing_ptr = msg->timing_ptr;
/* If reached the end of timing and so the end of data */
if (*timing_ptr == 0) {
/* Return whatever we have */
break;
}
if (sscanf(timing_ptr, "%1[][><+=]%" SCNu64 "%n",
type_buf, &first_val, &read) < 2) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
type = *type_buf;
timing_ptr += read;
if (type == '[' || type == ']') {
if (sscanf(timing_ptr, "/%" SCNu64 "%n", &second_val, &read) < 1) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
timing_ptr += read;
} else if (type == '=') {
if (sscanf(timing_ptr, "x%" SCNu64 "%n", &second_val, &read) < 1) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
timing_ptr += read;
} else {
second_val = 0;
}
/* If it is a delay record */
if (type == '+') {
if (first_val != 0) {
if (first_val > TLOG_DELAY_MAX_MS_NUM) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
/* If there was I/O already */
if (io_len > 0) {
/*
* We gotta return the old pos packet and re-read
* delay record next time
*/
break;
}
delay.tv_sec = first_val / 1000;
delay.tv_nsec = first_val % 1000 * 1000000;
tlog_timespec_add(&msg->pos, &delay, &msg->pos);
}
/* Timing record consumed */
msg->timing_ptr = timing_ptr;
/* Read next timing record - no I/O from this one */
continue;
/* If it is a window record */
} else if (type == '=') {
/* If there was I/O already */
if (io_len > 0) {
/*
* We gotta return the I/O packet and re-read
* window record next time
*/
break;
}
/* Check extents */
if (first_val > USHRT_MAX || second_val > USHRT_MAX) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
/* Return window packet */
tlog_pkt_init_window(pkt, &msg->pos,
(unsigned short int)first_val,
(unsigned short int)second_val);
/* Timing record consumed */
msg->timing_ptr = timing_ptr;
return TLOG_RC_OK;
/* If it is a text input record */
} else if (type == '<') {
if (first_val > SIZE_MAX) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
msg->output = false;
msg->binary = false;
msg->rem = first_val;
msg->ptxt_ptr = &msg->in_txt_ptr;
msg->ptxt_len = &msg->in_txt_len;
/* If it is a binary input record */
} else if (type == '[') {
if (first_val > SIZE_MAX || second_val > SIZE_MAX) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
msg->output = false;
msg->binary = true;
msg->rem = second_val;
msg->ptxt_ptr = &msg->in_txt_ptr;
msg->ptxt_len = &msg->in_txt_len;
msg->bin_obj = msg->in_bin_obj;
msg->pbin_pos = &msg->in_bin_pos;
/* If it is a text output record */
} else if (type == '>') {
if (first_val > SIZE_MAX) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
msg->output = true;
msg->binary = false;
msg->rem = first_val;
msg->ptxt_ptr = &msg->out_txt_ptr;
msg->ptxt_len = &msg->out_txt_len;
/* If it is a binary output record */
} else if (type == ']') {
if (first_val > SIZE_MAX || second_val > SIZE_MAX) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
msg->output = true;
msg->binary = true;
msg->rem = second_val;
msg->ptxt_ptr = &msg->out_txt_ptr;
msg->ptxt_len = &msg->out_txt_len;
msg->bin_obj = msg->out_bin_obj;
msg->pbin_pos = &msg->out_bin_pos;
} else {
assert(false);
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TIMING;
}
/* Timing record consumed */
msg->timing_ptr = timing_ptr;
if (msg->binary) {
size_t l;
/* Skip replacement characters */
for (; first_val > 0; first_val--) {
/* If not enough text */
if (*msg->ptxt_len == 0) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TXT;
}
l = tlog_json_msg_utf8_len(*(uint8_t *)*msg->ptxt_ptr);
/* If found invalid UTF-8 character in text */
if (l == 0) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TXT;
}
/* If character crosses text boundary */
if (l > *msg->ptxt_len) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TXT;
}
*msg->ptxt_len -= l;
*msg->ptxt_ptr += l;
}
}
/* Ignore zero I/O */
if (msg->rem == 0) {
continue;
}
}
/* Stop if the packet I/O is in different direction */
if (io_len == 0) {
pkt_output = msg->output;
} else if (pkt_output != msg->output) {
/* Return whatever we have */
break;
}
/*
* Append (a piece of) I/O to the output buffer
*/
if (msg->binary) {
struct json_object *o;
int32_t n;
for (; msg->rem > 0; msg->rem--, io_len++, (*msg->pbin_pos)++) {
o = json_object_array_get_idx(msg->bin_obj, *msg->pbin_pos);
/* If not enough bytes */
if (o == NULL) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_BIN;
}
/* If supposed byte is not an int */
if (json_object_get_type(o) != json_type_int) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_BIN;
}
n = json_object_get_int(o);
/* If supposed byte value is out of range */
if (n < 0 || n > UINT8_MAX) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_BIN;
}
io_buf[io_len] = (uint8_t)n;
/* If the I/O buffer is full */
if (io_len >= io_size) {
io_full = true;
break;
}
}
} else {
uint8_t b;
size_t l;
while (msg->rem > 0) {
b = *(uint8_t *)*msg->ptxt_ptr;
l = tlog_json_msg_utf8_len(b);
/* If found invalid UTF-8 character in text */
if (l == 0) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TXT;
}
/* If character crosses text boundary */
if (l > *msg->ptxt_len) {
return TLOG_RC_JSON_MSG_FIELD_INVALID_VALUE_TXT;
}
/* If character crosses the I/O buffer boundary */
if (io_len + l > io_size) {
io_full = true;
break;
}
while (true) {
io_buf[io_len] = b;
io_len++;
(*msg->ptxt_len)--;
(*msg->ptxt_ptr)++;
l--;
if (l == 0) {
break;
}
b = *(uint8_t *)*msg->ptxt_ptr;
}
msg->rem--;
}
}
} while (!io_full);
if (io_len > 0) {
tlog_pkt_init_io(pkt, &msg->pos, pkt_output, io_buf, false, io_len);
}
return TLOG_RC_OK;
}
/**
* Transfer and log terminal data until interrupted or either end closes.
*
* @param tty_source TTY data source.
* @param log_sink Log sink.
* @param tty_sink TTY data sink.
* @param latency Number of seconds to wait before flushing logged data.
* @param log_mask Logging mask with bits indexed by enum tlog_log_item.
*
* @return Global return code.
*/
static tlog_grc
transfer(struct tlog_source *tty_source,
struct tlog_sink *log_sink,
struct tlog_sink *tty_sink,
unsigned int latency,
unsigned int log_mask)
{
const int exit_sig[] = {SIGINT, SIGTERM, SIGHUP};
tlog_grc return_grc = TLOG_RC_OK;
tlog_grc grc;
size_t i, j;
struct sigaction sa;
bool alarm_set = false;
bool log_pending = false;
sig_atomic_t last_alarm_caught = 0;
sig_atomic_t new_alarm_caught;
struct tlog_pkt pkt = TLOG_PKT_VOID;
struct tlog_pkt_pos tty_pos = TLOG_PKT_POS_VOID;
struct tlog_pkt_pos log_pos = TLOG_PKT_POS_VOID;
/* Setup signal handlers to terminate gracefully */
for (i = 0; i < TLOG_ARRAY_SIZE(exit_sig); i++) {
sigaction(exit_sig[i], NULL, &sa);
if (sa.sa_handler != SIG_IGN)
{
sa.sa_handler = exit_sighandler;
sigemptyset(&sa.sa_mask);
for (j = 0; j < TLOG_ARRAY_SIZE(exit_sig); j++)
sigaddset(&sa.sa_mask, exit_sig[j]);
/* NOTE: no SA_RESTART on purpose */
sa.sa_flags = 0;
sigaction(exit_sig[i], &sa, NULL);
}
}
/* Setup ALRM signal handler */
sa.sa_handler = alarm_sighandler;
sigemptyset(&sa.sa_mask);
/* NOTE: no SA_RESTART on purpose */
sa.sa_flags = 0;
sigaction(SIGALRM, &sa, NULL);
/*
* Transfer I/O and window changes
*/
while (exit_signum == 0) {
/* Handle latency limit */
new_alarm_caught = alarm_caught;
if (new_alarm_caught != last_alarm_caught) {
alarm_set = false;
grc = tlog_sink_flush(log_sink);
if (grc != TLOG_RC_OK) {
fprintf(stderr, "Failed flushing log: %s\n",
tlog_grc_strerror(grc));
return_grc = grc;
goto cleanup;
}
last_alarm_caught = new_alarm_caught;
log_pending = false;
} else if (log_pending && !alarm_set) {
alarm(latency);
alarm_set = true;
}
/* Deliver logged data if any */
if (tlog_pkt_pos_cmp(&tty_pos, &log_pos) < 0) {
grc = tlog_sink_write(tty_sink, &pkt, &tty_pos, &log_pos);
if (grc != TLOG_RC_OK) {
if (grc == TLOG_GRC_FROM(errno, EINTR)) {
continue;
} else if (grc != TLOG_GRC_FROM(errno, EBADF) &&
grc != TLOG_GRC_FROM(errno, EINVAL)) {
fprintf(stderr, "Failed writing terminal data: %s\n",
tlog_grc_strerror(grc));
return_grc = grc;
}
break;
}
continue;
}
/* Log the received data, if any */
if (tlog_pkt_pos_is_in(&log_pos, &pkt)) {
/* If asked to log this type of packet */
if (log_mask & (1 << tlog_log_item_from_pkt(&pkt))) {
grc = tlog_sink_write(log_sink, &pkt, &log_pos, NULL);
if (grc != TLOG_RC_OK &&
grc != TLOG_GRC_FROM(errno, EINTR)) {
fprintf(stderr, "Failed logging terminal data: %s\n",
tlog_grc_strerror(grc));
return_grc = grc;
goto cleanup;
}
log_pending = true;
} else {
tlog_pkt_pos_move_past(&log_pos, &pkt);
}
continue;
}
/* Read new data */
tlog_pkt_cleanup(&pkt);
log_pos = TLOG_PKT_POS_VOID;
tty_pos = TLOG_PKT_POS_VOID;
grc = tlog_source_read(tty_source, &pkt);
if (grc != TLOG_RC_OK) {
if (grc == TLOG_GRC_FROM(errno, EINTR)) {
continue;
} else if (grc != TLOG_GRC_FROM(errno, EBADF) &&
grc != TLOG_GRC_FROM(errno, EIO)) {
fprintf(stderr, "Failed reading terminal data: %s\n",
tlog_grc_strerror(grc));
return_grc = grc;
}
break;
} else if (tlog_pkt_is_void(&pkt)) {
break;
}
}
/* Cut the log (write incomplete characters as binary) */
grc = tlog_sink_cut(log_sink);
if (grc != TLOG_RC_OK) {
fprintf(stderr, "Failed cutting-off the log: %s\n",
tlog_grc_strerror(grc));
if (return_grc == TLOG_RC_OK) {
return_grc = grc;
}
goto cleanup;
}
/* Flush the log */
grc = tlog_sink_flush(log_sink);
if (grc != TLOG_RC_OK) {
fprintf(stderr, "Failed flushing the log: %s\n",
tlog_grc_strerror(grc));
if (return_grc == TLOG_RC_OK) {
return_grc = grc;
}
goto cleanup;
}
cleanup:
tlog_pkt_cleanup(&pkt);
/* Stop the timer */
alarm(0);
/* Restore signal handlers */
signal(SIGALRM, SIG_DFL);
for (i = 0; i < TLOG_ARRAY_SIZE(exit_sig); i++) {
sigaction(exit_sig[i], NULL, &sa);
if (sa.sa_handler != SIG_IGN)
signal(exit_sig[i], SIG_DFL);
}
return return_grc;
}
