core: rework logging code to remove log message truncation (bgo #698312)

Use a static GString which will resize itself if the log message
is bigger than the current string size, but will also ensure we
don't do a ton of memory reallocation on every log message.

Previously all log messages were trucated at 512 bytes due to the
log buffer char array being 512 bytes long.
This commit is contained in:
Dan Williams
2013-04-18 10:19:57 -05:00
parent 3cb639a6bb
commit 27e1936277

View File

@@ -62,6 +62,9 @@ static const LogDesc level_descs[] = {
{ 0, NULL } { 0, NULL }
}; };
static GString *msgbuf = NULL;
static volatile gsize msgbuf_once = 0;
void void
_mm_log (const char *loc, _mm_log (const char *loc,
const char *func, const char *func,
@@ -70,24 +73,35 @@ _mm_log (const char *loc,
...) ...)
{ {
va_list args; va_list args;
char *msg;
GTimeVal tv; GTimeVal tv;
char tsbuf[100] = { 0 };
char msgbuf[512] = { 0 };
int syslog_priority = LOG_INFO; int syslog_priority = LOG_INFO;
const char *prefix = NULL;
ssize_t ign; ssize_t ign;
if (!(log_level & level)) if (!(log_level & level))
return; return;
va_start (args, fmt); if (g_once_init_enter (&msgbuf_once)) {
msg = g_strdup_vprintf (fmt, args); msgbuf = g_string_sized_new (512);
va_end (args); g_once_init_leave (&msgbuf_once, 1);
} else
g_string_truncate (msgbuf, 0);
if ((log_level & LOGL_DEBUG) && (level == LOGL_DEBUG))
g_string_append (msgbuf, "<debug> ");
else if ((log_level & LOGL_INFO) && (level == LOGL_INFO))
g_string_append (msgbuf, "<info> ");
else if ((log_level & LOGL_WARN) && (level == LOGL_WARN)) {
g_string_append (msgbuf, "<warn> ");
syslog_priority = LOG_WARNING;
} else if ((log_level & LOGL_ERR) && (level == LOGL_ERR)) {
g_string_append (msgbuf, "<error> ");
syslog_priority = LOG_ERR;
} else
return;
if (ts_flags == TS_FLAG_WALL) { if (ts_flags == TS_FLAG_WALL) {
g_get_current_time (&tv); g_get_current_time (&tv);
snprintf (&tsbuf[0], sizeof (tsbuf), " [%09ld.%06ld]", tv.tv_sec, tv.tv_usec); g_string_append_printf (msgbuf, "[%09ld.%06ld] ", tv.tv_sec, tv.tv_usec);
} else if (ts_flags == TS_FLAG_REL) { } else if (ts_flags == TS_FLAG_REL) {
glong secs; glong secs;
glong usecs; glong usecs;
@@ -100,39 +114,26 @@ _mm_log (const char *loc,
usecs += 1000000; usecs += 1000000;
} }
snprintf (&tsbuf[0], sizeof (tsbuf), " [%06ld.%06ld]", secs, usecs); g_string_append_printf (msgbuf, "[%06ld.%06ld] ", secs, usecs);
} }
if ((log_level & LOGL_DEBUG) && (level == LOGL_DEBUG)) if (func_loc && log_level & LOGL_DEBUG)
prefix = "<debug>"; g_string_append_printf (msgbuf, "[%s] %s(): ", loc, func);
else if ((log_level & LOGL_INFO) && (level == LOGL_INFO))
prefix = "<info> ";
else if ((log_level & LOGL_WARN) && (level == LOGL_WARN)) {
prefix = "<warn> ";
syslog_priority = LOG_WARNING;
} else if ((log_level & LOGL_ERR) && (level == LOGL_ERR)) {
prefix = "<error>";
syslog_priority = LOG_ERR;
} else
g_warn_if_reached ();
if (prefix) { va_start (args, fmt);
if (func_loc && log_level & LOGL_DEBUG) g_string_append_vprintf (msgbuf, fmt, args);
snprintf (msgbuf, sizeof (msgbuf), "%s%s [%s] %s(): %s\n", prefix, tsbuf, loc, func, msg); va_end (args);
else
snprintf (msgbuf, sizeof (msgbuf), "%s%s %s\n", prefix, tsbuf, msg);
if (logfd < 0) g_string_append_c (msgbuf, '\n');
syslog (syslog_priority, "%s", msgbuf);
else {
ign = write (logfd, msgbuf, strlen (msgbuf));
if (ign) {} /* whatever; really shut up about unused result */
fsync (logfd); /* Make sure output is dumped to disk immediately */ if (logfd < 0)
} syslog (syslog_priority, "%s", msgbuf->str);
else {
ign = write (logfd, msgbuf->str, msgbuf->len);
if (ign) {} /* whatever; really shut up about unused result */
fsync (logfd); /* Make sure output is dumped to disk immediately */
} }
g_free (msg);
} }
static void static void