summaryrefslogtreecommitdiff
path: root/logd/LogBufferTest.cpp
diff options
context:
space:
mode:
authorBaligh Uddin <baligh@google.com>2020-10-08 23:17:52 +0000
committerBaligh Uddin <baligh@google.com>2020-10-08 23:17:52 +0000
commitd2c21a10d30e64a67ad9ccdbef4a551c3ec6aac4 (patch)
tree8104fbd8310d76d1a2d5cc95c270f0e9aa947c24 /logd/LogBufferTest.cpp
parent83e9bc346a90c77c28d68d7d0e969864dbc7c69b (diff)
Remove liblog, logcat, logd, logwrapper
These subdirectories have moved to platform/system/logging. BUG: 168791309 Test: Local build + TH Change-Id: Iaee2ff59d4450f3e59dc9ea8b0e257b2de53e478
Diffstat (limited to 'logd/LogBufferTest.cpp')
-rw-r--r--logd/LogBufferTest.cpp458
1 files changed, 0 insertions, 458 deletions
diff --git a/logd/LogBufferTest.cpp b/logd/LogBufferTest.cpp
deleted file mode 100644
index cb9f4284b..000000000
--- a/logd/LogBufferTest.cpp
+++ /dev/null
@@ -1,458 +0,0 @@
-/*
- * Copyright (C) 2020 The Android Open Source Project
- *
- * Licensed under the Apache License, Version 2.0 (the "License");
- * you may not use this file except in compliance with the License.
- * You may obtain a copy of the License at
- *
- * http://www.apache.org/licenses/LICENSE-2.0
- *
- * Unless required by applicable law or agreed to in writing, software
- * distributed under the License is distributed on an "AS IS" BASIS,
- * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
- * See the License for the specific language governing permissions and
- * limitations under the License.
- */
-
-#include "LogBufferTest.h"
-
-#include <unistd.h>
-
-#include <limits>
-#include <memory>
-#include <regex>
-#include <vector>
-
-#include <android-base/stringprintf.h>
-#include <android-base/strings.h>
-
-#include "LogBuffer.h"
-#include "LogReaderThread.h"
-#include "LogWriter.h"
-
-using android::base::Join;
-using android::base::Split;
-using android::base::StringPrintf;
-
-char* android::uidToName(uid_t) {
- return nullptr;
-}
-
-static std::vector<std::string> CompareLoggerEntries(const logger_entry& expected,
- const logger_entry& result, bool ignore_len) {
- std::vector<std::string> errors;
- if (!ignore_len && expected.len != result.len) {
- errors.emplace_back(
- StringPrintf("len: expected %" PRIu16 " vs %" PRIu16, expected.len, result.len));
- }
- if (expected.hdr_size != result.hdr_size) {
- errors.emplace_back(StringPrintf("hdr_size: %" PRIu16 " vs %" PRIu16, expected.hdr_size,
- result.hdr_size));
- }
- if (expected.pid != result.pid) {
- errors.emplace_back(
- StringPrintf("pid: expected %" PRIi32 " vs %" PRIi32, expected.pid, result.pid));
- }
- if (expected.tid != result.tid) {
- errors.emplace_back(
- StringPrintf("tid: expected %" PRIu32 " vs %" PRIu32, expected.tid, result.tid));
- }
- if (expected.sec != result.sec) {
- errors.emplace_back(
- StringPrintf("sec: expected %" PRIu32 " vs %" PRIu32, expected.sec, result.sec));
- }
- if (expected.nsec != result.nsec) {
- errors.emplace_back(
- StringPrintf("nsec: expected %" PRIu32 " vs %" PRIu32, expected.nsec, result.nsec));
- }
- if (expected.lid != result.lid) {
- errors.emplace_back(
- StringPrintf("lid: expected %" PRIu32 " vs %" PRIu32, expected.lid, result.lid));
- }
- if (expected.uid != result.uid) {
- errors.emplace_back(
- StringPrintf("uid: expected %" PRIu32 " vs %" PRIu32, expected.uid, result.uid));
- }
- return errors;
-}
-
-static std::string MakePrintable(std::string in) {
- if (in.size() > 80) {
- in = in.substr(0, 80) + "...";
- }
- std::string result;
- for (const char c : in) {
- if (isprint(c)) {
- result.push_back(c);
- } else {
- result.append(StringPrintf("\\%02x", static_cast<int>(c) & 0xFF));
- }
- }
- return result;
-}
-
-static std::string CompareMessages(const std::string& expected, const std::string& result) {
- if (expected == result) {
- return {};
- }
- size_t diff_index = 0;
- for (; diff_index < std::min(expected.size(), result.size()); ++diff_index) {
- if (expected[diff_index] != result[diff_index]) {
- break;
- }
- }
-
- if (diff_index < 80) {
- auto expected_short = MakePrintable(expected);
- auto result_short = MakePrintable(result);
- return StringPrintf("msg: expected '%s' vs '%s'", expected_short.c_str(),
- result_short.c_str());
- }
-
- auto expected_short = MakePrintable(expected.substr(diff_index));
- auto result_short = MakePrintable(result.substr(diff_index));
- return StringPrintf("msg: index %zu: expected '%s' vs '%s'", diff_index, expected_short.c_str(),
- result_short.c_str());
-}
-
-static std::string CompareRegexMessages(const std::string& expected, const std::string& result) {
- auto expected_pieces = Split(expected, std::string("\0", 1));
- auto result_pieces = Split(result, std::string("\0", 1));
-
- if (expected_pieces.size() != 3 || result_pieces.size() != 3) {
- return StringPrintf(
- "msg: should have 3 null delimited strings found %d in expected, %d in result: "
- "'%s' vs '%s'",
- static_cast<int>(expected_pieces.size()), static_cast<int>(result_pieces.size()),
- MakePrintable(expected).c_str(), MakePrintable(result).c_str());
- }
- if (expected_pieces[0] != result_pieces[0]) {
- return StringPrintf("msg: tag/priority mismatch expected '%s' vs '%s'",
- MakePrintable(expected_pieces[0]).c_str(),
- MakePrintable(result_pieces[0]).c_str());
- }
- std::regex expected_tag_regex(expected_pieces[1]);
- if (!std::regex_search(result_pieces[1], expected_tag_regex)) {
- return StringPrintf("msg: message regex mismatch expected '%s' vs '%s'",
- MakePrintable(expected_pieces[1]).c_str(),
- MakePrintable(result_pieces[1]).c_str());
- }
- if (expected_pieces[2] != result_pieces[2]) {
- return StringPrintf("msg: nothing expected after final null character '%s' vs '%s'",
- MakePrintable(expected_pieces[2]).c_str(),
- MakePrintable(result_pieces[2]).c_str());
- }
- return {};
-}
-
-void CompareLogMessages(const std::vector<LogMessage>& expected,
- const std::vector<LogMessage>& result) {
- EXPECT_EQ(expected.size(), result.size());
- size_t end = std::min(expected.size(), result.size());
- size_t num_errors = 0;
- for (size_t i = 0; i < end; ++i) {
- auto errors =
- CompareLoggerEntries(expected[i].entry, result[i].entry, expected[i].regex_compare);
- auto msg_error = expected[i].regex_compare
- ? CompareRegexMessages(expected[i].message, result[i].message)
- : CompareMessages(expected[i].message, result[i].message);
- if (!msg_error.empty()) {
- errors.emplace_back(msg_error);
- }
- if (!errors.empty()) {
- GTEST_LOG_(ERROR) << "Mismatch log message " << i << "\n" << Join(errors, "\n");
- ++num_errors;
- }
- }
- EXPECT_EQ(0U, num_errors);
-}
-
-void FixupMessages(std::vector<LogMessage>* messages) {
- for (auto& [entry, message, _] : *messages) {
- entry.hdr_size = sizeof(logger_entry);
- entry.len = message.size();
- }
-}
-
-TEST_P(LogBufferTest, smoke) {
- std::vector<LogMessage> log_messages = {
- {{
- .pid = 1,
- .tid = 1,
- .sec = 1234,
- .nsec = 323001,
- .lid = LOG_ID_MAIN,
- .uid = 0,
- },
- "smoke test"},
- };
- FixupMessages(&log_messages);
- LogMessages(log_messages);
-
- std::vector<LogMessage> read_log_messages;
- {
- auto lock = std::lock_guard{logd_lock};
- std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, nullptr));
- std::unique_ptr<FlushToState> flush_to_state =
- log_buffer_->CreateFlushToState(1, kLogMaskAll);
- EXPECT_TRUE(log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr));
- EXPECT_EQ(2ULL, flush_to_state->start());
- }
- CompareLogMessages(log_messages, read_log_messages);
-}
-
-TEST_P(LogBufferTest, smoke_with_reader_thread) {
- std::vector<LogMessage> log_messages = {
- {{.pid = 1, .tid = 2, .sec = 10000, .nsec = 20001, .lid = LOG_ID_MAIN, .uid = 0},
- "first"},
- {{.pid = 10, .tid = 2, .sec = 10000, .nsec = 20002, .lid = LOG_ID_MAIN, .uid = 0},
- "second"},
- {{.pid = 100, .tid = 2, .sec = 10000, .nsec = 20003, .lid = LOG_ID_KERNEL, .uid = 0},
- "third"},
- {{.pid = 10, .tid = 2, .sec = 10000, .nsec = 20004, .lid = LOG_ID_MAIN, .uid = 0},
- "fourth"},
- {{.pid = 1, .tid = 2, .sec = 10000, .nsec = 20005, .lid = LOG_ID_RADIO, .uid = 0},
- "fifth"},
- {{.pid = 2, .tid = 2, .sec = 10000, .nsec = 20006, .lid = LOG_ID_RADIO, .uid = 0},
- "sixth"},
- {{.pid = 3, .tid = 2, .sec = 10000, .nsec = 20007, .lid = LOG_ID_RADIO, .uid = 0},
- "seventh"},
- {{.pid = 4, .tid = 2, .sec = 10000, .nsec = 20008, .lid = LOG_ID_MAIN, .uid = 0},
- "eighth"},
- {{.pid = 5, .tid = 2, .sec = 10000, .nsec = 20009, .lid = LOG_ID_CRASH, .uid = 0},
- "nineth"},
- {{.pid = 6, .tid = 2, .sec = 10000, .nsec = 20011, .lid = LOG_ID_MAIN, .uid = 0},
- "tenth"},
- };
- FixupMessages(&log_messages);
- LogMessages(log_messages);
-
- std::vector<LogMessage> read_log_messages;
- bool released = false;
-
- {
- auto lock = std::lock_guard{logd_lock};
- std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, &released));
- std::unique_ptr<LogReaderThread> log_reader(
- new LogReaderThread(log_buffer_.get(), &reader_list_, std::move(test_writer), true,
- 0, kLogMaskAll, 0, {}, 1, {}));
- reader_list_.reader_threads().emplace_back(std::move(log_reader));
- }
-
- while (!released) {
- usleep(5000);
- }
- {
- auto lock = std::lock_guard{logd_lock};
- EXPECT_EQ(0U, reader_list_.reader_threads().size());
- }
- CompareLogMessages(log_messages, read_log_messages);
-}
-
-// Generate random messages, set the 'sec' parameter explicit though, to be able to track the
-// expected order of messages.
-LogMessage GenerateRandomLogMessage(uint32_t sec) {
- auto rand_uint32 = [](int max) -> uint32_t { return rand() % max; };
- logger_entry entry = {
- .hdr_size = sizeof(logger_entry),
- .pid = rand() % 5000,
- .tid = rand_uint32(5000),
- .sec = sec,
- .nsec = rand_uint32(NS_PER_SEC),
- .lid = rand_uint32(LOG_ID_STATS),
- .uid = rand_uint32(100000),
- };
-
- // See comment in ChattyLogBuffer::Log() for why this is disallowed.
- if (entry.nsec % 1000 == 0) {
- ++entry.nsec;
- }
-
- if (entry.lid == LOG_ID_EVENTS) {
- entry.lid = LOG_ID_KERNEL;
- }
-
- std::string message;
- char priority = ANDROID_LOG_INFO + rand() % 2;
- message.push_back(priority);
-
- int tag_length = 2 + rand() % 10;
- for (int i = 0; i < tag_length; ++i) {
- message.push_back('a' + rand() % 26);
- }
- message.push_back('\0');
-
- int msg_length = 2 + rand() % 1000;
- for (int i = 0; i < msg_length; ++i) {
- message.push_back('a' + rand() % 26);
- }
- message.push_back('\0');
-
- entry.len = message.size();
-
- return {entry, message};
-}
-
-TEST_P(LogBufferTest, random_messages) {
- srand(1);
- std::vector<LogMessage> log_messages;
- for (size_t i = 0; i < 1000; ++i) {
- log_messages.emplace_back(GenerateRandomLogMessage(i));
- }
- LogMessages(log_messages);
-
- std::vector<LogMessage> read_log_messages;
- bool released = false;
-
- {
- auto lock = std::lock_guard{logd_lock};
- std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, &released));
- std::unique_ptr<LogReaderThread> log_reader(
- new LogReaderThread(log_buffer_.get(), &reader_list_, std::move(test_writer), true,
- 0, kLogMaskAll, 0, {}, 1, {}));
- reader_list_.reader_threads().emplace_back(std::move(log_reader));
- }
-
- while (!released) {
- usleep(5000);
- }
- {
- auto lock = std::lock_guard{logd_lock};
- EXPECT_EQ(0U, reader_list_.reader_threads().size());
- }
- CompareLogMessages(log_messages, read_log_messages);
-}
-
-TEST_P(LogBufferTest, read_last_sequence) {
- std::vector<LogMessage> log_messages = {
- {{.pid = 1, .tid = 2, .sec = 10000, .nsec = 20001, .lid = LOG_ID_MAIN, .uid = 0},
- "first"},
- {{.pid = 10, .tid = 2, .sec = 10000, .nsec = 20002, .lid = LOG_ID_MAIN, .uid = 0},
- "second"},
- {{.pid = 100, .tid = 2, .sec = 10000, .nsec = 20003, .lid = LOG_ID_MAIN, .uid = 0},
- "third"},
- };
- FixupMessages(&log_messages);
- LogMessages(log_messages);
-
- std::vector<LogMessage> read_log_messages;
- bool released = false;
-
- {
- auto lock = std::lock_guard{logd_lock};
- std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, &released));
- std::unique_ptr<LogReaderThread> log_reader(
- new LogReaderThread(log_buffer_.get(), &reader_list_, std::move(test_writer), true,
- 0, kLogMaskAll, 0, {}, 3, {}));
- reader_list_.reader_threads().emplace_back(std::move(log_reader));
- }
-
- while (!released) {
- usleep(5000);
- }
- {
- auto lock = std::lock_guard{logd_lock};
- EXPECT_EQ(0U, reader_list_.reader_threads().size());
- }
- std::vector<LogMessage> expected_log_messages = {log_messages.back()};
- CompareLogMessages(expected_log_messages, read_log_messages);
-}
-
-TEST_P(LogBufferTest, clear_logs) {
- // Log 3 initial logs.
- std::vector<LogMessage> log_messages = {
- {{.pid = 1, .tid = 2, .sec = 10000, .nsec = 20001, .lid = LOG_ID_MAIN, .uid = 0},
- "first"},
- {{.pid = 10, .tid = 2, .sec = 10000, .nsec = 20002, .lid = LOG_ID_MAIN, .uid = 0},
- "second"},
- {{.pid = 100, .tid = 2, .sec = 10000, .nsec = 20003, .lid = LOG_ID_MAIN, .uid = 0},
- "third"},
- };
- FixupMessages(&log_messages);
- LogMessages(log_messages);
-
- std::vector<LogMessage> read_log_messages;
- bool released = false;
-
- // Connect a blocking reader.
- {
- auto lock = std::lock_guard{logd_lock};
- std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, &released));
- std::unique_ptr<LogReaderThread> log_reader(
- new LogReaderThread(log_buffer_.get(), &reader_list_, std::move(test_writer), false,
- 0, kLogMaskAll, 0, {}, 1, {}));
- reader_list_.reader_threads().emplace_back(std::move(log_reader));
- }
-
- // Wait up to 250ms for the reader to read the first 3 logs.
- constexpr int kMaxRetryCount = 50;
- int count = 0;
- for (; count < kMaxRetryCount; ++count) {
- usleep(5000);
- auto lock = std::lock_guard{logd_lock};
- if (reader_list_.reader_threads().back()->start() == 4) {
- break;
- }
- }
- ASSERT_LT(count, kMaxRetryCount);
-
- // Clear the log buffer.
- log_buffer_->Clear(LOG_ID_MAIN, 0);
-
- // Log 3 more logs.
- std::vector<LogMessage> after_clear_messages = {
- {{.pid = 1, .tid = 2, .sec = 10000, .nsec = 20001, .lid = LOG_ID_MAIN, .uid = 0},
- "4th"},
- {{.pid = 10, .tid = 2, .sec = 10000, .nsec = 20002, .lid = LOG_ID_MAIN, .uid = 0},
- "5th"},
- {{.pid = 100, .tid = 2, .sec = 10000, .nsec = 20003, .lid = LOG_ID_MAIN, .uid = 0},
- "6th"},
- };
- FixupMessages(&after_clear_messages);
- LogMessages(after_clear_messages);
-
- // Wait up to 250ms for the reader to read the 3 additional logs.
- for (count = 0; count < kMaxRetryCount; ++count) {
- usleep(5000);
- auto lock = std::lock_guard{logd_lock};
- if (reader_list_.reader_threads().back()->start() == 7) {
- break;
- }
- }
- ASSERT_LT(count, kMaxRetryCount);
-
- // Release the reader, wait for it to get the signal then check that it has been deleted.
- {
- auto lock = std::lock_guard{logd_lock};
- reader_list_.reader_threads().back()->Release();
- }
- while (!released) {
- usleep(5000);
- }
- {
- auto lock = std::lock_guard{logd_lock};
- EXPECT_EQ(0U, reader_list_.reader_threads().size());
- }
-
- // Check that we have read all 6 messages.
- std::vector<LogMessage> expected_log_messages = log_messages;
- expected_log_messages.insert(expected_log_messages.end(), after_clear_messages.begin(),
- after_clear_messages.end());
- CompareLogMessages(expected_log_messages, read_log_messages);
-
- // Finally, call FlushTo and ensure that only the 3 logs after the clear remain in the buffer.
- std::vector<LogMessage> read_log_messages_after_clear;
- {
- auto lock = std::lock_guard{logd_lock};
- std::unique_ptr<LogWriter> test_writer(
- new TestWriter(&read_log_messages_after_clear, nullptr));
- std::unique_ptr<FlushToState> flush_to_state =
- log_buffer_->CreateFlushToState(1, kLogMaskAll);
- EXPECT_TRUE(log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr));
- EXPECT_EQ(7ULL, flush_to_state->start());
- }
- CompareLogMessages(after_clear_messages, read_log_messages_after_clear);
-}
-
-INSTANTIATE_TEST_CASE_P(LogBufferTests, LogBufferTest,
- testing::Values("chatty", "serialized", "simple"));