fix some perf statistic in write (facebook#12285)

Summary: ### Summary: perf context lack statistics in some write steps ``` rocksdb::get_perf_context()->write_wal_time); rocksdb::get_perf_context()->write_memtable_time); rocksdb::get_perf_context()->write_pre_and_post_process_time); ``` #### case 1: when the unordered_write is true, the `write_memtable_time` is 0 ``` write_wal_time : 13.7012 write_memtable_time : 0 write_pre_and_post_process_time : 142.037 ``` Reason: `DBImpl::UnorderedWriteMemtable` function has no statistical `write_memtable_time` during insert memtable, ```c++ Status DBImpl::UnorderedWriteMemtable(const WriteOptions& write_options, WriteBatch* my_batch, WriteCallback* callback, uint64_t log_ref, SequenceNumber seq, const size_t sub_batch_cnt) { ... if (w.CheckCallback(this) && w.ShouldWriteToMemtable()) { // need calculate write_memtable_time ColumnFamilyMemTablesImpl column_family_memtables( versions_->GetColumnFamilySet()); w.status = WriteBatchInternal::InsertInto( &w, w.sequence, &column_family_memtables, &flush_scheduler_, &trim_history_scheduler_, write_options.ignore_missing_column_families, 0 /*log_number*/, this, true /*concurrent_memtable_writes*/, seq_per_batch_, sub_batch_cnt, true /*batch_per_txn*/, write_options.memtable_insert_hint_per_batch); if (write_options.disableWAL) { has_unpersisted_data_.store(true, std::memory_order_relaxed); } } ... } ``` Fix: add perf function ``` write_wal_time : 14.3991 write_memtable_time : 19.3367 write_pre_and_post_process_time : 130.441 ``` #### case 2: when the enable_pipelined_write is true, the `write_memtable_time` is small ``` write_wal_time : 11.2986 write_memtable_time : 1.0205 write_pre_and_post_process_time : 140.131 ``` Fix: `DBImpl::UnorderedWriteMemtable` function has no statistical `write_memtable_time` when `w.state == WriteThread::STATE_PARALLEL_MEMTABLE_WRITER` ```c++ Status DBImpl::PipelinedWriteImpl(const WriteOptions& write_options, WriteBatch* my_batch, WriteCallback* callback, uint64_t* log_used, uint64_t log_ref, bool disable_memtable, uint64_t* seq_used) { ... if (w.state == WriteThread::STATE_PARALLEL_MEMTABLE_WRITER) { // need calculate write_memtable_time assert(w.ShouldWriteToMemtable()); ColumnFamilyMemTablesImpl column_family_memtables( versions_->GetColumnFamilySet()); w.status = WriteBatchInternal::InsertInto( &w, w.sequence, &column_family_memtables, &flush_scheduler_, &trim_history_scheduler_, write_options.ignore_missing_column_families, 0 /*log_number*/, this, true /*concurrent_memtable_writes*/, false /*seq_per_batch*/, 0 /*batch_cnt*/, true /*batch_per_txn*/, write_options.memtable_insert_hint_per_batch); if (write_thread_.CompleteParallelMemTableWriter(&w)) { MemTableInsertStatusCheck(w.status); versions_->SetLastSequence(w.write_group->last_sequence); write_thread_.ExitAsMemTableWriter(&w, *w.write_group); } } if (seq_used != nullptr) { *seq_used = w.sequence; } assert(w.state == WriteThread::STATE_COMPLETED); return w.FinalStatus(); } ``` FIx: add perf function ``` write_wal_time : 10.5201 write_memtable_time : 17.1048 write_pre_and_post_process_time : 114.313 ``` #### case3: `DBImpl::WriteImplWALOnly` function has no statistical `write_delay_time` ```c++ Status DBImpl::WriteImplWALOnly( WriteThread* write_thread, const WriteOptions& write_options, WriteBatch* my_batch, WriteCallback* callback, uint64_t* log_used, const uint64_t log_ref, uint64_t* seq_used, const size_t sub_batch_cnt, PreReleaseCallback* pre_release_callback, const AssignOrder assign_order, const PublishLastSeq publish_last_seq, const bool disable_memtable) { ... if (publish_last_seq == kDoPublishLastSeq) { } else { // need calculate write_delay_time InstrumentedMutexLock lock(&mutex_); Status status = DelayWrite(/*num_bytes=*/0ull, *write_thread, write_options); if (!status.ok()) { WriteThread::WriteGroup write_group; write_thread->EnterAsBatchGroupLeader(&w, &write_group); write_thread->ExitAsBatchGroupLeader(write_group, status); return status; } } } ``` Pull Request resolved: facebook#12285 Reviewed By: ajkr Differential Revision: D53191765 Pulled By: cbi42 fbshipit-source-id: f78d5b280bea6a777f077c89c3e0b8fe98d3c860
jaykorean · Jan 29, 2024 · fc48af3 · fc48af3
1 parent 071a146
commit fc48af3
Show file tree

Hide file tree

Showing 2 changed files with 17 additions and 0 deletions.
diff --git a/db/db_impl/db_impl_write.cc b/db/db_impl/db_impl_write.cc
@@ -819,6 +819,9 @@ Status DBImpl::PipelinedWriteImpl(const WriteOptions& write_options,
   }
 
   if (w.state == WriteThread::STATE_PARALLEL_MEMTABLE_WRITER) {
+    PERF_TIMER_STOP(write_pre_and_post_process_time);
+    PERF_TIMER_GUARD(write_memtable_time);
+
     assert(w.ShouldWriteToMemtable());
     ColumnFamilyMemTablesImpl column_family_memtables(
         versions_->GetColumnFamilySet());
@@ -828,6 +831,10 @@ Status DBImpl::PipelinedWriteImpl(const WriteOptions& write_options,
         0 /*log_number*/, this, true /*concurrent_memtable_writes*/,
         false /*seq_per_batch*/, 0 /*batch_cnt*/, true /*batch_per_txn*/,
         write_options.memtable_insert_hint_per_batch);
+
+    PERF_TIMER_STOP(write_memtable_time);
+    PERF_TIMER_START(write_pre_and_post_process_time);
+
     if (write_thread_.CompleteParallelMemTableWriter(&w)) {
       MemTableInsertStatusCheck(w.status);
       versions_->SetLastSequence(w.write_group->last_sequence);
@@ -860,6 +867,9 @@ Status DBImpl::UnorderedWriteMemtable(const WriteOptions& write_options,
     stats->AddDBStats(InternalStats::kIntStatsNumKeysWritten, total_count);
     RecordTick(stats_, NUMBER_KEYS_WRITTEN, total_count);
 
+    PERF_TIMER_STOP(write_pre_and_post_process_time);
+    PERF_TIMER_GUARD(write_memtable_time);
+
     ColumnFamilyMemTablesImpl column_family_memtables(
         versions_->GetColumnFamilySet());
     w.status = WriteBatchInternal::InsertInto(
@@ -871,6 +881,8 @@ Status DBImpl::UnorderedWriteMemtable(const WriteOptions& write_options,
     if (write_options.disableWAL) {
       has_unpersisted_data_.store(true, std::memory_order_relaxed);
     }
+
+    PERF_TIMER_START(write_pre_and_post_process_time);
   }
 
   size_t pending_cnt = pending_memtable_writes_.fetch_sub(1) - 1;
@@ -941,9 +953,13 @@ Status DBImpl::WriteImplWALOnly(
       return status;
     }
   } else {
+    PERF_TIMER_STOP(write_pre_and_post_process_time);
+    PERF_TIMER_GUARD(write_delay_time);
     InstrumentedMutexLock lock(&mutex_);
     Status status =
         DelayWrite(/*num_bytes=*/0ull, *write_thread, write_options);
+    PERF_TIMER_STOP(write_delay_time);
+    PERF_TIMER_START(write_pre_and_post_process_time);
     if (!status.ok()) {
       WriteThread::WriteGroup write_group;
       write_thread->EnterAsBatchGroupLeader(&w, &write_group);

diff --git a/unreleased_history/bug_fixes/fix_some_write_perf_statistics.md b/unreleased_history/bug_fixes/fix_some_write_perf_statistics.md
@@ -0,0 +1 @@
+Fix some perf context statistics error in write steps. which include missing write_memtable_time in unordered_write. missing write_memtable_time in PipelineWrite when Writer stat is STATE_PARALLEL_MEMTABLE_WRITER. missing write_delay_time when calling DelayWrite in WriteImplWALOnly function.