From 46a3165cde956683e514788f625a87b3380ddf7c Mon Sep 17 00:00:00 2001
From: wm4 <wm4@nowhere>
Date: Tue, 1 Mar 2016 22:34:14 +0100
Subject: msg: introduce partial line buffers per mp_log

The goal is reducing log messups (which happen surprisingly often) by
buffering partial lines in mp_log. This is still not 100% reliable, but
better.

The extrabuffers for MSGL_STATUS and MSGL_STATS are not needed anymore,
because a separate mp_log instance can be used if problems really occur.

Also, give up, and replace the snprintf acrobatics with bstr.

mp_log.partial has a quite subtle problem wrt. talloc: talloc parents
can not be used, because there's no lock around the internal talloc
structures associated with mp_log. Thus it has to be freed manually,
even if this happens through a talloc destructor.
---
 common/msg.c | 53 ++++++++++++++++++++++++++++-------------------------
 1 file changed, 28 insertions(+), 25 deletions(-)

(limited to 'common')

diff --git a/common/msg.c b/common/msg.c
index 29dd5abbf5..534ba41cb5 100644
--- a/common/msg.c
+++ b/common/msg.c
@@ -31,6 +31,7 @@
 #include "common/common.h"
 #include "common/global.h"
 #include "misc/ring.h"
+#include "misc/bstr.h"
 #include "options/options.h"
 #include "osdep/terminal.h"
 #include "osdep/io.h"
@@ -64,7 +65,7 @@ struct mp_log_root {
      * synchronized mp_log tree.) */
     atomic_ulong reload_counter;
     // --- protected by mp_msg_lock
-    char *buffer;
+    bstr buffer;
 };
 
 struct mp_log {
@@ -74,6 +75,7 @@ struct mp_log {
     int level;                  // minimum log level for any outputs
     int terminal_level;         // minimum log level for terminal output
     atomic_ulong reload_counter;
+    char *partial;
 };
 
 struct mp_log_buffer {
@@ -335,27 +337,17 @@ void mp_msg_va(struct mp_log *log, int lev, const char *format, va_list va)
 
     pthread_mutex_lock(&mp_msg_lock);
 
-    // MSGL_STATUS and MSGL_STATS use their own buffer; this prevents clashes
-    // with mp_msg() users which do not properly send complete lines only.
-    char tmp[256];
-    bool use_tmp = lev == MSGL_STATUS || lev == MSGL_STATS;
-
     struct mp_log_root *root = log->root;
-    char *text = use_tmp ? tmp : root->buffer;
-    int len = use_tmp ? 0 : strlen(text);
-    int max_len = use_tmp ? sizeof(tmp) : talloc_get_size(text);
-
-    va_list t;
-    va_copy(t, va);
-    int res = vsnprintf(text + len, max_len - len, format, t);
-    if (res >= 0 && res >= max_len - len && !use_tmp) {
-        root->buffer = talloc_realloc(root, root->buffer, char, res + len + 1);
-        text = root->buffer;
-        max_len = talloc_get_size(text);
-        res = vsnprintf(text + len, max_len - len, format, va);
-    }
-    if (res < 0)
-        text = "[fprintf error]\n";
+
+    root->buffer.len = 0;
+
+    if (log->partial[0])
+        bstr_xappend_asprintf(root, &root->buffer, "%s", log->partial);
+    log->partial[0] = '\0';
+
+    bstr_xappend_vasprintf(root, &root->buffer, format, va);
+
+    char *text = root->buffer.start;
 
     if (lev == MSGL_STATS) {
         dump_stats(log, lev, text);
@@ -384,15 +376,25 @@ void mp_msg_va(struct mp_log *log, int lev, const char *format, va_list va)
         if (lev == MSGL_STATUS) {
             if (text[0])
                 print_terminal_line(log, lev, text, root->termosd ? "\r" : "\n");
-        } else {
-            int leftover = strlen(text);
-            memmove(root->buffer, text, leftover + 1);
+        } else if (text[0]) {
+            int size = strlen(text) + 1;
+            if (talloc_get_size(log->partial) < size)
+                log->partial = talloc_realloc(NULL, log->partial, char, size);
+            memcpy(log->partial, text, size);
         }
     }
 
     pthread_mutex_unlock(&mp_msg_lock);
 }
 
+static void destroy_log(void *ptr)
+{
+    struct mp_log *log = ptr;
+    // This is not managed via talloc itself, because mp_msg calls must be
+    // thread-safe, while talloc is not thread-safe.
+    talloc_free(log->partial);
+}
+
 // Create a new log context, which uses talloc_ctx as talloc parent, and parent
 // as logical parent.
 // The name is the prefix put before the output. It's usually prefixed by the
@@ -409,7 +411,9 @@ struct mp_log *mp_log_new(void *talloc_ctx, struct mp_log *parent,
     struct mp_log *log = talloc_zero(talloc_ctx, struct mp_log);
     if (!parent->root)
         return log; // same as null_log
+    talloc_set_destructor(log, destroy_log);
     log->root = parent->root;
+    log->partial = talloc_strdup(NULL, "");
     if (name) {
         if (name[0] == '!') {
             name = &name[1];
@@ -443,7 +447,6 @@ void mp_msg_init(struct mpv_global *global)
     *root = (struct mp_log_root){
         .global = global,
         .reload_counter = ATOMIC_VAR_INIT(1),
-        .buffer = talloc_strdup(root, ""),
     };
 
     struct mp_log dummy = { .root = root };
-- 
cgit v1.2.3