From d3ecc66b9cb38974ef0d19ed9e25074bbe70f1fa Mon Sep 17 00:00:00 2001 From: Tom Cherry Date: Thu, 9 Apr 2020 14:53:55 -0700 Subject: [PATCH] liblog: support extended logger_entry headers logger_entry has a hdr_size field meant for backwards compatibility, however there are a few checks that expect it to be a specific size. More problematically, it has a variable length array element, msg[0] at the end, that would be incorrect if the header size was not kept static. This change fixes up those issues to facilitate future additions. Bug: 119867234 Test: logging works with extended size headers, logging unit tests Test: newly added unit tests with extended size header Change-Id: I14b2b0855d219d11f374b53a5aa8e05cd6a65eef --- liblog/include/log/log_read.h | 4 --- liblog/logprint.cpp | 22 ++++++------ liblog/pmsg_reader.cpp | 2 +- liblog/tests/logprint_test.cpp | 66 ++++++++++++++++++++++++++++++++++ logd/tests/logd_test.cpp | 2 +- 5 files changed, 79 insertions(+), 17 deletions(-) diff --git a/liblog/include/log/log_read.h b/liblog/include/log/log_read.h index 05ad25f5e..b9a6bc9d3 100644 --- a/liblog/include/log/log_read.h +++ b/liblog/include/log/log_read.h @@ -48,8 +48,6 @@ extern "C" { * access to raw information, or parsing is an issue. */ -#pragma clang diagnostic push -#pragma clang diagnostic ignored "-Wzero-length-array" struct logger_entry { uint16_t len; /* length of the payload */ uint16_t hdr_size; /* sizeof(struct logger_entry) */ @@ -59,9 +57,7 @@ struct logger_entry { uint32_t nsec; /* nanoseconds */ uint32_t lid; /* log id of the payload, bottom 4 bits currently */ uint32_t uid; /* generating process's uid */ - char msg[0]; /* the entry's payload */ }; -#pragma clang diagnostic pop /* * The maximum size of the log entry payload that can be diff --git a/liblog/logprint.cpp b/liblog/logprint.cpp index e32878acf..5c69bf863 100644 --- a/liblog/logprint.cpp +++ b/liblog/logprint.cpp @@ -509,12 +509,12 @@ int android_log_processLogBuffer(struct logger_entry* buf, AndroidLogEntry* entr * format: \0\0 * * tag str - * starts at buf->msg+1 + * starts at buf + buf->hdr_size + 1 * msg - * starts at buf->msg+1+len(tag)+1 + * starts at buf + buf->hdr_size + 1 + len(tag) + 1 * - * The message may have been truncated by the kernel log driver. - * When that happens, we must null-terminate the message ourselves. + * The message may have been truncated. When that happens, we must null-terminate the message + * ourselves. */ if (buf->len < 3) { /* @@ -529,11 +529,11 @@ int android_log_processLogBuffer(struct logger_entry* buf, AndroidLogEntry* entr int msgEnd = -1; int i; - char* msg = buf->msg; - if (buf->hdr_size != sizeof(struct logger_entry)) { - fprintf(stderr, "+++ LOG: entry illegal hdr_size\n"); + if (buf->hdr_size < sizeof(logger_entry)) { + fprintf(stderr, "+++ LOG: hdr_size must be at least as big as struct logger_entry\n"); return -1; } + char* msg = reinterpret_cast(buf) + buf->hdr_size; entry->uid = buf->uid; for (i = 1; i < buf->len; i++) { @@ -985,11 +985,11 @@ int android_log_processBinaryLogBuffer( entry->pid = buf->pid; entry->tid = buf->tid; - eventData = (const unsigned char*)buf->msg; - if (buf->hdr_size != sizeof(struct logger_entry)) { - fprintf(stderr, "+++ LOG: entry illegal hdr_size\n"); + if (buf->hdr_size < sizeof(logger_entry)) { + fprintf(stderr, "+++ LOG: hdr_size must be at least as big as struct logger_entry\n"); return -1; } + eventData = reinterpret_cast(buf) + buf->hdr_size; if (buf->lid == LOG_ID_SECURITY) { entry->priority = ANDROID_LOG_WARN; } @@ -1048,7 +1048,7 @@ int android_log_processBinaryLogBuffer( } if ((result == 1) && fmtStr) { /* We overflowed :-(, let's repaint the line w/o format dressings */ - eventData = (const unsigned char*)buf->msg; + eventData = reinterpret_cast(buf) + buf->hdr_size; eventData += 4; outBuf = messageBuf; outRemaining = messageBufLen - 1; diff --git a/liblog/pmsg_reader.cpp b/liblog/pmsg_reader.cpp index 129d76721..0e39aab14 100644 --- a/liblog/pmsg_reader.cpp +++ b/liblog/pmsg_reader.cpp @@ -96,7 +96,7 @@ int PmsgRead(struct logger_list* logger_list, struct log_msg* log_msg) { ((logger_list->start.tv_sec != buf.l.realtime.tv_sec) || (logger_list->start.tv_nsec <= buf.l.realtime.tv_nsec)))) && (!logger_list->pid || (logger_list->pid == buf.p.pid))) { - char* msg = log_msg->entry.msg; + char* msg = reinterpret_cast(&log_msg->entry) + log_msg->entry.hdr_size; *msg = buf.prio; fd = atomic_load(&logger_list->fd); if (fd <= 0) { diff --git a/liblog/tests/logprint_test.cpp b/liblog/tests/logprint_test.cpp index 7ca02ac0b..72e53f9bd 100644 --- a/liblog/tests/logprint_test.cpp +++ b/liblog/tests/logprint_test.cpp @@ -14,8 +14,14 @@ * limitations under the License. */ +#include + +#include + #include +#include + size_t convertPrintable(char* p, const char* message, size_t messageLen); TEST(liblog, convertPrintable_ascii) { @@ -85,3 +91,63 @@ TEST(liblog, convertPrintable_mixed) { EXPECT_EQ(output_size, strlen(expected_output)); EXPECT_STREQ(expected_output, output); } + +TEST(liblog, log_print_different_header_size) { + constexpr int32_t kPid = 123; + constexpr uint32_t kTid = 456; + constexpr uint32_t kSec = 1000; + constexpr uint32_t kNsec = 999; + constexpr uint32_t kLid = LOG_ID_MAIN; + constexpr uint32_t kUid = 987; + constexpr char kPriority = ANDROID_LOG_ERROR; + + auto create_buf = [](char* buf, size_t len, uint16_t hdr_size) { + memset(buf, 0, len); + logger_entry* header = reinterpret_cast(buf); + header->hdr_size = hdr_size; + header->pid = kPid; + header->tid = kTid; + header->sec = kSec; + header->nsec = kNsec; + header->lid = kLid; + header->uid = kUid; + char* message = buf + header->hdr_size; + uint16_t message_len = 0; + message[message_len++] = kPriority; + message[message_len++] = 'T'; + message[message_len++] = 'a'; + message[message_len++] = 'g'; + message[message_len++] = '\0'; + message[message_len++] = 'm'; + message[message_len++] = 's'; + message[message_len++] = 'g'; + message[message_len++] = '!'; + message[message_len++] = '\0'; + header->len = message_len; + }; + + auto check_entry = [&](const AndroidLogEntry& entry) { + EXPECT_EQ(kSec, static_cast(entry.tv_sec)); + EXPECT_EQ(kNsec, static_cast(entry.tv_nsec)); + EXPECT_EQ(kPriority, entry.priority); + EXPECT_EQ(kUid, static_cast(entry.uid)); + EXPECT_EQ(kPid, entry.pid); + EXPECT_EQ(kTid, static_cast(entry.tid)); + EXPECT_STREQ("Tag", entry.tag); + EXPECT_EQ(4U, entry.tagLen); // Apparently taglen includes the nullptr? + EXPECT_EQ(4U, entry.messageLen); + EXPECT_STREQ("msg!", entry.message); + }; + alignas(logger_entry) char buf[LOGGER_ENTRY_MAX_LEN]; + create_buf(buf, sizeof(buf), sizeof(logger_entry)); + + AndroidLogEntry entry_normal_size; + ASSERT_EQ(0, + android_log_processLogBuffer(reinterpret_cast(buf), &entry_normal_size)); + check_entry(entry_normal_size); + + create_buf(buf, sizeof(buf), sizeof(logger_entry) + 3); + AndroidLogEntry entry_odd_size; + ASSERT_EQ(0, android_log_processLogBuffer(reinterpret_cast(buf), &entry_odd_size)); + check_entry(entry_odd_size); +} \ No newline at end of file diff --git a/logd/tests/logd_test.cpp b/logd/tests/logd_test.cpp index c7f348069..d57b79efc 100644 --- a/logd/tests/logd_test.cpp +++ b/logd/tests/logd_test.cpp @@ -246,7 +246,7 @@ static void dump_log_msg(const char* prefix, log_msg* msg, int lid) { std::cerr << std::flush; fflush(stdout); fflush(stderr); - EXPECT_EQ(sizeof(logger_entry), msg->entry.hdr_size); + EXPECT_GE(msg->entry.hdr_size, sizeof(logger_entry)); fprintf(stderr, "%s: [%u] ", prefix, msg->len()); fprintf(stderr, "hdr_size=%u ", msg->entry.hdr_size);