access_log: check for reopen flag on flush interval (envoyproxy#8261)

Checks for the reopen flag when the log flush timer fires and issues the reopen even if no data is pending. This prevents Envoy from holding a file descriptor on rotated but seldom written log files until the next write. Risk Level: low Testing: add unit test Docs Changes: n/a Release Notes: n/a Fixes: envoyproxy#8249 Signed-off-by: Stephan Zuercher <[email protected]>
danzh2010 · Sep 24, 2019 · 1fcb426 · 1fcb426
1 parent 8371efa
commit 1fcb426
Show file tree

Hide file tree

Showing 2 changed files with 50 additions and 2 deletions.
diff --git a/source/common/access_log/access_log_manager_impl.cc b/source/common/access_log/access_log_manager_impl.cc
@@ -123,7 +123,7 @@ void AccessLogFileImpl::flushThreadFunc() {
 
       // flush_event_ can be woken up either by large enough flush_buffer or by timer.
       // In case it was timer, flush_buffer_ can be empty.
-      while (flush_buffer_.length() == 0 && !flush_thread_exit_) {
+      while (flush_buffer_.length() == 0 && !flush_thread_exit_ && !reopen_file_) {
         // CondVar::wait() does not throw, so it's safe to pass the mutex rather than the guard.
         flush_event_.wait(write_lock_);
       }
@@ -133,7 +133,6 @@ void AccessLogFileImpl::flushThreadFunc() {
       }
 
       flush_lock = std::unique_lock<Thread::BasicLockable>(flush_lock_);
-      ASSERT(flush_buffer_.length() > 0);
       about_to_write_buffer_.move(flush_buffer_);
       ASSERT(flush_buffer_.length() == 0);
     }

diff --git a/test/common/access_log/access_log_manager_impl_test.cc b/test/common/access_log/access_log_manager_impl_test.cc
@@ -306,6 +306,55 @@ TEST_F(AccessLogManagerImplTest, reopenFile) {
   }
 }
 
+// Test that the flush timer will trigger file reopen even if no data is waiting.
+TEST_F(AccessLogManagerImplTest, reopenFileOnTimerOnly) {
+  NiceMock<Event::MockTimer>* timer = new NiceMock<Event::MockTimer>(&dispatcher_);
+
+  Sequence sq;
+  EXPECT_CALL(*file_, open_(_))
+      .InSequence(sq)
+      .WillOnce(Return(ByMove(Filesystem::resultSuccess<bool>(true))));
+  AccessLogFileSharedPtr log_file = access_log_manager_.createAccessLog("foo");
+
+  EXPECT_CALL(*file_, write_(_))
+      .InSequence(sq)
+      .WillOnce(Invoke([](absl::string_view data) -> Api::IoCallSizeResult {
+        EXPECT_EQ(0, data.compare("before"));
+        return Filesystem::resultSuccess<ssize_t>(static_cast<ssize_t>(data.length()));
+      }));
+
+  log_file->write("before");
+  timer->invokeCallback();
+
+  {
+    Thread::LockGuard lock(file_->write_mutex_);
+    while (file_->num_writes_ != 1) {
+      file_->write_event_.wait(file_->write_mutex_);
+    }
+  }
+
+  EXPECT_CALL(*file_, close_())
+      .InSequence(sq)
+      .WillOnce(Return(ByMove(Filesystem::resultSuccess<bool>(true))));
+  EXPECT_CALL(*file_, open_(_))
+      .InSequence(sq)
+      .WillOnce(Return(ByMove(Filesystem::resultSuccess<bool>(true))));
+
+  EXPECT_CALL(*file_, close_())
+      .InSequence(sq)
+      .WillOnce(Return(ByMove(Filesystem::resultSuccess<bool>(true))));
+
+  log_file->reopen();
+  timer->invokeCallback();
+
+  {
+    Thread::LockGuard lock(file_->open_mutex_);
+    while (file_->num_opens_ != 2) {
+      file_->open_event_.wait(file_->open_mutex_);
+    }
+  }
+}
+
 TEST_F(AccessLogManagerImplTest, reopenThrows) {
   NiceMock<Event::MockTimer>* timer = new NiceMock<Event::MockTimer>(&dispatcher_);