logd: missing klogd content

(cherry pick from commit ee49c6a670a54e0636f81f39ddc93c87c9a4d766)

- regression in log_strtok_r (part deux) In commit
      'logd: fix kernel logline stutter'
  2c3b300fd8307e8da13608197d0a89bc613de5fb we introduced log_strtok_r.
  as a replacement for strtok_r that dealt with a problem with
  some kernel log messages. Fix is to refine definition of
  is_timestamp to not match on patterns like [0], requiring
  a single period. Another fix is to refine definition of
  is_prio to properly escape non-digit content.
- Missing content because SYSLOG_ACTION_SIZE_BUFFER with added logging
  is too short for full read of SYSLOG_ACTION_READ_ALL dropping
  initial content. Add a margin for additional 1024 bytes.
- Absolute _first_ log entry has sequence number of 1, which is
  specifically dropped, start sequence count at 1 rather than 0.
- Remove trailing space for efficiency.
- If tag exists but no content, trick into kernel logging.

Bug: 21851884
Change-Id: I0867a555a3bca09bbf18d18e75e41dffffe57a23

3 files changed, 68 insertions, 42 deletions

diff --git a/logd/LogBufferElement.cpp b/logd/LogBufferElement.cpp
index 7df1123..3f5fdce 100644
--- a/logd/LogBufferElement.cpp
+++ b/logd/LogBufferElement.cpp
@@ -30,7 +30,7 @@
 #include "LogReader.h"
 
 const uint64_t LogBufferElement::FLUSH_ERROR(0);
-atomic_int_fast64_t LogBufferElement::sequence;
+atomic_int_fast64_t LogBufferElement::sequence(1);
 
 LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime,
                                    uid_t uid, pid_t pid, pid_t tid,
diff --git a/logd/LogKlog.cpp b/logd/LogKlog.cpp
index 7d14648..d578c04 100644
--- a/logd/LogKlog.cpp
+++ b/logd/LogKlog.cpp
@@ -45,8 +45,8 @@ static char *is_prio(char *s) {
     }
     char c;
     while ((c = *s++)) {
-        if (!isdigit(c) && (c == '>')) {
-            return s;
+        if (!isdigit(c)) {
+            return (c == '>') ? s : NULL;
         }
     }
     return NULL;
@@ -65,17 +65,15 @@ static char *is_timestamp(char *s) {
     while ((c = *s++)) {
         if ((c == '.') && first_period) {
             first_period = false;
-            continue;
-        }
-        if (!isdigit(c) && (c == ']')) {
-            return s;
+        } else if (!isdigit(c)) {
+            return ((c == ']') && !first_period && (*s == ' ')) ? s : NULL;
         }
     }
     return NULL;
 }
 
 // Like strtok_r with "\r\n" except that we look for log signatures (regex)
-//   \(\(<[0-9]+>\)\([[] *[0-9]+[]]\)\{0,1\}\|[[] *[0-9]+[]]\)
+// \(\(<[0-9]+>\)\([[] *[0-9]+[.][0-9]+[]] \)\{0,1\}\|[[] *[0-9]+[.][0-9]+[]] \)
 // and split if we see a second one without a newline.
 
 #define SIGNATURE_MASK     0xF0
@@ -547,10 +545,21 @@ int LogKlog::log(const char *buf) {
         }
     }
     size_t l = etag - tag;
+    // skip leading space
     while (isspace(*buf)) {
         ++buf;
     }
-    size_t n = 1 + l + 1 + strlen(buf) + 1;
+    // truncate trailing space
+    size_t b = strlen(buf);
+    while (b && isspace(buf[b-1])) {
+        --b;
+    }
+    // trick ... allow tag with empty content to be logged. log() drops empty
+    if (!b && l) {
+        buf = " ";
+        b = 1;
+    }
+    size_t n = 1 + l + 1 + b + 1;
 
     // Allocate a buffer to hold the interpreted log message
     int rc = n;
@@ -572,7 +581,8 @@ int LogKlog::log(const char *buf) {
     ++np;
 
     // Copy main message to the remainder
-    strcpy(np, buf);
+    strncpy(np, buf, b);
+    np[b] = '\0';
 
     // Log message
     rc = logbuf->log(LOG_ID_KERNEL, now, uid, pid, tid, newstr,
diff --git a/logd/main.cpp b/logd/main.cpp
index a876c99..9b88983 100644
--- a/logd/main.cpp
+++ b/logd/main.cpp
@@ -33,6 +33,8 @@
 #include <syslog.h>
 #include <unistd.h>
 
+#include <memory>
+
 #include <cutils/properties.h>
 #include <cutils/sched_policy.h>
 #include <cutils/sockets.h>
@@ -275,6 +277,45 @@ static bool property_get_bool_svelte(const char *key) {
             && !property_get_bool("ro.config.low_ram", false));
 }
 
+static void readDmesg(LogAudit *al, LogKlog *kl) {
+    if (!al && !kl) {
+        return;
+    }
+
+    int len = klogctl(KLOG_SIZE_BUFFER, NULL, 0);
+    if (len <= 0) {
+        return;
+    }
+
+    len += 1024; // Margin for additional input race or trailing nul
+    std::unique_ptr<char []> buf(new char[len]);
+
+    int rc = klogctl(KLOG_READ_ALL, buf.get(), len);
+    if (rc <= 0) {
+        return;
+    }
+
+    if (rc < len) {
+        len = rc + 1;
+    }
+    buf[len - 1] = '\0';
+
+    if (kl) {
+        kl->synchronize(buf.get());
+    }
+
+    for (char *ptr = NULL, *tok = buf.get();
+         (rc >= 0) && ((tok = log_strtok_r(tok, &ptr)));
+         tok = NULL) {
+        if (al) {
+            rc = al->log(tok);
+        }
+        if (kl) {
+            rc = kl->log(tok);
+        }
+    }
+}
+
 // Foreground waits for exit of the main persistent threads
 // that are started here. The threads are created to manage
 // UNIX domain client sockets for writing, reading and
@@ -410,41 +451,16 @@ int main(int argc, char *argv[]) {
         kl = new LogKlog(logBuf, reader, fdDmesg, fdPmesg, al != NULL);
     }
 
-    if (al || kl) {
-        int len = klogctl(KLOG_SIZE_BUFFER, NULL, 0);
-        if (len > 0) {
-            len++;
-            char buf[len];
-
-            int rc = klogctl(KLOG_READ_ALL, buf, len);
-
-            buf[len - 1] = '\0';
-
-            if ((rc >= 0) && kl) {
-                kl->synchronize(buf);
-            }
-
-            for (char *ptr = NULL, *tok = buf;
-                 (rc >= 0) && ((tok = log_strtok_r(tok, &ptr)));
-                 tok = NULL) {
-                if (al) {
-                    rc = al->log(tok);
-                }
-                if (kl) {
-                    rc = kl->log(tok);
-                }
-            }
-        }
+    readDmesg(al, kl);
 
-        // failure is an option ... messages are in dmesg (required by standard)
+    // failure is an option ... messages are in dmesg (required by standard)
 
-        if (kl && kl->startListener()) {
-            delete kl;
-        }
+    if (kl && kl->startListener()) {
+        delete kl;
+    }
 
-        if (al && al->startListener()) {
-            delete al;
-        }
+    if (al && al->startListener()) {
+        delete al;
     }
 
     TEMP_FAILURE_RETRY(pause());