[LEDE-DEV] [PATCH] ubox logread

[Maksym Ruchko]

The read optimization with buffer ustream in the logread caused the logger to hung randomly, more often under high load and when logged messages are large.

To reproduce 100% compile and run:
#include <syslog.h>
#include <stdlib.h>
#include <string.h>

#define BUF_SIZE 8192

int i;
static char msg_buf[BUF_SIZE];

int main(int argc, char* argv[])
{
        setlogmask(LOG_UPTO(LOG_NOTICE));

        openlog(argv[0], LOG_CONS | LOG_PID | LOG_NDELAY, LOG_LOCAL1);

        syslog(LOG_NOTICE, "Program started by User %d", getuid());
        syslog(LOG_INFO, "A tree falls in a forest");

        memset(msg_buf, 'A', BUF_SIZE - 1);
        msg_buf[BUF_SIZE-1] = '\0';
        for (i=0; i < 10; ++i) syslog(LOG_NOTICE, msg_buf);

        syslog(LOG_NOTICE, "After");

        closelog();

        exit(0);
}

The line "After" will not show up in the log and all subsequent log messages are blocked.

Patch below against ubox master branch at https://git.openwrt.org/project/ubox.git  fixes the problem, keeping buffers trickery as fast patch for short messages.


--- log/logread.c.orig  2017-10-19 16:31:04.033719240 +0100
+++ log/logread.c       2017-10-19 16:44:49.203118281 +0100
@@ -223,18 +223,34 @@
 {
        while (true) {
                struct blob_attr *a;
-               int len, cur_len;
+               int len, full_blob_len, read_pending_len, read;
+               char* buf;
 
                a = (void*) ustream_get_read_buf(s, &len);
                if (len < sizeof(*a))
                        break;
 
-               cur_len = blob_len(a) + sizeof(*a);
-               if (len < cur_len)
-                       break;
-
-               log_notify(a);
-               ustream_consume(s, cur_len);
+               full_blob_len = blob_raw_len(a);
+               if (len < full_blob_len) {
+                       read_pending_len = ustream_pending_data(s, false);
+                       if (read_pending_len < full_blob_len)
+                               break;
+                       buf = malloc(full_blob_len);
+                       if (buf) {
+                               read = 0;
+                               do {
+                                       read += ustream_read(s, buf + read, full_blob_len - read);
+                               } while (read < full_blob_len);
+                               log_notify((struct blob_attr*)buf);
+                               free(buf);
+                       } else {
+                               fprintf(stderr, "Malloc failed\n");
+                               break;
+                       }
+               } else {
+                       log_notify(a);
+                       ustream_consume(s, full_blob_len);
+               }
        }
        if (!log_follow)
                uloop_end();
@@ -245,6 +261,7 @@
        static struct ustream_fd test_fd;
 
        test_fd.stream.notify_read = logread_fd_data_cb;
+       test_fd.stream.r.max_buffers = -1;
        ustream_fd_init(&test_fd, fd);
 }


Maksym Ruchko
mruchko at advantech-bb.com