From 84e12ac55a6049cf08ef2f9a5527737424fe1c6a Mon Sep 17 00:00:00 2001 From: David Lamparter Date: Sat, 10 Apr 2021 21:02:06 +0200 Subject: [PATCH] lib: fix possible assert() fail in zlog_fd() If the last message in a batched logging operation isn't printed due to priority, this skips the code that flushes prepared messages through writev() and can trigger the assert() at the end of zlog_fd(). Since any logmsg above info priority triggers a buffer flush, running into this situation requires a log file target configured for info priority, at least 1 message of info priority buffered, a debug message buffered after that, and then a buffer flush (explicit or due to buffer full). I haven't seen this chain of events happen in the wild, but it needs fixing anyway. Signed-off-by: David Lamparter (cherry picked from commit db2baed166581081db692fab0214752dbb121ed3) --- lib/zlog_targets.c | 60 ++++++++++++++++++++++++++-------------------- 1 file changed, 34 insertions(+), 26 deletions(-) diff --git a/lib/zlog_targets.c b/lib/zlog_targets.c index b23ab073b4..cc97daea73 100644 --- a/lib/zlog_targets.c +++ b/lib/zlog_targets.c @@ -78,40 +78,48 @@ void zlog_fd(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsgs) struct zlog_msg *msg = msgs[i]; int prio = zlog_msg_prio(msg); - if (prio > zt->prio_min) - continue; - - iov[iovpos].iov_base = ts_pos; - if (iovpos > 0) - *ts_pos++ = '\n'; - ts_pos += zlog_msg_ts(msg, ts_pos, sizeof(ts_buf) - 1 - - (ts_pos - ts_buf), - ZLOG_TS_LEGACY | zte->ts_subsec); - *ts_pos++ = ' '; - iov[iovpos].iov_len = ts_pos - (char *)iov[iovpos].iov_base; + if (prio <= zt->prio_min) { + iov[iovpos].iov_base = ts_pos; + if (iovpos > 0) + *ts_pos++ = '\n'; + ts_pos += zlog_msg_ts(msg, ts_pos, + sizeof(ts_buf) - 1 + - (ts_pos - ts_buf), + ZLOG_TS_LEGACY | zte->ts_subsec); + *ts_pos++ = ' '; + iov[iovpos].iov_len = + ts_pos - (char *)iov[iovpos].iov_base; - iovpos++; + iovpos++; - if (zte->record_priority) { - iov[iovpos].iov_base = (char *)prionames[prio]; - iov[iovpos].iov_len = strlen(iov[iovpos].iov_base); + if (zte->record_priority) { + iov[iovpos].iov_base = (char *)prionames[prio]; + iov[iovpos].iov_len = + strlen(iov[iovpos].iov_base); - iovpos++; - } + iovpos++; + } - iov[iovpos].iov_base = zlog_prefix; - iov[iovpos].iov_len = zlog_prefixsz; + iov[iovpos].iov_base = zlog_prefix; + iov[iovpos].iov_len = zlog_prefixsz; - iovpos++; + iovpos++; - iov[iovpos].iov_base = (char *)zlog_msg_text(msg, &textlen); - iov[iovpos].iov_len = textlen; + iov[iovpos].iov_base = + (char *)zlog_msg_text(msg, &textlen); + iov[iovpos].iov_len = textlen; - iovpos++; + iovpos++; + } - if (ts_buf + sizeof(ts_buf) - ts_pos < TS_LEN - || i + 1 == nmsgs - || array_size(iov) - iovpos < 5) { + /* conditions that trigger writing: + * - out of space for more timestamps/headers + * - this being the last message in the batch + * - not enough remaining iov entries + */ + if (iovpos > 0 && (ts_buf + sizeof(ts_buf) - ts_pos < TS_LEN + || i + 1 == nmsgs + || array_size(iov) - iovpos < 5)) { iov[iovpos].iov_base = (char *)"\n"; iov[iovpos].iov_len = 1; -- 2.39.5