From b07e339b537162d090db7da08fd864dee1895344 Mon Sep 17 00:00:00 2001 From: Tom Cherry Date: Wed, 24 Jun 2020 11:47:49 -0700 Subject: [PATCH] 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 --- logd/SerializedFlushToState.cpp | 2 +- logd/SerializedFlushToState.h | 18 ++++---- logd/SerializedFlushToStateTest.cpp | 42 +++++++++++++++++-- logd/SerializedLogBuffer.cpp | 5 --- logd/SerializedLogChunk.h | 3 ++ logd/fuzz/Android.bp | 3 ++ logd/fuzz/corpus/logentry_use_after_compress | Bin 0 -> 3338 bytes 7 files changed, 56 insertions(+), 17 deletions(-) create mode 100644 logd/fuzz/corpus/logentry_use_after_compress diff --git a/logd/SerializedFlushToState.cpp b/logd/SerializedFlushToState.cpp index 6e2e8b053..2633348cf 100644 --- a/logd/SerializedFlushToState.cpp +++ b/logd/SerializedFlushToState.cpp @@ -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; } diff --git a/logd/SerializedFlushToState.h b/logd/SerializedFlushToState.h index 74b3de55c..0b20822dd 100644 --- a/logd/SerializedFlushToState.h +++ b/logd/SerializedFlushToState.h @@ -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* logs_ = nullptr; // An optional structure that contains an iterator to the serialized log buffer and offset into // it that this logger should handle next. diff --git a/logd/SerializedFlushToStateTest.cpp b/logd/SerializedFlushToStateTest.cpp index a1d21ac13..f4515c8e3 100644 --- a/logd/SerializedFlushToStateTest.cpp +++ b/logd/SerializedFlushToStateTest.cpp @@ -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& 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()); +} \ No newline at end of file diff --git a/logd/SerializedLogBuffer.cpp b/logd/SerializedLogBuffer.cpp index ea9feec27..0f307945a 100644 --- a/logd/SerializedLogBuffer.cpp +++ b/logd/SerializedLogBuffer.cpp @@ -276,7 +276,6 @@ bool SerializedLogBuffer::FlushTo( auto& state = reinterpret_cast(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); diff --git a/logd/SerializedLogChunk.h b/logd/SerializedLogChunk.h index a8ac8cd28..f0d2c4960 100644 --- a/logd/SerializedLogChunk.h +++ b/logd/SerializedLogChunk.h @@ -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. diff --git a/logd/fuzz/Android.bp b/logd/fuzz/Android.bp index 587eedca1..d346cd71d 100644 --- a/logd/fuzz/Android.bp +++ b/logd/fuzz/Android.bp @@ -44,4 +44,7 @@ cc_fuzz { srcs: [ "serialized_log_buffer_fuzzer.cpp", ], + corpus: [ + "corpus/logentry_use_after_compress", + ] } diff --git a/logd/fuzz/corpus/logentry_use_after_compress b/logd/fuzz/corpus/logentry_use_after_compress new file mode 100644 index 0000000000000000000000000000000000000000..2081b13c83d334aa3a2429f4ba363e227c3ff40d GIT binary patch literal 3338 zcmd^T!Nl++s+v-V%tZS*0+IO%se0so-IUfd+Mdw$w;8+&~b+GEwz1jQ{^RLX;d2`{Yn;KUkL(Vhs|a9;d3ap&kXf-KS!rYIO)fTPGT38 xG^56B2Aj_xym6)+l<>az*`BTplZ0GW0d?Frk=174prz_J{P0=T5T&C+nBEsqMZ^FA literal 0 HcmV?d00001