From ecba6a320ef2db92d90328260c4ccb97219d1704 Mon Sep 17 00:00:00 2001 From: anand76 Date: Sun, 13 Nov 2022 21:38:35 -0800 Subject: [PATCH] Add some async read stats (#10947) Summary: Add stats for time spent in the ReadAsync call, and async read errors. Pull Request resolved: https://github.com/facebook/rocksdb/pull/10947 Test Plan: Run db_bench and look at stats Reviewed By: akankshamahajan15 Differential Revision: D41236637 Pulled By: anand1976 fbshipit-source-id: 70539b69a28491d57acead449436a761f7108acf --- HISTORY.md | 1 + file/random_access_file_reader.cc | 8 ++++++++ include/rocksdb/statistics.h | 5 +++++ java/rocksjni/portal.h | 8 ++++++++ monitoring/statistics.cc | 4 +++- 5 files changed, 25 insertions(+), 1 deletion(-) diff --git a/HISTORY.md b/HISTORY.md index f2fb97f6d..705dd1f5a 100644 --- a/HISTORY.md +++ b/HISTORY.md @@ -13,6 +13,7 @@ ### New Features * Add basic support for user-defined timestamp to Merge (#10819). +* Add stats for ReadAsync time spent and async read errors. ### Public API Changes * Marked `block_cache_compressed` as a deprecated feature. Use SecondaryCache instead. diff --git a/file/random_access_file_reader.cc b/file/random_access_file_reader.cc index 7180e239e..030cd8d07 100644 --- a/file/random_access_file_reader.cc +++ b/file/random_access_file_reader.cc @@ -471,6 +471,7 @@ IOStatus RandomAccessFileReader::ReadAsync( (uintptr_t(req.scratch) & (alignment - 1)) == 0; read_async_info->is_aligned_ = is_aligned; + uint64_t elapsed = 0; if (use_direct_io() && is_aligned == false) { FSReadRequest aligned_req = Align(req, alignment); aligned_req.status.PermitUncheckedError(); @@ -491,12 +492,17 @@ IOStatus RandomAccessFileReader::ReadAsync( assert(read_async_info->buf_.CurrentSize() == 0); + StopWatch sw(clock_, nullptr /*stats*/, 0 /*hist_type*/, &elapsed, + true /*overwrite*/, true /*delay_enabled*/); s = file_->ReadAsync(aligned_req, opts, read_async_callback, read_async_info, io_handle, del_fn, nullptr /*dbg*/); } else { + StopWatch sw(clock_, nullptr /*stats*/, 0 /*hist_type*/, &elapsed, + true /*overwrite*/, true /*delay_enabled*/); s = file_->ReadAsync(req, opts, read_async_callback, read_async_info, io_handle, del_fn, nullptr /*dbg*/); } + RecordTick(stats_, READ_ASYNC_MICROS, elapsed); // Suppress false positive clang analyzer warnings. // Memory is not released if file_->ReadAsync returns !s.ok(), because @@ -575,6 +581,8 @@ void RandomAccessFileReader::ReadAsyncCallback(const FSReadRequest& req, } if (req.status.ok()) { RecordInHistogram(stats_, ASYNC_READ_BYTES, req.result.size()); + } else if (!req.status.IsAborted()) { + RecordTick(stats_, ASYNC_READ_ERROR_COUNT, 1); } #ifndef ROCKSDB_LITE if (ShouldNotifyListeners()) { diff --git a/include/rocksdb/statistics.h b/include/rocksdb/statistics.h index 2317108cd..42a938f30 100644 --- a/include/rocksdb/statistics.h +++ b/include/rocksdb/statistics.h @@ -448,6 +448,11 @@ enum Tickers : uint32_t { // # of bytes written into blob cache. BLOB_DB_CACHE_BYTES_WRITE, + // Time spent in the ReadAsync file system call + READ_ASYNC_MICROS, + // Number of errors returned to the async read callback + ASYNC_READ_ERROR_COUNT, + TICKER_ENUM_MAX }; diff --git a/java/rocksjni/portal.h b/java/rocksjni/portal.h index dea119a59..340199507 100644 --- a/java/rocksjni/portal.h +++ b/java/rocksjni/portal.h @@ -5151,6 +5151,10 @@ class TickerTypeJni { return -0x33; case ROCKSDB_NAMESPACE::Tickers::BLOB_DB_CACHE_BYTES_WRITE: return -0x34; + case ROCKSDB_NAMESPACE::Tickers::READ_ASYNC_MICROS: + return -0x35; + case ROCKSDB_NAMESPACE::Tickers::ASYNC_READ_ERROR_COUNT: + return -0x36; case ROCKSDB_NAMESPACE::Tickers::TICKER_ENUM_MAX: // 0x5F was the max value in the initial copy of tickers to Java. // Since these values are exposed directly to Java clients, we keep @@ -5534,6 +5538,10 @@ class TickerTypeJni { return ROCKSDB_NAMESPACE::Tickers::BLOB_DB_CACHE_BYTES_READ; case -0x34: return ROCKSDB_NAMESPACE::Tickers::BLOB_DB_CACHE_BYTES_WRITE; + case -0x35: + return ROCKSDB_NAMESPACE::Tickers::READ_ASYNC_MICROS; + case -0x36: + return ROCKSDB_NAMESPACE::Tickers::ASYNC_READ_ERROR_COUNT; case 0x5F: // 0x5F was the max value in the initial copy of tickers to Java. // Since these values are exposed directly to Java clients, we keep diff --git a/monitoring/statistics.cc b/monitoring/statistics.cc index 958fc65fb..e01eed3f3 100644 --- a/monitoring/statistics.cc +++ b/monitoring/statistics.cc @@ -233,7 +233,9 @@ const std::vector> TickersNameMap = { {BLOB_DB_CACHE_ADD, "rocksdb.blobdb.cache.add"}, {BLOB_DB_CACHE_ADD_FAILURES, "rocksdb.blobdb.cache.add.failures"}, {BLOB_DB_CACHE_BYTES_READ, "rocksdb.blobdb.cache.bytes.read"}, - {BLOB_DB_CACHE_BYTES_WRITE, "rocksdb.blobdb.cache.bytes.write"}}; + {BLOB_DB_CACHE_BYTES_WRITE, "rocksdb.blobdb.cache.bytes.write"}, + {READ_ASYNC_MICROS, "rocksdb.read.async.micros"}, + {ASYNC_READ_ERROR_COUNT, "rocksdb.async.read.error.count"}}; const std::vector> HistogramsNameMap = { {DB_GET, "rocksdb.db.get.micros"},