logd: fix use after resize of contents_ vector

SerializedFlushToState::PopNextUnreadLog() was calling
AddMinHeapEntry() to replenish the element that was just popped off of
the heap, however AddMinHeapEntry() also manages reference counts for
the buffers, and this resulting in the following scenario:

PopNextUnreadLog() returns a pointer referencing log buffer #1
AddMinHeapEntry() sees that all logs from buffer #1 has been read, so
it decrements the reference count
The caller of PopNextUnreadLog() uses the result which references
invalid memory.

This calls CheckForNewLogs() within HasUnreadLogs() instead of
requiring a separate call, which fixes an additional issue where
continuing from the loop in SerializedLogBuffer::FlushTo() may not
pick up subsequent logs in a given log buffer, since CheckForNewLogs()
wouldn't be called.  This was exacerbated by the above change.

This adds a test to check the reference counts for this case and fixes
an argument mismatch in SerializedFlushToStateTest.

This adds the corpus that surfaced the issue.

Bug: 159753229
Bug: 159783005
Test: these unit tests, run fuzzer without error
Change-Id: Ib2636dfc14293b7e2cd00876b9def6e9dbbff4ce
This commit is contained in:
Tom Cherry 2020-06-24 11:47:49 -07:00
parent d9299c5119
commit b07e339b53
7 changed files with 56 additions and 17 deletions

View file

@ -121,7 +121,7 @@ MinHeapElement SerializedFlushToState::PopNextUnreadLog() {
log_positions_[log_id]->read_offset += entry->total_len();
AddMinHeapEntry(log_id);
logs_needed_from_next_position_[log_id] = true;
return top;
}

View file

@ -61,15 +61,13 @@ class SerializedFlushToState : public FlushToState {
if (logs_ == nullptr) logs_ = logs;
}
// Checks to see if any log buffers set in logs_needed_from_next_position_ have new logs and
// calls AddMinHeapEntry() if so.
void CheckForNewLogs();
bool HasUnreadLogs() {
CheckForNewLogs();
return !min_heap_.empty();
}
bool HasUnreadLogs() { return !min_heap_.empty(); }
// Pops the next unread log from the min heap. Add the next log for that log_id to the min heap
// if one is available otherwise set logs_needed_from_next_position_ to indicate that we're
// waiting for more logs.
// Pops the next unread log from the min heap and sets logs_needed_from_next_position_ to
// indicate that we're waiting for more logs from the associated log buffer.
MinHeapElement PopNextUnreadLog();
// If the parent log buffer prunes logs, the reference that this class contains may become
@ -86,6 +84,10 @@ class SerializedFlushToState : public FlushToState {
// first chunk and then first log entry within that chunk that is greater or equal to start().
void CreateLogPosition(log_id_t log_id);
// Checks to see if any log buffers set in logs_needed_from_next_position_ have new logs and
// calls AddMinHeapEntry() if so.
void CheckForNewLogs();
std::list<SerializedLogChunk>* logs_ = nullptr;
// An optional structure that contains an iterator to the serialized log buffer and offset into
// it that this logger should handle next.

View file

@ -89,7 +89,6 @@ class SerializedFlushToStateTest : public testing::Test {
for (uint32_t mask = 0; mask < max_mask; ++mask) {
auto state = SerializedFlushToState{sequence, mask};
state.InitializeLogs(log_chunks_);
state.CheckForNewLogs();
TestReading(sequence, mask, state);
}
}
@ -109,7 +108,6 @@ class SerializedFlushToStateTest : public testing::Test {
state.InitializeLogs(log_chunks_);
int loop_count = 0;
while (write_logs(loop_count++)) {
state.CheckForNewLogs();
TestReading(sequence, mask, state);
sequence_numbers_per_buffer_.clear();
}
@ -149,7 +147,7 @@ class SerializedFlushToStateTest : public testing::Test {
// Add a chunk with the given messages to the a given log buffer. Keep track of the sequence
// numbers for future validation. Optionally mark the block as having finished writing.
void AddChunkWithMessages(int buffer, bool finish_writing,
void AddChunkWithMessages(bool finish_writing, int buffer,
const std::vector<std::string>& messages) {
auto chunk = SerializedLogChunk{kChunkSize};
for (const auto& message : messages) {
@ -252,3 +250,41 @@ TEST_F(SerializedFlushToStateTest, future_writes) {
TestAllReadingWithFutureMessages(write_logs);
}
TEST_F(SerializedFlushToStateTest, no_dangling_references) {
AddChunkWithMessages(true, 0, {"1st", "2nd"});
AddChunkWithMessages(true, 0, {"3rd", "4th"});
auto state = SerializedFlushToState{1, kLogMaskAll};
state.InitializeLogs(log_chunks_);
ASSERT_EQ(log_chunks_[0].size(), 2U);
auto first_chunk = log_chunks_[0].begin();
auto second_chunk = std::next(first_chunk);
ASSERT_TRUE(state.HasUnreadLogs());
auto first_log = state.PopNextUnreadLog();
EXPECT_STREQ(first_log.entry->msg(), "1st");
EXPECT_EQ(first_chunk->reader_ref_count(), 1U);
EXPECT_EQ(second_chunk->reader_ref_count(), 0U);
ASSERT_TRUE(state.HasUnreadLogs());
auto second_log = state.PopNextUnreadLog();
EXPECT_STREQ(second_log.entry->msg(), "2nd");
EXPECT_EQ(first_chunk->reader_ref_count(), 1U);
EXPECT_EQ(second_chunk->reader_ref_count(), 0U);
ASSERT_TRUE(state.HasUnreadLogs());
auto third_log = state.PopNextUnreadLog();
EXPECT_STREQ(third_log.entry->msg(), "3rd");
EXPECT_EQ(first_chunk->reader_ref_count(), 0U);
EXPECT_EQ(second_chunk->reader_ref_count(), 1U);
ASSERT_TRUE(state.HasUnreadLogs());
auto fourth_log = state.PopNextUnreadLog();
EXPECT_STREQ(fourth_log.entry->msg(), "4th");
EXPECT_EQ(first_chunk->reader_ref_count(), 0U);
EXPECT_EQ(second_chunk->reader_ref_count(), 1U);
EXPECT_FALSE(state.HasUnreadLogs());
}

View file

@ -276,7 +276,6 @@ bool SerializedLogBuffer::FlushTo(
auto& state = reinterpret_cast<SerializedFlushToState&>(abstract_state);
state.InitializeLogs(logs_);
state.CheckForNewLogs();
while (state.HasUnreadLogs()) {
MinHeapElement top = state.PopNextUnreadLog();
@ -309,10 +308,6 @@ bool SerializedLogBuffer::FlushTo(
return false;
}
lock.lock();
// Since we released the log above, buffers that aren't in our min heap may now have had
// logs added, so re-check them.
state.CheckForNewLogs();
}
state.set_start(state.start() + 1);

View file

@ -60,6 +60,9 @@ class SerializedLogChunk {
int write_offset() const { return write_offset_; }
uint64_t highest_sequence_number() const { return highest_sequence_number_; }
// Exposed for testing
uint32_t reader_ref_count() const { return reader_ref_count_; }
private:
// The decompressed contents of this log buffer. Deallocated when the ref_count reaches 0 and
// writer_active_ is false.

View file

@ -44,4 +44,7 @@ cc_fuzz {
srcs: [
"serialized_log_buffer_fuzzer.cpp",
],
corpus: [
"corpus/logentry_use_after_compress",
]
}

Binary file not shown.