Merge "logd: add a test for clearing logs with a reader present" am: 8d3265539b (00636fb0) · Commits · e / os / android_system_core

logd/LogBufferTest.cpp

+95 −3

Original line number	Diff line number	Diff line
		@@ -26,6 +26,7 @@
		#include <android-base/stringprintf.h>
		#include <android-base/strings.h>

		#include "LogBuffer.h"
		#include "LogReaderThread.h"
		#include "LogWriter.h"

		@@ -240,7 +241,7 @@ TEST_P(LogBufferTest, smoke_with_reader_thread) {
		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, ~0, 0, {}, 1, {}));
		0, kLogMaskAll, 0, {}, 1, {}));
		reader_list_.reader_threads().emplace_back(std::move(log_reader));
		}

		@@ -314,7 +315,7 @@ TEST_P(LogBufferTest, random_messages) {
		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, ~0, 0, {}, 1, {}));
		0, kLogMaskAll, 0, {}, 1, {}));
		reader_list_.reader_threads().emplace_back(std::move(log_reader));
		}

		@@ -348,7 +349,7 @@ TEST_P(LogBufferTest, read_last_sequence) {
		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, ~0, 0, {}, 3, {}));
		0, kLogMaskAll, 0, {}, 3, {}));
		reader_list_.reader_threads().emplace_back(std::move(log_reader));
		}

		@@ -363,4 +364,95 @@ TEST_P(LogBufferTest, read_last_sequence) {
		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::unique_lock{reader_list_.reader_threads_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::unique_lock{reader_list_.reader_threads_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::unique_lock{reader_list_.reader_threads_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::unique_lock{reader_list_.reader_threads_lock()};
		reader_list_.reader_threads().back()->release_Locked();
		}
		while (!released) {
		usleep(5000);
		}
		{
		auto lock = std::unique_lock{reader_list_.reader_threads_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;
		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", "simple"));