diff --git a/HISTORY.md b/HISTORY.md index 40430a59d..56e3c1186 100644 --- a/HISTORY.md +++ b/HISTORY.md @@ -10,6 +10,7 @@ * `TableProperties::num_entries` and `TableProperties::num_deletions` now also account for number of range tombstones. * Remove geodb, spatial_db, document_db, json_document, date_tiered_db, and redis_lists. * With "ldb ----try_load_options", when wal_dir specified by the option file doesn't exist, ignore it. +* Change time resolution in FileOperationInfo. ### Bug Fixes * Fix a deadlock caused by compaction and file ingestion waiting for each other in the event of write stalls. diff --git a/db/listener_test.cc b/db/listener_test.cc index cbbffc8cb..894769d88 100644 --- a/db/listener_test.cc +++ b/db/listener_test.cc @@ -905,6 +905,7 @@ class TestFileOperationListener : public EventListener { if (info.status.ok()) { ++file_reads_success_; } + ReportDuration(info); } void OnFileWriteFinish(const FileOperationInfo& info) override { @@ -912,6 +913,7 @@ class TestFileOperationListener : public EventListener { if (info.status.ok()) { ++file_writes_success_; } + ReportDuration(info); } bool ShouldBeNotifiedOnFileIO() override { return true; } @@ -920,6 +922,13 @@ class TestFileOperationListener : public EventListener { std::atomic file_reads_success_; std::atomic file_writes_; std::atomic file_writes_success_; + + private: + void ReportDuration(const FileOperationInfo& info) const { + auto duration = std::chrono::duration_cast( + info.finish_timestamp - info.start_timestamp); + ASSERT_GT(duration.count(), 0); + } }; TEST_F(EventListenerTest, OnFileOperationTest) { diff --git a/include/rocksdb/listener.h b/include/rocksdb/listener.h index e39d7c347..7c2c26785 100644 --- a/include/rocksdb/listener.h +++ b/include/rocksdb/listener.h @@ -4,6 +4,7 @@ #pragma once +#include #include #include #include @@ -144,13 +145,18 @@ struct TableFileDeletionInfo { }; struct FileOperationInfo { + using TimePoint = std::chrono::time_point; + const std::string& path; uint64_t offset; size_t length; - time_t start_timestamp; - time_t finish_timestamp; + const TimePoint& start_timestamp; + const TimePoint& finish_timestamp; Status status; - FileOperationInfo(const std::string& _path) : path(_path) {} + FileOperationInfo(const std::string& _path, const TimePoint& start, + const TimePoint& finish) + : path(_path), start_timestamp(start), finish_timestamp(finish) {} }; struct FlushJobInfo { diff --git a/util/file_reader_writer.cc b/util/file_reader_writer.cc index e0ae9cb0e..42f7e2e35 100644 --- a/util/file_reader_writer.cc +++ b/util/file_reader_writer.cc @@ -99,17 +99,18 @@ Status RandomAccessFileReader::Read(uint64_t offset, size_t n, Slice* result, } Slice tmp; - time_t start_ts = 0; + FileOperationInfo::TimePoint start_ts; uint64_t orig_offset = 0; if (ShouldNotifyListeners()) { - start_ts = std::chrono::system_clock::to_time_t( - std::chrono::system_clock::now()); + start_ts = std::chrono::system_clock::now(); orig_offset = aligned_offset + buf.CurrentSize(); } s = file_->Read(aligned_offset + buf.CurrentSize(), allowed, &tmp, buf.Destination()); if (ShouldNotifyListeners()) { - NotifyOnFileReadFinish(orig_offset, tmp.size(), start_ts, s); + auto finish_ts = std::chrono::system_clock::now(); + NotifyOnFileReadFinish(orig_offset, tmp.size(), start_ts, finish_ts, + s); } buf.Size(buf.CurrentSize() + tmp.size()); @@ -145,16 +146,17 @@ Status RandomAccessFileReader::Read(uint64_t offset, size_t n, Slice* result, Slice tmp_result; #ifndef ROCKSDB_LITE - time_t start_ts = 0; + FileOperationInfo::TimePoint start_ts; if (ShouldNotifyListeners()) { - start_ts = std::chrono::system_clock::to_time_t( - std::chrono::system_clock::now()); + start_ts = std::chrono::system_clock::now(); } #endif s = file_->Read(offset + pos, allowed, &tmp_result, scratch + pos); #ifndef ROCKSDB_LITE if (ShouldNotifyListeners()) { - NotifyOnFileReadFinish(offset + pos, tmp_result.size(), start_ts, s); + auto finish_ts = std::chrono::system_clock::now(); + NotifyOnFileReadFinish(offset + pos, tmp_result.size(), start_ts, + finish_ts, s); } #endif @@ -444,18 +446,18 @@ Status WritableFileWriter::WriteBuffered(const char* data, size_t size) { TEST_SYNC_POINT("WritableFileWriter::Flush:BeforeAppend"); #ifndef ROCKSDB_LITE - time_t start_ts = 0; + FileOperationInfo::TimePoint start_ts; uint64_t old_size = writable_file_->GetFileSize(); if (ShouldNotifyListeners()) { - start_ts = std::chrono::system_clock::to_time_t( - std::chrono::system_clock::now()); + start_ts = std::chrono::system_clock::now(); old_size = next_write_offset_; } #endif s = writable_file_->Append(Slice(src, allowed)); #ifndef ROCKSDB_LITE if (ShouldNotifyListeners()) { - NotifyOnFileWriteFinish(old_size, allowed, start_ts, s); + auto finish_ts = std::chrono::system_clock::now(); + NotifyOnFileWriteFinish(old_size, allowed, start_ts, finish_ts, s); } #endif if (!s.ok()) { @@ -520,15 +522,15 @@ Status WritableFileWriter::WriteDirect() { { IOSTATS_TIMER_GUARD(write_nanos); TEST_SYNC_POINT("WritableFileWriter::Flush:BeforeAppend"); - time_t start_ts(0); + FileOperationInfo::TimePoint start_ts; if (ShouldNotifyListeners()) { - start_ts = std::chrono::system_clock::to_time_t( - std::chrono::system_clock::now()); + start_ts = std::chrono::system_clock::now(); } // direct writes must be positional s = writable_file_->PositionedAppend(Slice(src, size), write_offset); if (ShouldNotifyListeners()) { - NotifyOnFileWriteFinish(write_offset, size, start_ts, s); + auto finish_ts = std::chrono::system_clock::now(); + NotifyOnFileWriteFinish(write_offset, size, start_ts, finish_ts, s); } if (!s.ok()) { buf_.Size(file_advance + leftover_tail); diff --git a/util/file_reader_writer.h b/util/file_reader_writer.h index ec7acebcc..1083c685c 100644 --- a/util/file_reader_writer.h +++ b/util/file_reader_writer.h @@ -64,15 +64,13 @@ class SequentialFileReader { class RandomAccessFileReader { private: #ifndef ROCKSDB_LITE - void NotifyOnFileReadFinish(uint64_t offset, size_t length, time_t start_ts, + void NotifyOnFileReadFinish(uint64_t offset, size_t length, + const FileOperationInfo::TimePoint& start_ts, + const FileOperationInfo::TimePoint& finish_ts, const Status& status) const { - FileOperationInfo info(file_name_); + FileOperationInfo info(file_name_, start_ts, finish_ts); info.offset = offset; info.length = length; - info.start_timestamp = start_ts; - time_t finish_ts = - std::chrono::system_clock::to_time_t(std::chrono::system_clock::now()); - info.finish_timestamp = finish_ts; info.status = status; for (auto& listener : listeners_) { @@ -157,15 +155,13 @@ class RandomAccessFileReader { class WritableFileWriter { private: #ifndef ROCKSDB_LITE - void NotifyOnFileWriteFinish(uint64_t offset, size_t length, time_t start_ts, + void NotifyOnFileWriteFinish(uint64_t offset, size_t length, + const FileOperationInfo::TimePoint& start_ts, + const FileOperationInfo::TimePoint& finish_ts, const Status& status) { - FileOperationInfo info(file_name_); + FileOperationInfo info(file_name_, start_ts, finish_ts); info.offset = offset; info.length = length; - info.start_timestamp = start_ts; - time_t finish_ts = - std::chrono::system_clock::to_time_t(std::chrono::system_clock::now()); - info.finish_timestamp = finish_ts; info.status = status; for (auto& listener : listeners_) {