laforge has submitted this change. (
https://gerrit.osmocom.org/c/libosmocore/+/35208?usp=email )
(
2 is the latest approved patch-set.
No files were changed between the latest approved patch-set and the submitted
one.
)Change subject: logging: fix nul octets in log output / use osmo_strbuf
......................................................................
logging: fix nul octets in log output / use osmo_strbuf
Patch [1] merged few weeks ago, for yet unknown reasons, sprinkles nul
characters at seemingly randomly chosen log line ends.
Trying to figure out why that happens, i got tired of the unreadable
cruft, and decided to migrate the _output_buf() implementation to
osmo_strbuf first.
With osmo_strbuf in use and implementing 1:1 what the previous code did,
the odd nul octets have disappeared. So the bug was caused by unreadable
code.
[1] 11a416827dd9f2da6b7c1db0e1e83adb1e6e5cc8
Ia7de9d88aa5ac48ec0d5c1a931a89d21c02c5433
"logging: ensure ANSI color escape is sent in same line/before newline"
Related: OS#6284
Related: Ia7de9d88aa5ac48ec0d5c1a931a89d21c02c5433
Change-Id: Ib577a5e0d7450ce93ff21f37ba3262704cbf4752
---
M src/core/logging.c
1 file changed, 70 insertions(+), 84 deletions(-)
Approvals:
Jenkins Builder: Verified
osmith: Looks good to me, but someone else must approve
neels: Looks good to me, approved
laforge: Looks good to me, but someone else must approve
diff --git a/src/core/logging.c b/src/core/logging.c
index dc19cf3..0d215f4 100644
--- a/src/core/logging.c
+++ b/src/core/logging.c
@@ -486,18 +486,18 @@
unsigned int level, const char *file, int line, int
cont,
const char *format, va_list ap)
{
- int ret, len = 0, offset = 0, rem = buf_len;
+ int ret;
const char *c_subsys = NULL;
+ struct osmo_strbuf sb = { .buf = buf, .len = buf_len };
+
+ /* safety net in case of encountering errors and returning nothing */
+ buf[0] = '\0';
/* are we using color */
if (target->use_color) {
c_subsys = color(subsys);
- if (c_subsys) {
- ret = snprintf(buf + offset, rem, "%s", c_subsys);
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
- }
+ if (c_subsys)
+ OSMO_STRBUF_PRINTF(sb, "%s", c_subsys);
}
if (!cont) {
if (target->print_ext_timestamp) {
@@ -506,13 +506,10 @@
struct timeval tv;
osmo_gettimeofday(&tv, NULL);
localtime_r(&tv.tv_sec, &tm);
- ret = snprintf(buf + offset, rem,
"%04d%02d%02d%02d%02d%02d%03d ",
- tm.tm_year + 1900, tm.tm_mon + 1,
tm.tm_mday,
- tm.tm_hour, tm.tm_min, tm.tm_sec,
- (int)(tv.tv_usec / 1000));
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
+ OSMO_STRBUF_PRINTF(sb, "%04d%02d%02d%02d%02d%02d%03d ",
+ tm.tm_year + 1900, tm.tm_mon + 1,
tm.tm_mday,
+ tm.tm_hour, tm.tm_min, tm.tm_sec,
+ (int)(tv.tv_usec / 1000));
#endif
} else if (target->print_timestamp) {
time_t tm;
@@ -520,97 +517,66 @@
goto err;
/* Get human-readable representation of time.
man ctime: we need at least 26 bytes in buf */
- if (rem < 26 || !ctime_r(&tm, buf + offset))
+ if (OSMO_STRBUF_REMAIN(sb) < 26 || !ctime_r(&tm,
sb.pos))
goto err;
- ret = strlen(buf + offset);
+ ret = strnlen(sb.pos, 26);
if (ret <= 0)
goto err;
+ OSMO_STRBUF_ADDED_TAIL(sb, ret);
/* Get rid of useless final '\n' added by ctime_r. We
want a space instead. */
- buf[offset + ret - 1] = ' ';
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
+ OSMO_STRBUF_DROP_TAIL(sb, 1);
+ OSMO_STRBUF_PRINTF(sb, " ");
}
if (target->print_tid) {
if (logging_tid == 0)
logging_tid = (long int)osmo_gettid();
- ret = snprintf(buf + offset, rem, "%ld ", logging_tid);
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
+ OSMO_STRBUF_PRINTF(sb, "%ld ", logging_tid);
}
- if (target->print_category) {
- ret = snprintf(buf + offset, rem, "%s%s%s%s ",
- target->use_color ? level_color(level) :
"",
- log_category_name(subsys),
- target->use_color ? OSMO_LOGCOLOR_END :
"",
- c_subsys ? c_subsys : "");
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
- }
- if (target->print_level) {
- ret = snprintf(buf + offset, rem, "%s%s%s%s ",
- target->use_color ? level_color(level) :
"",
- log_level_str(level),
- target->use_color ? OSMO_LOGCOLOR_END :
"",
- c_subsys ? c_subsys : "");
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
- }
- if (target->print_category_hex) {
- ret = snprintf(buf + offset, rem, "<%4.4x> ", subsys);
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
- }
+ if (target->print_category)
+ OSMO_STRBUF_PRINTF(sb, "%s%s%s%s ",
+ target->use_color ?
level_color(level) : "",
+ log_category_name(subsys),
+ target->use_color ?
OSMO_LOGCOLOR_END : "",
+ c_subsys ? c_subsys : "");
+ if (target->print_level)
+ OSMO_STRBUF_PRINTF(sb, "%s%s%s%s ",
+ target->use_color ?
level_color(level) : "",
+ log_level_str(level),
+ target->use_color ?
OSMO_LOGCOLOR_END : "",
+ c_subsys ? c_subsys : "");
+ if (target->print_category_hex)
+ OSMO_STRBUF_PRINTF(sb, "<%4.4x> ", subsys);
if (target->print_filename_pos == LOG_FILENAME_POS_HEADER_END) {
switch (target->print_filename2) {
case LOG_FILENAME_NONE:
break;
case LOG_FILENAME_PATH:
- ret = snprintf(buf + offset, rem, "%s:%d ",
file, line);
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
+ OSMO_STRBUF_PRINTF(sb, "%s:%d ", file, line);
break;
case LOG_FILENAME_BASENAME:
- ret = snprintf(buf + offset, rem, "%s:%d ",
const_basename(file), line);
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
+ OSMO_STRBUF_PRINTF(sb, "%s:%d ",
const_basename(file), line);
break;
}
}
}
- ret = vsnprintf(buf + offset, rem, format, ap);
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
+ OSMO_STRBUF_APPEND(sb, vsnprintf, format, ap);
/* For LOG_FILENAME_POS_LAST, print the source file info only when the
caller ended the log
* message in '\n'. If so, nip the last '\n' away, insert the source
file info and re-append an
* '\n'. All this to allow LOGP("start..."); LOGPC("...end\n")
constructs. */
if (target->print_filename_pos == LOG_FILENAME_POS_LINE_END
- && offset > 0 && buf[offset - 1] == '\n') {
+ && sb.pos > sb.buf && *(sb.pos - 1) == '\n') {
switch (target->print_filename2) {
case LOG_FILENAME_NONE:
break;
case LOG_FILENAME_PATH:
- offset--;
- len--;
- ret = snprintf(buf + offset, rem, " (%s:%d)\n", file,
line);
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
+ OSMO_STRBUF_DROP_TAIL(sb, 1);
+ OSMO_STRBUF_PRINTF(sb, " (%s:%d)\n", file, line);
break;
case LOG_FILENAME_BASENAME:
- offset--;
- len--;
- ret = snprintf(buf + offset, rem, " (%s:%d)\n",
const_basename(file), line);
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
+ OSMO_STRBUF_DROP_TAIL(sb, 1);
+ OSMO_STRBUF_PRINTF(sb, " (%s:%d)\n",
const_basename(file), line);
break;
}
}
@@ -618,21 +584,15 @@
if (target->use_color && c_subsys) {
/* Ensure the last color escape is sent before the newline
* (to not clobber journald, which works on single-lines only) */
- if (offset > 0 && buf[offset - 1] == '\n') {
- offset--; rem++;
- ret = snprintf(buf + offset, rem, OSMO_LOGCOLOR_END
"\n");
+ if (sb.pos > sb.buf && *(sb.pos - 1) == '\n') {
+ OSMO_STRBUF_DROP_TAIL(sb, 1);
+ OSMO_STRBUF_PRINTF(sb, OSMO_LOGCOLOR_END "\n");
} else {
- ret = snprintf(buf + offset, rem, OSMO_LOGCOLOR_END);
+ OSMO_STRBUF_PRINTF(sb, OSMO_LOGCOLOR_END);
}
-
- if (ret < 0)
- goto err;
- OSMO_SNPRINTF_RET(ret, rem, offset, len);
}
err:
- len = OSMO_MIN(buf_len - 1, len);
- buf[len] = '\0';
- return len;
+ return OSMO_STRBUF_CHAR_COUNT(sb);
}
/* Format the log line for given target; use a stack buffer and call
target->output */
--
To view, visit https://gerrit.osmocom.org/c/libosmocore/+/35208?usp=email
To unsubscribe, or for help writing mail filters, visit
https://gerrit.osmocom.org/settings
Gerrit-Project: libosmocore
Gerrit-Branch: master
Gerrit-Change-Id: Ib577a5e0d7450ce93ff21f37ba3262704cbf4752
Gerrit-Change-Number: 35208
Gerrit-PatchSet: 3
Gerrit-Owner: neels <nhofm...@sysmocom.de>
Gerrit-Reviewer: Jenkins Builder
Gerrit-Reviewer: laforge <lafo...@osmocom.org>
Gerrit-Reviewer: neels <nhofm...@sysmocom.de>
Gerrit-Reviewer: osmith <osm...@sysmocom.de>
Gerrit-MessageType: merged
