Merge "logd: replay the entire log when UID clearing"
diff --git a/logd/Android.bp b/logd/Android.bp
index 6306c73..6f23808 100644
--- a/logd/Android.bp
+++ b/logd/Android.bp
@@ -153,6 +153,7 @@
"ChattyLogBufferTest.cpp",
"logd_test.cpp",
"LogBufferTest.cpp",
+ "SerializedLogBufferTest.cpp",
"SerializedLogChunkTest.cpp",
"SerializedFlushToStateTest.cpp",
],
diff --git a/logd/SerializedLogBuffer.cpp b/logd/SerializedLogBuffer.cpp
index 7446813..0101c17 100644
--- a/logd/SerializedLogBuffer.cpp
+++ b/logd/SerializedLogBuffer.cpp
@@ -27,6 +27,70 @@
#include "LogStatistics.h"
#include "SerializedFlushToState.h"
+static SerializedLogEntry* LogToLogBuffer(std::list<SerializedLogChunk>& log_buffer,
+ size_t max_size, uint64_t sequence, log_time realtime,
+ uid_t uid, pid_t pid, pid_t tid, const char* msg,
+ uint16_t len) {
+ if (log_buffer.empty()) {
+ log_buffer.push_back(SerializedLogChunk(max_size / SerializedLogBuffer::kChunkSizeDivisor));
+ }
+
+ auto total_len = sizeof(SerializedLogEntry) + len;
+ if (!log_buffer.back().CanLog(total_len)) {
+ log_buffer.back().FinishWriting();
+ log_buffer.push_back(SerializedLogChunk(max_size / SerializedLogBuffer::kChunkSizeDivisor));
+ }
+
+ return log_buffer.back().Log(sequence, realtime, uid, pid, tid, msg, len);
+}
+
+// Clear all logs from a particular UID by iterating through all existing logs for a log_id, and
+// write all logs that don't match the UID into a new log buffer, then swapping the log buffers.
+// There is an optimization that chunks are copied as-is until a log message from the UID is found,
+// to ensure that back-to-back clears of the same UID do not require reflowing the entire buffer.
+void ClearLogsByUid(std::list<SerializedLogChunk>& log_buffer, uid_t uid, size_t max_size,
+ log_id_t log_id, LogStatistics* stats) REQUIRES(logd_lock) {
+ bool contains_uid_logs = false;
+ std::list<SerializedLogChunk> new_logs;
+ auto it = log_buffer.begin();
+ while (it != log_buffer.end()) {
+ auto chunk = it++;
+ chunk->NotifyReadersOfPrune(log_id);
+ chunk->IncReaderRefCount();
+
+ if (!contains_uid_logs) {
+ for (const auto& entry : *chunk) {
+ if (entry.uid() == uid) {
+ contains_uid_logs = true;
+ break;
+ }
+ }
+ if (!contains_uid_logs) {
+ chunk->DecReaderRefCount();
+ new_logs.splice(new_logs.end(), log_buffer, chunk);
+ continue;
+ }
+ // We found a UID log, so push a writable chunk to prepare for the next loop.
+ new_logs.push_back(
+ SerializedLogChunk(max_size / SerializedLogBuffer::kChunkSizeDivisor));
+ }
+
+ for (const auto& entry : *chunk) {
+ if (entry.uid() == uid) {
+ if (stats != nullptr) {
+ stats->Subtract(entry.ToLogStatisticsElement(log_id));
+ }
+ } else {
+ LogToLogBuffer(new_logs, max_size, entry.sequence(), entry.realtime(), entry.uid(),
+ entry.pid(), entry.tid(), entry.msg(), entry.msg_len());
+ }
+ }
+ chunk->DecReaderRefCount();
+ log_buffer.erase(chunk);
+ }
+ std::swap(new_logs, log_buffer);
+}
+
SerializedLogBuffer::SerializedLogBuffer(LogReaderList* reader_list, LogTags* tags,
LogStatistics* stats)
: reader_list_(reader_list), tags_(tags), stats_(stats) {
@@ -87,18 +151,8 @@
auto sequence = sequence_.fetch_add(1, std::memory_order_relaxed);
auto lock = std::lock_guard{logd_lock};
-
- if (logs_[log_id].empty()) {
- logs_[log_id].push_back(SerializedLogChunk(max_size_[log_id] / 4));
- }
-
- auto total_len = sizeof(SerializedLogEntry) + len;
- if (!logs_[log_id].back().CanLog(total_len)) {
- logs_[log_id].back().FinishWriting();
- logs_[log_id].push_back(SerializedLogChunk(max_size_[log_id] / 4));
- }
-
- auto entry = logs_[log_id].back().Log(sequence, realtime, uid, pid, tid, msg, len);
+ auto entry = LogToLogBuffer(logs_[log_id], max_size_[log_id], sequence, realtime, uid, pid, tid,
+ msg, len);
stats_->Add(entry->ToLogStatisticsElement(log_id));
MaybePrune(log_id);
@@ -111,7 +165,7 @@
size_t total_size = GetSizeUsed(log_id);
size_t after_size = total_size;
if (total_size > max_size_[log_id]) {
- Prune(log_id, total_size - max_size_[log_id], 0);
+ Prune(log_id, total_size - max_size_[log_id]);
after_size = GetSizeUsed(log_id);
LOG(VERBOSE) << "Pruned Logs from log_id: " << log_id << ", previous size: " << total_size
<< " after size: " << after_size;
@@ -122,16 +176,13 @@
void SerializedLogBuffer::RemoveChunkFromStats(log_id_t log_id, SerializedLogChunk& chunk) {
chunk.IncReaderRefCount();
- int read_offset = 0;
- while (read_offset < chunk.write_offset()) {
- auto* entry = chunk.log_entry(read_offset);
- stats_->Subtract(entry->ToLogStatisticsElement(log_id));
- read_offset += entry->total_len();
+ for (const auto& entry : chunk) {
+ stats_->Subtract(entry.ToLogStatisticsElement(log_id));
}
chunk.DecReaderRefCount();
}
-void SerializedLogBuffer::Prune(log_id_t log_id, size_t bytes_to_free, uid_t uid) {
+void SerializedLogBuffer::Prune(log_id_t log_id, size_t bytes_to_free) {
auto& log_buffer = logs_[log_id];
auto it = log_buffer.begin();
while (it != log_buffer.end()) {
@@ -168,22 +219,28 @@
// Notify them to delete the reference.
it_to_prune->NotifyReadersOfPrune(log_id);
- if (uid != 0) {
- // Reorder the log buffer to remove logs from the given UID. If there are no logs left
- // in the buffer after the removal, delete it.
- if (it_to_prune->ClearUidLogs(uid, log_id, stats_)) {
- log_buffer.erase(it_to_prune);
- }
- } else {
- size_t buffer_size = it_to_prune->PruneSize();
- RemoveChunkFromStats(log_id, *it_to_prune);
- log_buffer.erase(it_to_prune);
- if (buffer_size >= bytes_to_free) {
- return;
- }
- bytes_to_free -= buffer_size;
+ size_t buffer_size = it_to_prune->PruneSize();
+ RemoveChunkFromStats(log_id, *it_to_prune);
+ log_buffer.erase(it_to_prune);
+ if (buffer_size >= bytes_to_free) {
+ return;
+ }
+ bytes_to_free -= buffer_size;
+ }
+}
+
+void SerializedLogBuffer::UidClear(log_id_t log_id, uid_t uid) {
+ // Wake all readers; see comment in Prune().
+ for (const auto& reader_thread : reader_list_->reader_threads()) {
+ if (!reader_thread->IsWatching(log_id)) {
+ continue;
+ }
+
+ if (reader_thread->deadline().time_since_epoch().count() != 0) {
+ reader_thread->TriggerReader();
}
}
+ ClearLogsByUid(logs_[log_id], uid, max_size_[log_id], log_id, stats_);
}
std::unique_ptr<FlushToState> SerializedLogBuffer::CreateFlushToState(uint64_t start,
@@ -243,7 +300,11 @@
bool SerializedLogBuffer::Clear(log_id_t id, uid_t uid) {
auto lock = std::lock_guard{logd_lock};
- Prune(id, ULONG_MAX, uid);
+ if (uid == 0) {
+ Prune(id, ULONG_MAX);
+ } else {
+ UidClear(id, uid);
+ }
// Clearing SerializedLogBuffer never waits for readers and therefore is always successful.
return true;
diff --git a/logd/SerializedLogBuffer.h b/logd/SerializedLogBuffer.h
index 4ce7a3b..ca78c42 100644
--- a/logd/SerializedLogBuffer.h
+++ b/logd/SerializedLogBuffer.h
@@ -36,6 +36,9 @@
class SerializedLogBuffer final : public LogBuffer {
public:
+ // Create SerializedLogChunk's with size = max_size_[log_id] / kChunkSizeDivisor.
+ static constexpr size_t kChunkSizeDivisor = 4;
+
SerializedLogBuffer(LogReaderList* reader_list, LogTags* tags, LogStatistics* stats);
void Init() override;
@@ -57,7 +60,8 @@
private:
bool ShouldLog(log_id_t log_id, const char* msg, uint16_t len);
void MaybePrune(log_id_t log_id) REQUIRES(logd_lock);
- void Prune(log_id_t log_id, size_t bytes_to_free, uid_t uid) REQUIRES(logd_lock);
+ void Prune(log_id_t log_id, size_t bytes_to_free) REQUIRES(logd_lock);
+ void UidClear(log_id_t log_id, uid_t uid) REQUIRES(logd_lock);
void RemoveChunkFromStats(log_id_t log_id, SerializedLogChunk& chunk);
size_t GetSizeUsed(log_id_t id) REQUIRES(logd_lock);
@@ -70,3 +74,7 @@
std::atomic<uint64_t> sequence_ = 1;
};
+
+// Exposed for testing.
+void ClearLogsByUid(std::list<SerializedLogChunk>& log_buffer, uid_t uid, size_t max_size,
+ log_id_t log_id, LogStatistics* stats);
\ No newline at end of file
diff --git a/logd/SerializedLogBufferTest.cpp b/logd/SerializedLogBufferTest.cpp
new file mode 100644
index 0000000..dbbe2f2
--- /dev/null
+++ b/logd/SerializedLogBufferTest.cpp
@@ -0,0 +1,398 @@
+/*
+ * Copyright (C) 2021 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 "SerializedLogBuffer.h"
+
+#include <gtest/gtest.h>
+#include <log/log.h>
+
+#include "LogReaderList.h"
+#include "LogSize.h"
+#include "LogStatistics.h"
+#include "LogTags.h"
+#include "SerializedLogChunk.h"
+#include "SerializedLogEntry.h"
+
+// b/188858988 - Previously, if clearing UID logs erased the back-most chunk, then a chunk that has
+// previously been closed for writing will be the back-most chunk in the list. Subsequent calls to
+// SerializedLogBuffer::Log() will call SerializedLogChunk::FinishWriting(), which triggered a
+// CHECK().
+TEST(SerializedLogBuffer, uid_prune_deletes_last_chunk) {
+ LogReaderList reader_list;
+ LogTags tags;
+ LogStatistics stats(false, true);
+ SerializedLogBuffer log_buffer(&reader_list, &tags, &stats);
+
+ log_buffer.SetSize(LOG_ID_MAIN, kLogBufferMinSize);
+ log_buffer.Clear(LOG_ID_MAIN, 0);
+
+ const uid_t kNonClearUid = 123;
+ const std::string kDontClearMessage = "this message is not cleared";
+ log_buffer.Log(LOG_ID_MAIN, log_time(0, 1), kNonClearUid, 1, 1, kDontClearMessage.data(),
+ kDontClearMessage.size());
+
+ // Fill at least one chunk with a message with the UID that we'll clear
+ const uid_t kClearUid = 555;
+ const std::string kClearMessage(1024, 'c');
+ size_t size_written = 0;
+ while (size_written < kLogBufferMinSize / 2) {
+ log_buffer.Log(LOG_ID_MAIN, log_time(1, size_written), kClearUid, 1, 1,
+ kClearMessage.data(), kClearMessage.size());
+ size_written += kClearMessage.size();
+ }
+
+ log_buffer.Clear(LOG_ID_MAIN, kClearUid);
+
+ // This previously would trigger a CHECK() in SerializedLogChunk::FinishWriting().
+ log_buffer.Log(LOG_ID_MAIN, log_time(0, 2), kNonClearUid, 1, 1, kDontClearMessage.data(),
+ kDontClearMessage.size());
+}
+
+struct TestEntry {
+ uint32_t uid;
+ uint32_t pid;
+ uint32_t tid;
+ uint64_t sequence;
+ log_time realtime;
+ std::string msg;
+};
+
+SerializedLogChunk CreateChunk(size_t max_size, const std::vector<TestEntry>& entries,
+ bool finish_writing) {
+ SerializedLogChunk chunk(max_size / SerializedLogBuffer::kChunkSizeDivisor);
+
+ for (const auto& entry : entries) {
+ if (!chunk.CanLog(sizeof(SerializedLogEntry) + entry.msg.size())) {
+ EXPECT_TRUE(false) << "Test set up failure, entries don't fit in chunks";
+ return chunk;
+ }
+ chunk.Log(entry.sequence, entry.realtime, entry.uid, entry.pid, entry.tid, entry.msg.data(),
+ entry.msg.size());
+ }
+ if (finish_writing) {
+ chunk.FinishWriting();
+ }
+ return chunk;
+}
+
+void VerifyChunks(const std::list<SerializedLogChunk>& expected,
+ const std::list<SerializedLogChunk>& chunks) {
+ int chunk = 0;
+ auto expected_it = expected.begin();
+ auto it = chunks.begin();
+ for (; expected_it != expected.end() && it != chunks.end(); ++expected_it, ++it, ++chunk) {
+ EXPECT_EQ(expected_it->reader_ref_count_, it->reader_ref_count_) << "chunk #" << chunk;
+ EXPECT_EQ(expected_it->writer_active_, it->writer_active_) << "chunk #" << chunk;
+ EXPECT_EQ(expected_it->highest_sequence_number_, it->highest_sequence_number_)
+ << "chunk #" << chunk;
+ EXPECT_EQ(expected_it->readers_, it->readers_) << "chunk #" << chunk;
+
+ ASSERT_EQ(expected_it->contents_.size(), it->contents_.size()) << "chunk #" << chunk;
+ ASSERT_EQ(expected_it->write_offset_, it->write_offset_) << "chunk #" << chunk;
+ if (expected_it->contents_.size() > 0) {
+ for (int i = 0; i < it->write_offset_; ++i) {
+ EXPECT_EQ(expected_it->contents_.data()[i], it->contents_.data()[i])
+ << "chunk #" << chunk;
+ }
+ }
+
+ ASSERT_EQ(expected_it->compressed_log_.size(), it->compressed_log_.size())
+ << "chunk #" << chunk;
+ if (expected_it->compressed_log_.size() > 0) {
+ for (size_t i = 0; i < it->compressed_log_.size(); ++i) {
+ EXPECT_EQ(expected_it->compressed_log_.data()[i], it->compressed_log_.data()[i])
+ << "chunk #" << chunk;
+ }
+ }
+ }
+ EXPECT_EQ(expected.end(), expected_it);
+ EXPECT_EQ(chunks.end(), it);
+}
+
+// If no blocks are present before ClearLogsByUid() then no blocks should be output.
+TEST(SerializedLogBuffer, uid_prune_no_blocks) {
+ const uid_t kClearUid = 555;
+ const size_t kMaxSize = kLogBufferMinSize;
+
+ std::list<SerializedLogChunk> chunks;
+ std::list<SerializedLogChunk> expected_chunks;
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
+
+// If no UIDs to be cleared are found, then the _same exact_ block is returned.
+TEST(SerializedLogBuffer, uid_prune_one_block_no_uid) {
+ const uid_t kNonClearUid = 123;
+ const uid_t kClearUid = 555;
+ const size_t kMaxSize = kLogBufferMinSize;
+
+ std::vector<TestEntry> entries = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = "some message"},
+ };
+
+ std::list<SerializedLogChunk> chunks;
+ chunks.emplace_back(CreateChunk(kMaxSize, entries, false));
+ void* original_chunk_address = reinterpret_cast<void*>(&chunks.front());
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.push_back(CreateChunk(kMaxSize, entries, false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+ void* after_clear_chunk_address = reinterpret_cast<void*>(&chunks.front());
+ EXPECT_EQ(original_chunk_address, after_clear_chunk_address);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+ after_clear_chunk_address = reinterpret_cast<void*>(&chunks.front());
+ EXPECT_EQ(original_chunk_address, after_clear_chunk_address);
+}
+
+std::vector<TestEntry> FilterEntries(const std::vector<TestEntry>& entries, uid_t uid_to_remove) {
+ std::vector<TestEntry> filtered_entries;
+ for (const auto& entry : entries) {
+ if (entry.uid == uid_to_remove) {
+ continue;
+ }
+ filtered_entries.emplace_back(entry);
+ }
+ return filtered_entries;
+}
+
+TEST(SerializedLogBuffer, uid_prune_one_block_some_uid) {
+ const uid_t kNonClearUid = 123;
+ const uid_t kClearUid = 555;
+ const size_t kMaxSize = kLogBufferMinSize;
+
+ std::list<SerializedLogChunk> chunks;
+ std::vector<TestEntry> entries = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = "some message"},
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 2,
+ .realtime = log_time(0, 1),
+ .msg = "some cleared message"},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries, false));
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, FilterEntries(entries, kClearUid), false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
+
+TEST(SerializedLogBuffer, uid_prune_one_block_all_uid) {
+ const uid_t kClearUid = 555;
+ const size_t kMaxSize = kLogBufferMinSize;
+
+ std::list<SerializedLogChunk> chunks;
+ std::vector<TestEntry> entries = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = "some message"},
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 2,
+ .realtime = log_time(0, 1),
+ .msg = "some cleared message"},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries, false));
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, {}, false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
+
+TEST(SerializedLogBuffer, uid_prune_first_middle_last_chunks) {
+ const uid_t kNonClearUid = 123;
+ const uid_t kClearUid = 555;
+ const std::string kMsg = "constant log message";
+ const size_t kMaxSize =
+ (sizeof(SerializedLogEntry) + kMsg.size()) * SerializedLogBuffer::kChunkSizeDivisor;
+
+ std::list<SerializedLogChunk> chunks;
+ std::vector<TestEntry> entries0 = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries0, true));
+ std::vector<TestEntry> entries1 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 2,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries1, true));
+ std::vector<TestEntry> entries2 = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 3,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries2, true));
+ std::vector<TestEntry> entries3 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 4,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries3, true));
+ std::vector<TestEntry> entries4 = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 5,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries4, false));
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, entries1, true));
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, entries3, false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
+
+TEST(SerializedLogBuffer, uid_prune_coalesce) {
+ const uid_t kNonClearUid = 123;
+ const uid_t kClearUid = 555;
+ const std::string kMsg = "constant log message";
+ const size_t kMaxSize =
+ (sizeof(SerializedLogEntry) + kMsg.size()) * SerializedLogBuffer::kChunkSizeDivisor * 2;
+
+ std::list<SerializedLogChunk> chunks;
+ std::vector<TestEntry> entries0 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 2,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries0, true));
+ std::vector<TestEntry> entries1 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 3,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 4,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries1, true));
+ std::vector<TestEntry> entries2 = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 5,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 6,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries2, true));
+ std::vector<TestEntry> entries3 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 7,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 8,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries3, false));
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, entries0, true));
+
+ std::vector<TestEntry> expected_entries_1;
+ expected_entries_1.emplace_back(entries1[0]);
+ expected_entries_1.emplace_back(entries3[0]);
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, expected_entries_1, true));
+
+ std::vector<TestEntry> expected_entries_2;
+ expected_entries_2.emplace_back(entries3[1]);
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, expected_entries_2, false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
diff --git a/logd/SerializedLogChunk.cpp b/logd/SerializedLogChunk.cpp
index a512bf3..e6b4f50 100644
--- a/logd/SerializedLogChunk.cpp
+++ b/logd/SerializedLogChunk.cpp
@@ -25,12 +25,16 @@
CHECK_EQ(reader_ref_count_, 0U);
}
-void SerializedLogChunk::Compress() {
+void SerializedLogChunk::FinishWriting() {
+ writer_active_ = false;
CHECK_EQ(compressed_log_.size(), 0U);
CompressionEngine::GetInstance().Compress(contents_, write_offset_, compressed_log_);
LOG(VERBOSE) << "Compressed Log, buffer max size: " << contents_.size()
<< " size used: " << write_offset_
<< " compressed size: " << compressed_log_.size();
+ if (reader_ref_count_ == 0) {
+ contents_.Resize(0);
+ }
}
// TODO: Develop a better reference counting strategy to guard against the case where the writer is
@@ -73,54 +77,6 @@
}
}
-bool SerializedLogChunk::ClearUidLogs(uid_t uid, log_id_t log_id, LogStatistics* stats) {
- CHECK_EQ(reader_ref_count_, 0U);
- if (write_offset_ == 0) {
- return true;
- }
-
- IncReaderRefCount();
-
- int read_offset = 0;
- int new_write_offset = 0;
- while (read_offset < write_offset_) {
- const auto* entry = log_entry(read_offset);
- if (entry->uid() == uid) {
- read_offset += entry->total_len();
- if (stats != nullptr) {
- stats->Subtract(entry->ToLogStatisticsElement(log_id));
- }
- continue;
- }
- size_t entry_total_len = entry->total_len();
- if (read_offset != new_write_offset) {
- memmove(contents_.data() + new_write_offset, contents_.data() + read_offset,
- entry_total_len);
- }
- read_offset += entry_total_len;
- new_write_offset += entry_total_len;
- }
-
- if (new_write_offset == 0) {
- DecReaderRefCount();
- return true;
- }
-
- // Clear the old compressed logs and set write_offset_ appropriately to compress the new
- // partially cleared log.
- if (new_write_offset != write_offset_) {
- write_offset_ = new_write_offset;
- if (!writer_active_) {
- compressed_log_.Resize(0);
- Compress();
- }
- }
-
- DecReaderRefCount();
-
- return false;
-}
-
bool SerializedLogChunk::CanLog(size_t len) {
return write_offset_ + len <= contents_.size();
}
diff --git a/logd/SerializedLogChunk.h b/logd/SerializedLogChunk.h
index 2318a2d..eb41674 100644
--- a/logd/SerializedLogChunk.h
+++ b/logd/SerializedLogChunk.h
@@ -18,6 +18,7 @@
#include <sys/types.h>
+#include <list>
#include <vector>
#include <android-base/logging.h>
@@ -31,11 +32,34 @@
class SerializedLogChunk {
public:
+ friend void VerifyChunks(const std::list<SerializedLogChunk>& expected,
+ const std::list<SerializedLogChunk>& chunks);
+
+ class LogEntryIterator {
+ public:
+ LogEntryIterator(SerializedLogChunk& chunk, int read_offset_)
+ : chunk_(chunk), read_offset_(read_offset_) {}
+
+ LogEntryIterator& operator++() {
+ read_offset_ += chunk_.log_entry(read_offset_)->total_len();
+ return *this;
+ }
+
+ bool operator!=(const LogEntryIterator& other) const {
+ return read_offset_ != other.read_offset_;
+ }
+ const SerializedLogEntry& operator*() const { return *chunk_.log_entry(read_offset_); }
+
+ private:
+ SerializedLogChunk& chunk_;
+ int read_offset_;
+ };
+
explicit SerializedLogChunk(size_t size) : contents_(size) {}
SerializedLogChunk(SerializedLogChunk&& other) noexcept = default;
~SerializedLogChunk();
- void Compress();
+ void FinishWriting();
void IncReaderRefCount();
void DecReaderRefCount();
void AttachReader(SerializedFlushToState* reader);
@@ -43,9 +67,6 @@
void NotifyReadersOfPrune(log_id_t log_id) REQUIRES(logd_lock);
- // Must have no readers referencing this. Return true if there are no logs left in this chunk.
- bool ClearUidLogs(uid_t uid, log_id_t log_id, LogStatistics* stats);
-
bool CanLog(size_t len);
SerializedLogEntry* Log(uint64_t sequence, log_time realtime, uid_t uid, pid_t pid, pid_t tid,
const char* msg, uint16_t len);
@@ -57,14 +78,6 @@
return sizeof(*this) + (compressed_log_.size() ?: contents_.size());
}
- void FinishWriting() {
- writer_active_ = false;
- Compress();
- if (reader_ref_count_ == 0) {
- contents_.Resize(0);
- }
- }
-
const SerializedLogEntry* log_entry(int offset) const {
CHECK(writer_active_ || reader_ref_count_ > 0);
return reinterpret_cast<const SerializedLogEntry*>(data() + offset);
@@ -73,6 +86,10 @@
int write_offset() const { return write_offset_; }
uint64_t highest_sequence_number() const { return highest_sequence_number_; }
+ LogEntryIterator begin() { return LogEntryIterator(*this, 0); }
+
+ LogEntryIterator end() { return LogEntryIterator(*this, write_offset_); }
+
// Exposed for testing
uint32_t reader_ref_count() const { return reader_ref_count_; }
diff --git a/logd/SerializedLogChunkTest.cpp b/logd/SerializedLogChunkTest.cpp
index d00ef5f..8e53365 100644
--- a/logd/SerializedLogChunkTest.cpp
+++ b/logd/SerializedLogChunkTest.cpp
@@ -115,192 +115,3 @@
EXPECT_DEATH({ chunk.DecReaderRefCount(); }, "");
}
-// Check that the CHECK() in ClearUidLogs() if the ref count is greater than 0 is caught.
-TEST_F(SerializedLogChunk_DeathTest, catch_ClearUidLogs_CHECK) {
- size_t chunk_size = 10 * 4096;
- auto chunk = SerializedLogChunk{chunk_size};
- chunk.IncReaderRefCount();
- EXPECT_DEATH({ chunk.ClearUidLogs(1000, LOG_ID_MAIN, nullptr); }, "");
- chunk.DecReaderRefCount();
-}
-
-class UidClearTest : public testing::TestWithParam<bool> {
- protected:
- template <typename Write, typename Check>
- void Test(const Write& write, const Check& check, bool expected_result) {
- write(chunk_);
-
- bool finish_writing = GetParam();
- if (finish_writing) {
- chunk_.FinishWriting();
- }
- EXPECT_EQ(expected_result, chunk_.ClearUidLogs(kUidToClear, LOG_ID_MAIN, nullptr));
- if (finish_writing) {
- chunk_.IncReaderRefCount();
- }
-
- check(chunk_);
-
- if (finish_writing) {
- chunk_.DecReaderRefCount();
- }
- }
-
- static constexpr size_t kChunkSize = 10 * 4096;
- static constexpr uid_t kUidToClear = 1000;
- static constexpr uid_t kOtherUid = 1234;
-
- SerializedLogChunk chunk_{kChunkSize};
-};
-
-// Test that ClearUidLogs() is a no-op if there are no logs of that UID in the buffer.
-TEST_P(UidClearTest, no_logs_in_chunk) {
- auto write = [](SerializedLogChunk&) {};
- auto check = [](SerializedLogChunk&) {};
-
- Test(write, check, true);
-}
-
-// Test that ClearUidLogs() is a no-op if there are no logs of that UID in the buffer.
-TEST_P(UidClearTest, no_logs_from_uid) {
- static const char msg[] = "this is a log message";
- auto write = [](SerializedLogChunk& chunk) {
- chunk.Log(1, log_time(), kOtherUid, 1, 2, msg, sizeof(msg));
- };
-
- auto check = [](SerializedLogChunk& chunk) {
- auto* entry = chunk.log_entry(0);
- EXPECT_STREQ(msg, entry->msg());
- };
-
- Test(write, check, false);
-}
-
-// Test that ClearUidLogs() returns true if all logs in a given buffer correspond to the given UID.
-TEST_P(UidClearTest, all_single) {
- static const char msg[] = "this is a log message";
- auto write = [](SerializedLogChunk& chunk) {
- chunk.Log(1, log_time(), kUidToClear, 1, 2, msg, sizeof(msg));
- };
- auto check = [](SerializedLogChunk&) {};
-
- Test(write, check, true);
-}
-
-// Test that ClearUidLogs() returns true if all logs in a given buffer correspond to the given UID.
-TEST_P(UidClearTest, all_multiple) {
- static const char msg[] = "this is a log message";
- auto write = [](SerializedLogChunk& chunk) {
- chunk.Log(2, log_time(), kUidToClear, 1, 2, msg, sizeof(msg));
- chunk.Log(3, log_time(), kUidToClear, 1, 2, msg, sizeof(msg));
- chunk.Log(4, log_time(), kUidToClear, 1, 2, msg, sizeof(msg));
- };
- auto check = [](SerializedLogChunk&) {};
-
- Test(write, check, true);
-}
-
-static std::string MakePrintable(const uint8_t* in, size_t length) {
- std::string result;
- for (size_t i = 0; i < length; ++i) {
- uint8_t c = in[i];
- if (isprint(c)) {
- result.push_back(c);
- } else {
- result.append(StringPrintf("\\%02x", static_cast<int>(c) & 0xFF));
- }
- }
- return result;
-}
-
-// This test clears UID logs at the beginning and end of the buffer, as well as two back to back
-// logs in the interior.
-TEST_P(UidClearTest, clear_beginning_and_end) {
- static const char msg1[] = "this is a log message";
- static const char msg2[] = "non-cleared message";
- static const char msg3[] = "back to back cleared messages";
- static const char msg4[] = "second in a row gone";
- static const char msg5[] = "but we save this one";
- static const char msg6[] = "and this 1!";
- static const char msg7[] = "the last one goes too";
- auto write = [](SerializedLogChunk& chunk) {
- ASSERT_NE(nullptr, chunk.Log(1, log_time(), kUidToClear, 1, 2, msg1, sizeof(msg1)));
- ASSERT_NE(nullptr, chunk.Log(2, log_time(), kOtherUid, 1, 2, msg2, sizeof(msg2)));
- ASSERT_NE(nullptr, chunk.Log(3, log_time(), kUidToClear, 1, 2, msg3, sizeof(msg3)));
- ASSERT_NE(nullptr, chunk.Log(4, log_time(), kUidToClear, 1, 2, msg4, sizeof(msg4)));
- ASSERT_NE(nullptr, chunk.Log(5, log_time(), kOtherUid, 1, 2, msg5, sizeof(msg5)));
- ASSERT_NE(nullptr, chunk.Log(6, log_time(), kOtherUid, 1, 2, msg6, sizeof(msg6)));
- ASSERT_NE(nullptr, chunk.Log(7, log_time(), kUidToClear, 1, 2, msg7, sizeof(msg7)));
- };
-
- auto check = [](SerializedLogChunk& chunk) {
- size_t read_offset = 0;
- auto* entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg2, entry->msg());
- read_offset += entry->total_len();
-
- entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg5, entry->msg());
- read_offset += entry->total_len();
-
- entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg6, entry->msg()) << MakePrintable(chunk.data(), chunk.write_offset());
- read_offset += entry->total_len();
-
- EXPECT_EQ(static_cast<int>(read_offset), chunk.write_offset());
- };
- Test(write, check, false);
-}
-
-// This tests the opposite case of beginning_and_end, in which we don't clear the beginning or end
-// logs. There is a single log pruned in the middle instead of back to back logs.
-TEST_P(UidClearTest, save_beginning_and_end) {
- static const char msg1[] = "saved first message";
- static const char msg2[] = "cleared interior message";
- static const char msg3[] = "last message stays";
- auto write = [](SerializedLogChunk& chunk) {
- ASSERT_NE(nullptr, chunk.Log(1, log_time(), kOtherUid, 1, 2, msg1, sizeof(msg1)));
- ASSERT_NE(nullptr, chunk.Log(2, log_time(), kUidToClear, 1, 2, msg2, sizeof(msg2)));
- ASSERT_NE(nullptr, chunk.Log(3, log_time(), kOtherUid, 1, 2, msg3, sizeof(msg3)));
- };
-
- auto check = [](SerializedLogChunk& chunk) {
- size_t read_offset = 0;
- auto* entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg1, entry->msg());
- read_offset += entry->total_len();
-
- entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg3, entry->msg());
- read_offset += entry->total_len();
-
- EXPECT_EQ(static_cast<int>(read_offset), chunk.write_offset());
- };
- Test(write, check, false);
-}
-
-INSTANTIATE_TEST_CASE_P(UidClearTests, UidClearTest, testing::Values(true, false));
-
-// b/166187079: ClearUidLogs() should not compress the log if writer_active_ is true
-TEST(SerializedLogChunk, ClearUidLogs_then_FinishWriting) {
- static constexpr size_t kChunkSize = 10 * 4096;
- static constexpr uid_t kUidToClear = 1000;
- static constexpr uid_t kOtherUid = 1234;
-
- SerializedLogChunk chunk{kChunkSize};
- static const char msg1[] = "saved first message";
- static const char msg2[] = "cleared interior message";
- static const char msg3[] = "last message stays";
- ASSERT_NE(nullptr, chunk.Log(1, log_time(), kOtherUid, 1, 2, msg1, sizeof(msg1)));
- ASSERT_NE(nullptr, chunk.Log(2, log_time(), kUidToClear, 1, 2, msg2, sizeof(msg2)));
- ASSERT_NE(nullptr, chunk.Log(3, log_time(), kOtherUid, 1, 2, msg3, sizeof(msg3)));
-
- chunk.ClearUidLogs(kUidToClear, LOG_ID_MAIN, nullptr);
-
- ASSERT_NE(nullptr, chunk.Log(4, log_time(), kOtherUid, 1, 2, msg3, sizeof(msg3)));
-
- chunk.FinishWriting();
- // The next line would violate a CHECK() during decompression with the faulty code.
- chunk.IncReaderRefCount();
- chunk.DecReaderRefCount();
-}
