Move several more logging inside DB mutex to log buffer

Summary: Move several some common logging still in DB mutex to log buffer.

Test Plan: make all check

Reviewers: haobo, igor, ljin, nkg-

Reviewed By: nkg-

CC: nkg-, yhchiang, leveldb

Differential Revision: https://reviews.facebook.net/D17439

Author: siying

db/compaction_picker.cc

@@ -587,7 +587,7 @@ Compaction* UniversalCompactionPicker::PickCompaction(Version* version,
                                options_->level0_file_num_compaction_trigger;
       if ((c = PickCompactionUniversalReadAmp(
                version, score, UINT_MAX, num_files, log_buffer)) != nullptr) {
-        Log(options_->info_log, "Universal: compacting for file num\n");
+        LogToBuffer(log_buffer, "Universal: compacting for file num\n");
       }
     }
   }

db/db_impl.cc

@@ -1460,7 +1460,7 @@ Status DBImpl::FlushMemTableToOutputFile(bool* madeProgress,
     s = imm_.InstallMemtableFlushResults(
         mems, versions_.get(), &mutex_, options_.info_log.get(), file_number,
         pending_outputs_, &deletion_state.memtables_to_free,
-        db_directory_.get());
+        db_directory_.get(), log_buffer);
   }
 
   if (s.ok()) {
@@ -2013,9 +2013,10 @@ Status DBImpl::BackgroundFlush(bool* madeProgress,
                                LogBuffer* log_buffer) {
   Status stat;
   while (stat.ok() && imm_.IsFlushPending()) {
-    Log(options_.info_log,
-        "BackgroundCallFlush doing FlushMemTableToOutputFile, flush slots available %d",
-        options_.max_background_flushes - bg_flush_scheduled_);
+    LogToBuffer(log_buffer,
+                "BackgroundCallFlush doing FlushMemTableToOutputFile, "
+                "flush slots available %d",
+                options_.max_background_flushes - bg_flush_scheduled_);
     stat = FlushMemTableToOutputFile(madeProgress, deletion_state, log_buffer);
   }
   return stat;
@@ -2461,7 +2462,8 @@ Status DBImpl::FinishCompactionOutputFile(CompactionState* compact,
 }
 
 
-Status DBImpl::InstallCompactionResults(CompactionState* compact) {
+Status DBImpl::InstallCompactionResults(CompactionState* compact,
+                                        LogBuffer* log_buffer) {
   mutex_.AssertHeld();
 
   // paranoia: verify that the files that we started with
@@ -2477,11 +2479,10 @@ Status DBImpl::InstallCompactionResults(CompactionState* compact) {
     return Status::Corruption("Compaction input files inconsistent");
   }
 
-  Log(options_.info_log,  "Compacted %d@%d + %d@%d files => %lld bytes",
-      compact->compaction->num_input_files(0),
-      compact->compaction->level(),
-      compact->compaction->num_input_files(1),
-      compact->compaction->level() + 1,
+  LogToBuffer(
+      log_buffer, "Compacted %d@%d + %d@%d files => %lld bytes",
+      compact->compaction->num_input_files(0), compact->compaction->level(),
+      compact->compaction->num_input_files(1), compact->compaction->level() + 1,
       static_cast<long long>(compact->total_bytes));
 
   // Add compaction outputs
@@ -2905,17 +2906,16 @@ Status DBImpl::DoCompactionWork(CompactionState* compact,
   bool prefix_initialized = false;
 
   int64_t imm_micros = 0;  // Micros spent doing imm_ compactions
-  Log(options_.info_log,
-      "Compacting %d@%d + %d@%d files, score %.2f slots available %d",
-      compact->compaction->num_input_files(0),
-      compact->compaction->level(),
-      compact->compaction->num_input_files(1),
-      compact->compaction->output_level(),
-      compact->compaction->score(),
-      options_.max_background_compactions - bg_compaction_scheduled_);
+  LogToBuffer(log_buffer,
+              "Compacting %d@%d + %d@%d files, score %.2f slots available %d",
+              compact->compaction->num_input_files(0),
+              compact->compaction->level(),
+              compact->compaction->num_input_files(1),
+              compact->compaction->output_level(), compact->compaction->score(),
+              options_.max_background_compactions - bg_compaction_scheduled_);
   char scratch[2345];
   compact->compaction->Summary(scratch, sizeof(scratch));
-  Log(options_.info_log, "Compaction start summary: %s\n", scratch);
+  LogToBuffer(log_buffer, "Compaction start summary: %s\n", scratch);
 
   assert(versions_->current()->NumLevelFiles(compact->compaction->level()) > 0);
   assert(compact->builder == nullptr);
@@ -3173,11 +3173,12 @@ Status DBImpl::DoCompactionWork(CompactionState* compact,
   ReleaseCompactionUnusedFileNumbers(compact);
 
   if (status.ok()) {
-    status = InstallCompactionResults(compact);
+    status = InstallCompactionResults(compact, log_buffer);
     InstallSuperVersion(deletion_state);
   }
   Version::LevelSummaryStorage tmp;
-  Log(options_.info_log,
+  LogToBuffer(
+      log_buffer,
       "compacted to: %s, %.1f MB/sec, level %d, files in(%d, %d) out(%d) "
       "MB in(%.1f, %.1f) out(%.1f), read-write-amplify(%.1f) "
       "write-amplify(%.1f) %s\n",

db/db_impl.h

@@ -388,7 +388,8 @@ class DBImpl : public DB {
 
   Status OpenCompactionOutputFile(CompactionState* compact);
   Status FinishCompactionOutputFile(CompactionState* compact, Iterator* input);
-  Status InstallCompactionResults(CompactionState* compact);
+  Status InstallCompactionResults(CompactionState* compact,
+                                  LogBuffer* log_buffer);
   void AllocateCompactionOutputFileNumbers(CompactionState* compact);
   void ReleaseCompactionUnusedFileNumbers(CompactionState* compact);
 

db/memtable_list.cc

@@ -11,6 +11,7 @@
 #include "rocksdb/env.h"
 #include "rocksdb/iterator.h"
 #include "util/coding.h"
+#include "util/log_buffer.h"
 
 namespace rocksdb {
 
@@ -140,10 +141,10 @@ void MemTableList::RollbackMemtableFlush(const autovector<MemTable*>& mems,
 
 // Record a successful flush in the manifest file
 Status MemTableList::InstallMemtableFlushResults(
-    const autovector<MemTable*>& mems, VersionSet* vset,
-    port::Mutex* mu, Logger* info_log, uint64_t file_number,
-    std::set<uint64_t>& pending_outputs, autovector<MemTable*>* to_delete,
-    Directory* db_directory) {
+    const autovector<MemTable*>& mems, VersionSet* vset, port::Mutex* mu,
+    Logger* info_log, uint64_t file_number, std::set<uint64_t>& pending_outputs,
+    autovector<MemTable*>* to_delete, Directory* db_directory,
+    LogBuffer* log_buffer) {
   mu->AssertHeld();
 
   // flush was sucessful
@@ -173,9 +174,8 @@ Status MemTableList::InstallMemtableFlushResults(
       break;
     }
 
-    Log(info_log,
-        "Level-0 commit table #%lu started",
-        (unsigned long)m->file_number_);
+    LogToBuffer(log_buffer, "Level-0 commit table #%lu started",
+                (unsigned long)m->file_number_);
 
     // this can release and reacquire the mutex.
     s = vset->LogAndApply(&m->edit_, mu, db_directory);
@@ -189,10 +189,8 @@ Status MemTableList::InstallMemtableFlushResults(
     uint64_t mem_id = 1;  // how many memtables has been flushed.
     do {
       if (s.ok()) { // commit new state
-        Log(info_log,
-            "Level-0 commit table #%lu: memtable #%lu done",
-            (unsigned long)m->file_number_,
-            (unsigned long)mem_id);
+        LogToBuffer(log_buffer, "Level-0 commit table #%lu: memtable #%lu done",
+                    (unsigned long)m->file_number_, (unsigned long)mem_id);
         current_->Remove(m);
         assert(m->file_number_ > 0);
 

db/memtable_list.h

@@ -104,7 +104,8 @@ class MemTableList {
                                      Logger* info_log, uint64_t file_number,
                                      std::set<uint64_t>& pending_outputs,
                                      autovector<MemTable*>* to_delete,
-                                     Directory* db_directory);
+                                     Directory* db_directory,
+                                     LogBuffer* log_buffer);
 
   // New memtables are inserted at the front of the list.
   // Takes ownership of the referenced held on *m by the caller of Add().