From 8444eb81b37991ce0fc4ae1d8d79b01688a02426 Mon Sep 17 00:00:00 2001
From: Mark Salyzyn <salyzyn@google.com>
Date: Thu, 24 Apr 2014 09:43:23 -0700
Subject: [PATCH] logd: liblog: ALOG silently drops excessively long messages

Bug: 14280914
Change-Id: Idddd29784625094e54144953c29f64692a88eee9
---
 liblog/logd_write.c          | 43 ++++++++++++++++++---------
 liblog/tests/liblog_test.cpp | 57 ++++++++++++++++++++++++++++++++++++
 logd/LogListener.cpp         |  2 +-
 3 files changed, 87 insertions(+), 15 deletions(-)

diff --git a/liblog/logd_write.c b/liblog/logd_write.c
index 48531d571..bd36a65c6 100644
--- a/liblog/logd_write.c
+++ b/liblog/logd_write.c
@@ -146,9 +146,15 @@ static int __write_to_log_kernel(log_id_t log_id, struct iovec *vec, size_t nr)
             ret = -errno;
         }
     } while (ret == -EINTR);
-
-    return ret;
 #else
+    static const unsigned header_length = 3;
+    struct iovec newVec[nr + header_length];
+    typeof_log_id_t log_id_buf;
+    uint16_t tid;
+    struct timespec ts;
+    log_time realtime_ts;
+    size_t i, payload_size;
+
     if (getuid() == AID_LOGD) {
         /*
          * ignore log messages we send to ourself.
@@ -181,29 +187,33 @@ static int __write_to_log_kernel(log_id_t log_id, struct iovec *vec, size_t nr)
      *      };
      *  };
      */
-    static const unsigned header_length = 3;
-    struct iovec newVec[nr + header_length];
-    typeof_log_id_t log_id_buf = log_id;
-    uint16_t tid = gettid();
+
+    log_id_buf = log_id;
+    tid = gettid();
 
     newVec[0].iov_base   = (unsigned char *) &log_id_buf;
     newVec[0].iov_len    = sizeof_log_id_t;
     newVec[1].iov_base   = (unsigned char *) &tid;
     newVec[1].iov_len    = sizeof(tid);
 
-    struct timespec ts;
     clock_gettime(CLOCK_REALTIME, &ts);
-    log_time realtime_ts;
     realtime_ts.tv_sec = ts.tv_sec;
     realtime_ts.tv_nsec = ts.tv_nsec;
 
     newVec[2].iov_base   = (unsigned char *) &realtime_ts;
     newVec[2].iov_len    = sizeof(log_time);
 
-    size_t i;
-    for (i = header_length; i < nr + header_length; i++) {
-        newVec[i].iov_base = vec[i-header_length].iov_base;
-        newVec[i].iov_len  = vec[i-header_length].iov_len;
+    for (payload_size = 0, i = header_length; i < nr + header_length; i++) {
+        newVec[i].iov_base = vec[i - header_length].iov_base;
+        payload_size += newVec[i].iov_len = vec[i - header_length].iov_len;
+
+        if (payload_size > LOGGER_ENTRY_MAX_PAYLOAD) {
+            newVec[i].iov_len -= payload_size - LOGGER_ENTRY_MAX_PAYLOAD;
+            if (newVec[i].iov_len) {
+                ++i;
+            }
+            break;
+        }
     }
 
     /*
@@ -212,7 +222,7 @@ static int __write_to_log_kernel(log_id_t log_id, struct iovec *vec, size_t nr)
      * ENOTCONN occurs if logd dies.
      * EAGAIN occurs if logd is overloaded.
      */
-    ret = writev(logd_fd, newVec, nr + header_length);
+    ret = writev(logd_fd, newVec, i);
     if (ret < 0) {
         ret = -errno;
         if (ret == -ENOTCONN) {
@@ -234,8 +244,13 @@ static int __write_to_log_kernel(log_id_t log_id, struct iovec *vec, size_t nr)
             }
         }
     }
-    return ret;
+
+    if (ret > (ssize_t)(sizeof_log_id_t + sizeof(tid) + sizeof(log_time))) {
+        ret -= sizeof_log_id_t + sizeof(tid) + sizeof(log_time);
+    }
 #endif
+
+    return ret;
 }
 
 #if FAKE_LOG_DEVICE
diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp
index 24ae738f0..92b68acee 100644
--- a/liblog/tests/liblog_test.cpp
+++ b/liblog/tests/liblog_test.cpp
@@ -482,11 +482,68 @@ TEST(liblog, max_payload) {
         }
     }
 
+    android_logger_list_close(logger_list);
+
     EXPECT_EQ(true, matches);
 
     EXPECT_LE(sizeof(max_payload_buf), static_cast<size_t>(max_len));
+}
+
+TEST(liblog, too_big_payload) {
+    pid_t pid = getpid();
+    static const char big_payload_tag[] = "TEST_big_payload_XXXX";
+    char tag[sizeof(big_payload_tag)];
+    memcpy(tag, big_payload_tag, sizeof(tag));
+    snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF);
+
+    std::string longString(3266519, 'x');
+
+    ssize_t ret = LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM,
+                                    ANDROID_LOG_INFO, tag, longString.c_str()));
+
+    struct logger_list *logger_list;
+
+    ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
+        LOG_ID_SYSTEM, O_RDONLY | O_NDELAY, 100, 0)));
+
+    ssize_t max_len = 0;
+
+    for(;;) {
+        log_msg log_msg;
+        if (android_logger_list_read(logger_list, &log_msg) <= 0) {
+            break;
+        }
+
+        if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) {
+            continue;
+        }
+
+        char *data = log_msg.msg() + 1;
+
+        if (strcmp(data, tag)) {
+            continue;
+        }
+
+        data += strlen(data) + 1;
+
+        const char *left = data;
+        const char *right = longString.c_str();
+        while (*left && *right && (*left == *right)) {
+            ++left;
+            ++right;
+        }
+
+        if (max_len <= (left - data)) {
+            max_len = left - data + 1;
+        }
+    }
 
     android_logger_list_close(logger_list);
+
+    EXPECT_LE(LOGGER_ENTRY_MAX_PAYLOAD - sizeof(big_payload_tag),
+              static_cast<size_t>(max_len));
+
+    EXPECT_EQ(ret, max_len + sizeof(big_payload_tag));
 }
 
 TEST(liblog, dual_reader) {
diff --git a/logd/LogListener.cpp b/logd/LogListener.cpp
index ed5b39156..1d0a51cfd 100644
--- a/logd/LogListener.cpp
+++ b/logd/LogListener.cpp
@@ -31,7 +31,7 @@ LogListener::LogListener(LogBuffer *buf, LogReader *reader)
 {  }
 
 bool LogListener::onDataAvailable(SocketClient *cli) {
-    char buffer[sizeof_log_id_t + sizeof(log_time) + sizeof(char)
+    char buffer[sizeof_log_id_t + sizeof(uint16_t) + sizeof(log_time)
         + LOGGER_ENTRY_MAX_PAYLOAD];
     struct iovec iov = { buffer, sizeof(buffer) };
     memset(buffer, 0, sizeof(buffer));