Print DB options on DB open (#27)

Summary:
Log Titan options on DB open. Sample: https://gist.github.com/yiwu-arbug/52720461651ad7019657d0dda3c50311

Also add logging around create CF/drop CF/destroy CF handle/set option.

Test Plan:
Run tests and look at the logs.
Signed-off-by: Yi Wu <yiwu@pingcap.com>

include/titan/options.h

 #pragma once
 
-#include "rocksdb/options.h"
-
 #include <map>
 #include <unordered_map>
 
+#include "rocksdb/options.h"
+#include "util/logging.h"
+
 namespace rocksdb {
 namespace titandb {
 
@@ -33,6 +34,8 @@ struct TitanDBOptions : public DBOptions {
   TitanDBOptions() = default;
   explicit TitanDBOptions(const DBOptions& options) : DBOptions(options) {}
 
+  void Dump(Logger* logger) const;
+
   TitanDBOptions& operator=(const DBOptions& options) {
     *static_cast<DBOptions*>(this) = options;
     return *this;
@@ -127,6 +130,8 @@ struct TitanCFOptions : public ColumnFamilyOptions {
   }
 
   std::string ToString() const;
+
+  void Dump(Logger* logger) const;
 };
 
 struct ImmutableTitanCFOptions {

src/db_impl.cc

@@ -218,6 +218,16 @@ Status TitanDBImpl::Open(const std::vector<TitanCFDescriptor>& descs,
     if (stats_.get()) {
       stats_->Initialize(column_families, db_->DefaultColumnFamily()->GetID());
     }
+    ROCKS_LOG_INFO(db_options_.info_log, "Titan DB open.");
+    db_options_.Dump(db_options_.info_log.get());
+    for (auto& desc : descs) {
+      ROCKS_LOG_HEADER(db_options_.info_log,
+                       "Column family [%s], options:", desc.name.c_str());
+      desc.options.Dump(db_options_.info_log.get());
+    }
+  } else {
+    ROCKS_LOG_ERROR(db_options_.info_log, "Titan DB open failed: %s",
+                    s.ToString().c_str());
   }
   return s;
 }
@@ -303,14 +313,31 @@ Status TitanDBImpl::CreateColumnFamilies(
       vset_->AddColumnFamilies(column_families);
     }
   }
+  if (s.ok()) {
+    for (auto& desc : descs) {
+      ROCKS_LOG_INFO(db_options_.info_log, "Created column family [%s].",
+                     desc.name.c_str());
+      desc.options.Dump(db_options_.info_log.get());
+    }
+  } else {
+    std::string column_families_str;
+    for (auto& desc : descs) {
+      column_families_str += "[" + desc.name + "]";
+    }
+    ROCKS_LOG_ERROR(db_options_.info_log,
+                    "Failed to create column families %s: %s",
+                    column_families_str.c_str(), s.ToString().c_str());
+  }
   return s;
 }
 
 Status TitanDBImpl::DropColumnFamilies(
     const std::vector<ColumnFamilyHandle*>& handles) {
   std::vector<uint32_t> column_families;
+  std::string column_families_str;
   for (auto& handle : handles) {
     column_families.emplace_back(handle->GetID());
+    column_families_str += "[" + handle->GetName() + "]";
   }
   Status s = db_impl_->DropColumnFamilies(handles);
   if (s.ok()) {
@@ -322,12 +349,24 @@ Status TitanDBImpl::DropColumnFamilies(
     SequenceNumber obsolete_sequence = db_impl_->GetLatestSequenceNumber();
     s = vset_->DropColumnFamilies(column_families, obsolete_sequence);
   }
+  if (s.ok()) {
+    ROCKS_LOG_INFO(db_options_.info_log, "Dropped column families: %s",
+                   column_families_str.c_str());
+  } else {
+    ROCKS_LOG_ERROR(db_options_.info_log,
+                    "Failed to drop column families %s: %s",
+                    column_families_str.c_str(), s.ToString().c_str());
+  }
   return s;
 }
 
 Status TitanDBImpl::DestroyColumnFamilyHandle(
     ColumnFamilyHandle* column_family) {
+  if (column_family == nullptr) {
+    return Status::InvalidArgument("Column family handle is nullptr.");
+  }
   auto cf_id = column_family->GetID();
+  std::string cf_name = column_family->GetName();
   Status s = db_impl_->DestroyColumnFamilyHandle(column_family);
 
   if (s.ok()) {
@@ -335,6 +374,14 @@ Status TitanDBImpl::DestroyColumnFamilyHandle(
     // it just changes some marks and doesn't delete blob files physically.
     vset_->DestroyColumnFamily(cf_id);
   }
+  if (s.ok()) {
+    ROCKS_LOG_INFO(db_options_.info_log, "Destroyed column family handle [%s].",
+                   cf_name.c_str());
+  } else {
+    ROCKS_LOG_ERROR(db_options_.info_log,
+                    "Failed to destroy column family handle [%s]: %s",
+                    cf_name.c_str(), s.ToString().c_str());
+  }
   return s;
 }
 
@@ -546,6 +593,9 @@ Status TitanDBImpl::SetOptions(
                                    blob_run_mode_string);
   } else {
     mode = pm->second;
+    ROCKS_LOG_INFO(db_options_.info_log, "[%s] Set blob_run_mode: %s",
+                   column_family->GetName().c_str(),
+                   blob_run_mode_string.c_str());
   }
   {
     MutexLock l(&mutex_);

src/options.cc

@@ -6,11 +6,22 @@
 
 #include <inttypes.h>
 
+#include "options/options_helper.h"
 #include "rocksdb/convenience.h"
+#include "util/logging.h"
 
 namespace rocksdb {
 namespace titandb {
 
+void TitanDBOptions::Dump(Logger* logger) const {
+  ROCKS_LOG_HEADER(logger, "TitanDBOptions.dirname                : %s",
+                   dirname.c_str());
+  ROCKS_LOG_HEADER(logger, "TitanDBOptions.disable_background_gc  : %d",
+                   static_cast<int>(disable_background_gc));
+  ROCKS_LOG_HEADER(logger, "TitanDBOptions.max_background_gc      : %" PRIi32,
+                   static_cast<int>(disable_background_gc));
+}
+
 TitanCFOptions::TitanCFOptions(const ImmutableTitanCFOptions& immutable_opts,
                                const MutableTitanCFOptions& mutable_opts)
     : min_blob_size(immutable_opts.min_blob_size),
@@ -42,6 +53,48 @@ std::string TitanCFOptions::ToString() const {
   return res;
 }
 
+void TitanCFOptions::Dump(Logger* logger) const {
+  ROCKS_LOG_HEADER(logger,
+                   "TitanCFOptions.min_blob_size                : %" PRIu64,
+                   min_blob_size);
+  std::string compression_str = "unknown";
+  for (auto& compression_type : compression_type_string_map) {
+    if (compression_type.second == blob_file_compression) {
+      compression_str = compression_type.first;
+      break;
+    }
+  }
+  ROCKS_LOG_HEADER(logger, "TitanCFOptions.blob_file_compression        : %s",
+                   compression_str.c_str());
+  ROCKS_LOG_HEADER(logger,
+                   "TitanCFOptions.blob_file_target_size        : %" PRIu64,
+                   blob_file_target_size);
+  ROCKS_LOG_HEADER(logger, "TitanCFOptions.blob_cache                   : %p",
+                   blob_cache.get());
+  if (blob_cache != nullptr) {
+    ROCKS_LOG_HEADER(logger, "%s", blob_cache->GetPrintableOptions().c_str());
+  }
+  ROCKS_LOG_HEADER(logger,
+                   "TitanCFOptions.max_gc_batch_size            : %" PRIu64,
+                   max_gc_batch_size);
+  ROCKS_LOG_HEADER(logger,
+                   "TitanCFOptions.min_gc_batch_size            : %" PRIu64,
+                   min_gc_batch_size);
+  ROCKS_LOG_HEADER(logger, "TitanCFOptions.blob_file_discardable_ratio  : %lf",
+                   blob_file_discardable_ratio);
+  ROCKS_LOG_HEADER(logger, "TitanCFOptions.sample_file_size_ratio       : %lf",
+                   sample_file_size_ratio);
+  ROCKS_LOG_HEADER(logger,
+                   "TitanCFOptions.merge_small_file_threshold   : %" PRIu64,
+                   merge_small_file_threshold);
+  std::string blob_run_mode_str = "unknown";
+  if (blob_run_mode_to_string.count(blob_run_mode) > 0) {
+    blob_run_mode_str = blob_run_mode_to_string.at(blob_run_mode);
+  }
+  ROCKS_LOG_HEADER(logger, "TitanCFOptions.blob_run_mode                : %s",
+                   blob_run_mode_str.c_str());
+}
+
 std::map<TitanBlobRunMode, std::string>
     TitanOptionsHelper::blob_run_mode_to_string = {
         {TitanBlobRunMode::kNormal, "kNormal"},