From d9f538e1a9c2afd31ecd3d54d947102fbf47a6de Mon Sep 17 00:00:00 2001 From: Mark Callaghan Date: Mon, 3 Jun 2013 08:16:16 -0700 Subject: [PATCH] Improve output for GetProperty('leveldb.stats') Summary: Display separate values for read, write & total compaction IO. Display compaction amplification and write amplification. Add similar values for the period since the last call to GetProperty. Results since the server started are reported as "cumulative" stats. Results since the last call to GetProperty are reported as "interval" stats. Level Files Size(MB) Time(sec) Read(MB) Write(MB) Rn(MB) Rnp1(MB) Wnew(MB) Amplify Read(MB/s) Write(MB/s) Rn Rnp1 Wnp1 NewW Count Ln-stall ---------------------------------------------------------------------------------------------------------------------------------------------------------------------- 0 7 13 21 0 211 0 0 211 0.0 0.0 10.1 0 0 0 0 113 0.0 1 79 157 88 993 989 198 795 194 9.0 11.3 11.2 106 405 502 97 14 0.0 2 19 36 5 63 63 37 27 36 2.4 12.3 12.2 19 14 32 18 12 0.0 >>>>>>>>>>>>>>>>>>>>>>>>> text below has been is new and/or reformatted Uptime(secs): 122.2 total, 0.9 interval Compaction IO cumulative (GB): 0.21 new, 1.03 read, 1.23 write, 2.26 read+write Compaction IO cumulative (MB/sec): 1.7 new, 8.6 read, 10.3 write, 19.0 read+write Amplification cumulative: 6.0 write, 11.0 compaction Compaction IO interval (MB): 5.59 new, 0.00 read, 5.59 write, 5.59 read+write Compaction IO interval (MB/sec): 6.5 new, 0.0 read, 6.5 write, 6.5 read+write Amplification interval: 1.0 write, 1.0 compaction >>>>>>>>>>>>>>>>>>>>>>>> text above is new and/or reformatted Stalls(secs): 90.574 level0_slowdown, 0.000 level0_numfiles, 10.165 memtable_compaction, 0.000 leveln_slowdown Task ID: # Blame Rev: Test Plan: make check, run db_bench Revert Plan: Database Impact: Memcache Impact: Other Notes: EImportant: - begin *PUBLIC* platform impact section - Bugzilla: # - end platform impact - Reviewers: haobo Reviewed By: haobo CC: leveldb Differential Revision: https://reviews.facebook.net/D11049 --- db/db_impl.cc | 79 +++++++++++++++++++++++++++++++++++++++++++++------ db/db_impl.h | 13 +++++++++ 2 files changed, 84 insertions(+), 8 deletions(-) diff --git a/db/db_impl.cc b/db/db_impl.cc index fecbd83be..72192f0e9 100644 --- a/db/db_impl.cc +++ b/db/db_impl.cc @@ -2380,10 +2380,16 @@ bool DBImpl::GetProperty(const Slice& property, std::string* value) { } else if (in == "stats") { char buf[1000]; - uint64_t total_bytes = 0; + uint64_t total_bytes_written = 0; + uint64_t total_bytes_read = 0; uint64_t micros_up = env_->NowMicros() - started_at_; - double seconds_up = micros_up / 1000000.0; + // Add "+1" to make sure seconds_up is > 0 and avoid NaN later + double seconds_up = (micros_up + 1) / 1000000.0; uint64_t total_slowdown = 0; + uint64_t interval_bytes_written = 0; + uint64_t interval_bytes_read = 0; + uint64_t interval_bytes_new = 0; + double interval_seconds_up = 0; // Pardon the long line but I think it is easier to read this way. snprintf(buf, sizeof(buf), @@ -2404,7 +2410,9 @@ bool DBImpl::GetProperty(const Slice& property, std::string* value) { : (stats_[level].bytes_written + stats_[level].bytes_readnp1) / (double) stats_[level].bytes_readn; - total_bytes += bytes_read + stats_[level].bytes_written; + total_bytes_read += bytes_read; + total_bytes_written += stats_[level].bytes_written; + snprintf( buf, sizeof(buf), "%3d %8d %8.0f %5.1f %9.0f %9.0f %9.0f %9.0f %9.0f %9.0f %7.1f %9.1f %11.1f %8d %8d %8d %8d %8d %9.1f\n", @@ -2435,16 +2443,66 @@ bool DBImpl::GetProperty(const Slice& property, std::string* value) { } } + interval_bytes_new = stats_[0].bytes_written - last_stats_.bytes_new_; + interval_bytes_read = total_bytes_read - last_stats_.bytes_read_; + interval_bytes_written = total_bytes_written - last_stats_.bytes_written_; + interval_seconds_up = seconds_up - last_stats_.seconds_up_; + + snprintf(buf, sizeof(buf), "Uptime(secs): %.1f total, %.1f interval\n", + seconds_up, interval_seconds_up); + value->append(buf); + snprintf(buf, sizeof(buf), - "Amplification: %.1f rate, %.2f GB in, %.2f GB out, %.2f MB/sec in, %.2f MB/sec out\n", - (double) total_bytes / stats_[0].bytes_written, + "Compaction IO cumulative (GB): " + "%.2f new, %.2f read, %.2f write, %.2f read+write\n", stats_[0].bytes_written / (1048576.0 * 1024), - total_bytes / (1048576.0 * 1024), + total_bytes_read / (1048576.0 * 1024), + total_bytes_written / (1048576.0 * 1024), + (total_bytes_read + total_bytes_written) / (1048576.0 * 1024)); + value->append(buf); + + snprintf(buf, sizeof(buf), + "Compaction IO cumulative (MB/sec): " + "%.1f new, %.1f read, %.1f write, %.1f read+write\n", stats_[0].bytes_written / 1048576.0 / seconds_up, - total_bytes / 1048576.0 / seconds_up); + total_bytes_read / 1048576.0 / seconds_up, + total_bytes_written / 1048576.0 / seconds_up, + (total_bytes_read + total_bytes_written) / 1048576.0 / seconds_up); + value->append(buf); + + // +1 to avoid divide by 0 and NaN + snprintf(buf, sizeof(buf), + "Amplification cumulative: %.1f write, %.1f compaction\n", + (double) total_bytes_written / (stats_[0].bytes_written+1), + (double) (total_bytes_written + total_bytes_read) + / (stats_[0].bytes_written+1)); value->append(buf); - snprintf(buf, sizeof(buf), "Uptime(secs): %.1f\n", seconds_up); + snprintf(buf, sizeof(buf), + "Compaction IO interval (MB): " + "%.2f new, %.2f read, %.2f write, %.2f read+write\n", + interval_bytes_new / 1048576.0, + interval_bytes_read/ 1048576.0, + interval_bytes_written / 1048576.0, + (interval_bytes_read + interval_bytes_written) / 1048576.0); + value->append(buf); + + snprintf(buf, sizeof(buf), + "Compaction IO interval (MB/sec): " + "%.1f new, %.1f read, %.1f write, %.1f read+write\n", + interval_bytes_new / 1048576.0 / interval_seconds_up, + interval_bytes_read / 1048576.0 / interval_seconds_up, + interval_bytes_written / 1048576.0 / interval_seconds_up, + (interval_bytes_read + interval_bytes_written) + / 1048576.0 / interval_seconds_up); + value->append(buf); + + // +1 to avoid divide by 0 and NaN + snprintf(buf, sizeof(buf), + "Amplification interval: %.1f write, %.1f compaction\n", + (double) interval_bytes_written / (interval_bytes_new+1), + (double) (interval_bytes_written + interval_bytes_read) / + (interval_bytes_new+1)); value->append(buf); snprintf(buf, sizeof(buf), @@ -2456,6 +2514,11 @@ bool DBImpl::GetProperty(const Slice& property, std::string* value) { total_slowdown / 1000000.0); value->append(buf); + last_stats_.bytes_read_ = total_bytes_read; + last_stats_.bytes_written_ = total_bytes_written; + last_stats_.bytes_new_ = stats_[0].bytes_written; + last_stats_.seconds_up_ = seconds_up; + return true; } else if (in == "sstables") { *value = versions_->current()->DebugString(); diff --git a/db/db_impl.h b/db/db_impl.h index 7d434dad4..5b8bd7fa1 100644 --- a/db/db_impl.h +++ b/db/db_impl.h @@ -338,6 +338,19 @@ class DBImpl : public DB { std::vector stats_; + // Used to compute per-interval statistics + struct StatsSnapshot { + uint64_t bytes_read_; + uint64_t bytes_written_; + uint64_t bytes_new_; + double seconds_up_; + + StatsSnapshot() : bytes_read_(0), bytes_written_(0), + bytes_new_(0), seconds_up_(0) {} + }; + + StatsSnapshot last_stats_; + static const int KEEP_LOG_FILE_NUM = 1000; std::string db_absolute_path_;