From 1d226018af894c9a6b3ff7e292860779e383085b Mon Sep 17 00:00:00 2001 From: Akanksha Mahajan Date: Mon, 25 Jan 2021 14:35:45 -0800 Subject: [PATCH] In IOTracing, add filename with each operation in trace file. (#7885) Summary: 1. In IOTracing, add filename with each IOTrace record. Filename is stored in file object (Tracing Wrappers). 2. Change the logic of figuring out which additional information (file_size, length, offset etc) needs to be store with each operation which is different for different operations. When new information will be added in future (depends on operation), this change would make the future additions simple. Logic: In IOTraceRecord, io_op_data is added and its bitwise positions represent which additional information need to added in the record from enum IOTraceOp. Values in IOTraceOp represent bitwise positions. So if length and offset needs to be stored (IOTraceOp::kIOLen is 1 and IOTraceOp::kIOOffset is 2), position 1 and 2 (from rightmost bit) will be set and io_op_data will contain 110. Pull Request resolved: https://github.com/facebook/rocksdb/pull/7885 Test Plan: Updated io_tracer_test and verified the trace file manually. Reviewed By: anand1976 Differential Revision: D25982353 Pulled By: akankshamahajan15 fbshipit-source-id: ebfc5539cc0e231d7794a6b42b73f5403e360b22 --- db/external_sst_file_ingestion_job.cc | 3 +- env/file_system_tracer.cc | 205 +++++++++++++++++--------- env/file_system_tracer.h | 64 ++++++-- file/random_access_file_reader.h | 2 +- file/sequence_file_reader.h | 5 +- file/writable_file_writer.h | 2 +- tools/io_tracer_parser_tool.cc | 51 ++++--- trace_replay/io_tracer.cc | 128 +++++++++------- trace_replay/io_tracer.h | 50 ++++--- trace_replay/io_tracer_test.cc | 129 +++++++++++++++- trace_replay/trace_replay.h | 8 +- 11 files changed, 454 insertions(+), 193 deletions(-) diff --git a/db/external_sst_file_ingestion_job.cc b/db/external_sst_file_ingestion_job.cc index 9bd064c80..39aab214b 100644 --- a/db/external_sst_file_ingestion_job.cc +++ b/db/external_sst_file_ingestion_job.cc @@ -810,7 +810,8 @@ Status ExternalSstFileIngestionJob::AssignGlobalSeqnoForIngestedFile( fs_->NewRandomRWFile(file_to_ingest->internal_file_path, env_options_, &rwfile, nullptr); if (status.ok()) { - FSRandomRWFilePtr fsptr(std::move(rwfile), io_tracer_); + FSRandomRWFilePtr fsptr(std::move(rwfile), io_tracer_, + file_to_ingest->internal_file_path); std::string seqno_val; PutFixed64(&seqno_val, seqno); status = fsptr->Write(file_to_ingest->global_seqno_offset, seqno_val, diff --git a/env/file_system_tracer.cc b/env/file_system_tracer.cc index 3b3f70034..28ee9d85c 100644 --- a/env/file_system_tracer.cc +++ b/env/file_system_tracer.cc @@ -16,8 +16,9 @@ IOStatus FileSystemTracingWrapper::NewSequentialFile( timer.Start(); IOStatus s = target()->NewSequentialFile(fname, file_opts, result, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), fname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + fname.substr(fname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -29,8 +30,9 @@ IOStatus FileSystemTracingWrapper::NewRandomAccessFile( timer.Start(); IOStatus s = target()->NewRandomAccessFile(fname, file_opts, result, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), fname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + fname.substr(fname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -42,8 +44,9 @@ IOStatus FileSystemTracingWrapper::NewWritableFile( timer.Start(); IOStatus s = target()->NewWritableFile(fname, file_opts, result, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), fname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + fname.substr(fname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -55,8 +58,9 @@ IOStatus FileSystemTracingWrapper::ReopenWritableFile( timer.Start(); IOStatus s = target()->ReopenWritableFile(fname, file_opts, result, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), fname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + fname.substr(fname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -70,8 +74,9 @@ IOStatus FileSystemTracingWrapper::ReuseWritableFile( IOStatus s = target()->ReuseWritableFile(fname, old_fname, file_opts, result, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), fname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + fname.substr(fname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -83,8 +88,9 @@ IOStatus FileSystemTracingWrapper::NewRandomRWFile( timer.Start(); IOStatus s = target()->NewRandomRWFile(fname, file_opts, result, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), fname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + fname.substr(fname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -96,8 +102,9 @@ IOStatus FileSystemTracingWrapper::NewDirectory( timer.Start(); IOStatus s = target()->NewDirectory(name, io_opts, result, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), name); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + name.substr(name.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -110,8 +117,9 @@ IOStatus FileSystemTracingWrapper::GetChildren(const std::string& dir, timer.Start(); IOStatus s = target()->GetChildren(dir, io_opts, r, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), dir); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + dir.substr(dir.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -123,8 +131,9 @@ IOStatus FileSystemTracingWrapper::DeleteFile(const std::string& fname, timer.Start(); IOStatus s = target()->DeleteFile(fname, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), fname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + fname.substr(fname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -136,8 +145,9 @@ IOStatus FileSystemTracingWrapper::CreateDir(const std::string& dirname, timer.Start(); IOStatus s = target()->CreateDir(dirname, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), dirname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + dirname.substr(dirname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -148,8 +158,9 @@ IOStatus FileSystemTracingWrapper::CreateDirIfMissing( timer.Start(); IOStatus s = target()->CreateDirIfMissing(dirname, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), dirname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + dirname.substr(dirname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -161,8 +172,9 @@ IOStatus FileSystemTracingWrapper::DeleteDir(const std::string& dirname, timer.Start(); IOStatus s = target()->DeleteDir(dirname, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileName, __func__, - elapsed, s.ToString(), dirname); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + dirname.substr(dirname.find_last_of("/\\") + 1)); io_tracer_->WriteIOOp(io_record); return s; } @@ -175,8 +187,11 @@ IOStatus FileSystemTracingWrapper::GetFileSize(const std::string& fname, timer.Start(); IOStatus s = target()->GetFileSize(fname, options, file_size, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileNameAndFileSize, - __func__, elapsed, s.ToString(), fname, *file_size); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOFileSize); + IOTraceRecord io_record( + env_->NowNanos(), TraceType::kIOTracer, io_op_data, __func__, elapsed, + s.ToString(), fname.substr(fname.find_last_of("/\\") + 1), *file_size); io_tracer_->WriteIOOp(io_record); return s; } @@ -189,8 +204,11 @@ IOStatus FileSystemTracingWrapper::Truncate(const std::string& fname, timer.Start(); IOStatus s = target()->Truncate(fname, size, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileNameAndFileSize, - __func__, elapsed, s.ToString(), fname, size); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOFileSize); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), + fname.substr(fname.find_last_of("/\\") + 1), size); io_tracer_->WriteIOOp(io_record); return s; } @@ -203,8 +221,11 @@ IOStatus FSSequentialFileTracingWrapper::Read(size_t n, timer.Start(); IOStatus s = target()->Read(n, options, result, scratch, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLen, __func__, - elapsed, s.ToString(), result->size()); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, + result->size(), 0 /*Offset*/); io_tracer_->WriteIOOp(io_record); return s; } @@ -215,8 +236,12 @@ IOStatus FSSequentialFileTracingWrapper::InvalidateCache(size_t offset, timer.Start(); IOStatus s = target()->InvalidateCache(offset, length); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, - __func__, elapsed, s.ToString(), length, offset); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, length, + offset); io_tracer_->WriteIOOp(io_record); return s; } @@ -229,9 +254,12 @@ IOStatus FSSequentialFileTracingWrapper::PositionedRead( IOStatus s = target()->PositionedRead(offset, n, options, result, scratch, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, - __func__, elapsed, s.ToString(), result->size(), - offset); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, + result->size(), offset); io_tracer_->WriteIOOp(io_record); return s; } @@ -244,8 +272,12 @@ IOStatus FSRandomAccessFileTracingWrapper::Read(uint64_t offset, size_t n, timer.Start(); IOStatus s = target()->Read(offset, n, options, result, scratch, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, - __func__, elapsed, s.ToString(), n, offset); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, n, + offset); io_tracer_->WriteIOOp(io_record); return s; } @@ -259,10 +291,13 @@ IOStatus FSRandomAccessFileTracingWrapper::MultiRead(FSReadRequest* reqs, IOStatus s = target()->MultiRead(reqs, num_reqs, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); uint64_t latency = elapsed; + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); for (size_t i = 0; i < num_reqs; i++) { - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, __func__, latency, reqs[i].status.ToString(), - reqs[i].len, reqs[i].offset); + file_name_, reqs[i].len, reqs[i].offset); io_tracer_->WriteIOOp(io_record); } return s; @@ -275,8 +310,12 @@ IOStatus FSRandomAccessFileTracingWrapper::Prefetch(uint64_t offset, size_t n, timer.Start(); IOStatus s = target()->Prefetch(offset, n, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, - __func__, elapsed, s.ToString(), n, offset); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, n, + offset); io_tracer_->WriteIOOp(io_record); return s; } @@ -287,8 +326,11 @@ IOStatus FSRandomAccessFileTracingWrapper::InvalidateCache(size_t offset, timer.Start(); IOStatus s = target()->InvalidateCache(offset, length); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, - __func__, elapsed, s.ToString(), length, + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, length, static_cast(offset)); io_tracer_->WriteIOOp(io_record); return s; @@ -301,8 +343,11 @@ IOStatus FSWritableFileTracingWrapper::Append(const Slice& data, timer.Start(); IOStatus s = target()->Append(data, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLen, __func__, - elapsed, s.ToString(), data.size()); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, + data.size(), 0 /*Offset*/); io_tracer_->WriteIOOp(io_record); return s; } @@ -314,8 +359,12 @@ IOStatus FSWritableFileTracingWrapper::PositionedAppend( timer.Start(); IOStatus s = target()->PositionedAppend(data, offset, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, - __func__, elapsed, s.ToString(), data.size(), offset); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, + data.size(), offset); io_tracer_->WriteIOOp(io_record); return s; } @@ -327,8 +376,11 @@ IOStatus FSWritableFileTracingWrapper::Truncate(uint64_t size, timer.Start(); IOStatus s = target()->Truncate(size, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLen, __func__, - elapsed, s.ToString(), size); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, size, + 0 /*Offset*/); io_tracer_->WriteIOOp(io_record); return s; } @@ -339,8 +391,9 @@ IOStatus FSWritableFileTracingWrapper::Close(const IOOptions& options, timer.Start(); IOStatus s = target()->Close(options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOGeneral, __func__, - elapsed, s.ToString()); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + file_name_); io_tracer_->WriteIOOp(io_record); return s; } @@ -351,9 +404,10 @@ uint64_t FSWritableFileTracingWrapper::GetFileSize(const IOOptions& options, timer.Start(); uint64_t file_size = target()->GetFileSize(options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOFileNameAndFileSize, - "GetFileSize", elapsed, "OK", "" /* file_name */, - file_size); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOFileSize); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, "OK", file_name_, file_size); io_tracer_->WriteIOOp(io_record); return file_size; } @@ -364,8 +418,11 @@ IOStatus FSWritableFileTracingWrapper::InvalidateCache(size_t offset, timer.Start(); IOStatus s = target()->InvalidateCache(offset, length); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, - __func__, elapsed, s.ToString(), length, + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, length, static_cast(offset)); io_tracer_->WriteIOOp(io_record); return s; @@ -378,8 +435,12 @@ IOStatus FSRandomRWFileTracingWrapper::Write(uint64_t offset, const Slice& data, timer.Start(); IOStatus s = target()->Write(offset, data, options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, - __func__, elapsed, s.ToString(), data.size(), offset); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, + data.size(), offset); io_tracer_->WriteIOOp(io_record); return s; } @@ -392,8 +453,12 @@ IOStatus FSRandomRWFileTracingWrapper::Read(uint64_t offset, size_t n, timer.Start(); IOStatus s = target()->Read(offset, n, options, result, scratch, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOLenAndOffset, - __func__, elapsed, s.ToString(), n, offset); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, io_op_data, + __func__, elapsed, s.ToString(), file_name_, n, + offset); io_tracer_->WriteIOOp(io_record); return s; } @@ -404,8 +469,9 @@ IOStatus FSRandomRWFileTracingWrapper::Flush(const IOOptions& options, timer.Start(); IOStatus s = target()->Flush(options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOGeneral, __func__, - elapsed, s.ToString()); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + file_name_); io_tracer_->WriteIOOp(io_record); return s; } @@ -416,8 +482,9 @@ IOStatus FSRandomRWFileTracingWrapper::Close(const IOOptions& options, timer.Start(); IOStatus s = target()->Close(options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOGeneral, __func__, - elapsed, s.ToString()); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + file_name_); io_tracer_->WriteIOOp(io_record); return s; } @@ -428,8 +495,9 @@ IOStatus FSRandomRWFileTracingWrapper::Sync(const IOOptions& options, timer.Start(); IOStatus s = target()->Sync(options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOGeneral, __func__, - elapsed, s.ToString()); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + file_name_); io_tracer_->WriteIOOp(io_record); return s; } @@ -440,8 +508,9 @@ IOStatus FSRandomRWFileTracingWrapper::Fsync(const IOOptions& options, timer.Start(); IOStatus s = target()->Fsync(options, dbg); uint64_t elapsed = timer.ElapsedNanos(); - IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOGeneral, __func__, - elapsed, s.ToString()); + IOTraceRecord io_record(env_->NowNanos(), TraceType::kIOTracer, + 0 /*io_op_data*/, __func__, elapsed, s.ToString(), + file_name_); io_tracer_->WriteIOOp(io_record); return s; } diff --git a/env/file_system_tracer.h b/env/file_system_tracer.h index 6b5ae314b..4f45957d5 100644 --- a/env/file_system_tracer.h +++ b/env/file_system_tracer.h @@ -131,10 +131,12 @@ class FileSystemPtr { class FSSequentialFileTracingWrapper : public FSSequentialFileWrapper { public: FSSequentialFileTracingWrapper(FSSequentialFile* t, - std::shared_ptr io_tracer) + std::shared_ptr io_tracer, + const std::string& file_name) : FSSequentialFileWrapper(t), io_tracer_(io_tracer), - env_(Env::Default()) {} + env_(Env::Default()), + file_name_(file_name) {} ~FSSequentialFileTracingWrapper() override {} @@ -150,6 +152,7 @@ class FSSequentialFileTracingWrapper : public FSSequentialFileWrapper { private: std::shared_ptr io_tracer_; Env* env_; + std::string file_name_; }; // The FSSequentialFilePtr is a wrapper class that takes pointer to storage @@ -161,10 +164,13 @@ class FSSequentialFilePtr { public: FSSequentialFilePtr() = delete; FSSequentialFilePtr(std::unique_ptr&& fs, - const std::shared_ptr& io_tracer) + const std::shared_ptr& io_tracer, + const std::string& file_name) : fs_(std::move(fs)), io_tracer_(io_tracer), - fs_tracer_(fs_.get(), io_tracer_) {} + fs_tracer_(fs_.get(), io_tracer_, + file_name.substr(file_name.find_last_of("/\\") + + 1) /* pass file name */) {} FSSequentialFile* operator->() const { if (io_tracer_ && io_tracer_->is_tracing_enabled()) { @@ -197,10 +203,12 @@ class FSSequentialFilePtr { class FSRandomAccessFileTracingWrapper : public FSRandomAccessFileWrapper { public: FSRandomAccessFileTracingWrapper(FSRandomAccessFile* t, - std::shared_ptr io_tracer) + std::shared_ptr io_tracer, + const std::string& file_name) : FSRandomAccessFileWrapper(t), io_tracer_(io_tracer), - env_(Env::Default()) {} + env_(Env::Default()), + file_name_(file_name) {} ~FSRandomAccessFileTracingWrapper() override {} @@ -219,6 +227,8 @@ class FSRandomAccessFileTracingWrapper : public FSRandomAccessFileWrapper { private: std::shared_ptr io_tracer_; Env* env_; + // Stores file name instead of full path. + std::string file_name_; }; // The FSRandomAccessFilePtr is a wrapper class that takes pointer to storage @@ -229,10 +239,13 @@ class FSRandomAccessFileTracingWrapper : public FSRandomAccessFileWrapper { class FSRandomAccessFilePtr { public: FSRandomAccessFilePtr(std::unique_ptr&& fs, - const std::shared_ptr& io_tracer) + const std::shared_ptr& io_tracer, + const std::string& file_name) : fs_(std::move(fs)), io_tracer_(io_tracer), - fs_tracer_(fs_.get(), io_tracer_) {} + fs_tracer_(fs_.get(), io_tracer_, + file_name.substr(file_name.find_last_of("/\\") + + 1) /* pass file name */) {} FSRandomAccessFile* operator->() const { if (io_tracer_ && io_tracer_->is_tracing_enabled()) { @@ -265,8 +278,12 @@ class FSRandomAccessFilePtr { class FSWritableFileTracingWrapper : public FSWritableFileWrapper { public: FSWritableFileTracingWrapper(FSWritableFile* t, - std::shared_ptr io_tracer) - : FSWritableFileWrapper(t), io_tracer_(io_tracer), env_(Env::Default()) {} + std::shared_ptr io_tracer, + const std::string& file_name) + : FSWritableFileWrapper(t), + io_tracer_(io_tracer), + env_(Env::Default()), + file_name_(file_name) {} ~FSWritableFileTracingWrapper() override {} @@ -300,6 +317,8 @@ class FSWritableFileTracingWrapper : public FSWritableFileWrapper { private: std::shared_ptr io_tracer_; Env* env_; + // Stores file name instead of full path. + std::string file_name_; }; // The FSWritableFilePtr is a wrapper class that takes pointer to storage @@ -310,9 +329,13 @@ class FSWritableFileTracingWrapper : public FSWritableFileWrapper { class FSWritableFilePtr { public: FSWritableFilePtr(std::unique_ptr&& fs, - const std::shared_ptr& io_tracer) + const std::shared_ptr& io_tracer, + const std::string& file_name) : fs_(std::move(fs)), io_tracer_(io_tracer) { - fs_tracer_.reset(new FSWritableFileTracingWrapper(fs_.get(), io_tracer_)); + fs_tracer_.reset(new FSWritableFileTracingWrapper( + fs_.get(), io_tracer_, + file_name.substr(file_name.find_last_of("/\\") + + 1) /* pass file name */)); } FSWritableFile* operator->() const { @@ -352,8 +375,12 @@ class FSWritableFilePtr { class FSRandomRWFileTracingWrapper : public FSRandomRWFileWrapper { public: FSRandomRWFileTracingWrapper(FSRandomRWFile* t, - std::shared_ptr io_tracer) - : FSRandomRWFileWrapper(t), io_tracer_(io_tracer), env_(Env::Default()) {} + std::shared_ptr io_tracer, + const std::string& file_name) + : FSRandomRWFileWrapper(t), + io_tracer_(io_tracer), + env_(Env::Default()), + file_name_(file_name) {} ~FSRandomRWFileTracingWrapper() override {} @@ -375,6 +402,8 @@ class FSRandomRWFileTracingWrapper : public FSRandomRWFileWrapper { private: std::shared_ptr io_tracer_; Env* env_; + // Stores file name instead of full path. + std::string file_name_; }; // The FSRandomRWFilePtr is a wrapper class that takes pointer to storage @@ -385,10 +414,13 @@ class FSRandomRWFileTracingWrapper : public FSRandomRWFileWrapper { class FSRandomRWFilePtr { public: FSRandomRWFilePtr(std::unique_ptr&& fs, - std::shared_ptr io_tracer) + std::shared_ptr io_tracer, + const std::string& file_name) : fs_(std::move(fs)), io_tracer_(io_tracer), - fs_tracer_(fs_.get(), io_tracer_) {} + fs_tracer_(fs_.get(), io_tracer_, + file_name.substr(file_name.find_last_of("/\\") + + 1) /* pass file name */) {} FSRandomRWFile* operator->() const { if (io_tracer_ && io_tracer_->is_tracing_enabled()) { diff --git a/file/random_access_file_reader.h b/file/random_access_file_reader.h index a0f7a1917..8efe8650d 100644 --- a/file/random_access_file_reader.h +++ b/file/random_access_file_reader.h @@ -82,7 +82,7 @@ class RandomAccessFileReader { HistogramImpl* file_read_hist = nullptr, RateLimiter* rate_limiter = nullptr, const std::vector>& listeners = {}) - : file_(std::move(raf), io_tracer), + : file_(std::move(raf), io_tracer, _file_name), file_name_(std::move(_file_name)), env_(_env), stats_(stats), diff --git a/file/sequence_file_reader.h b/file/sequence_file_reader.h index 139e5255f..c04fc10f9 100644 --- a/file/sequence_file_reader.h +++ b/file/sequence_file_reader.h @@ -31,7 +31,8 @@ class SequentialFileReader { explicit SequentialFileReader( std::unique_ptr&& _file, const std::string& _file_name, const std::shared_ptr& io_tracer = nullptr) - : file_name_(_file_name), file_(std::move(_file), io_tracer) {} + : file_name_(_file_name), + file_(std::move(_file), io_tracer, _file_name) {} explicit SequentialFileReader( std::unique_ptr&& _file, const std::string& _file_name, @@ -39,7 +40,7 @@ class SequentialFileReader { const std::shared_ptr& io_tracer = nullptr) : file_name_(_file_name), file_(NewReadaheadSequentialFile(std::move(_file), _readahead_size), - io_tracer) {} + io_tracer, _file_name) {} SequentialFileReader(const SequentialFileReader&) = delete; SequentialFileReader& operator=(const SequentialFileReader&) = delete; diff --git a/file/writable_file_writer.h b/file/writable_file_writer.h index 51fbcc04b..0904bf37f 100644 --- a/file/writable_file_writer.h +++ b/file/writable_file_writer.h @@ -151,7 +151,7 @@ class WritableFileWriter { const std::vector>& listeners = {}, FileChecksumGenFactory* file_checksum_gen_factory = nullptr) : file_name_(_file_name), - writable_file_(std::move(file), io_tracer), + writable_file_(std::move(file), io_tracer, _file_name), env_(env), buf_(), max_buffer_size_(options.writable_file_max_buffer_size), diff --git a/tools/io_tracer_parser_tool.cc b/tools/io_tracer_parser_tool.cc index fca04f164..df7700071 100644 --- a/tools/io_tracer_parser_tool.cc +++ b/tools/io_tracer_parser_tool.cc @@ -38,32 +38,39 @@ void IOTraceRecordParser::PrintHumanReadableHeader( void IOTraceRecordParser::PrintHumanReadableIOTraceRecord( const IOTraceRecord& record) { std::stringstream ss; - ss << "Access Time : " << std::setw(17) << std::left - << record.access_timestamp << ", File Operation: " << std::setw(18) + ss << "Access Time : " << std::setw(20) << std::left + << record.access_timestamp << ", File Name: " << std::setw(20) << std::left + << record.file_name.c_str() << ", File Operation: " << std::setw(18) << std::left << record.file_operation.c_str() - << ", Latency: " << std::setw(9) << std::left << record.latency + << ", Latency: " << std::setw(10) << std::left << record.latency << ", IO Status: " << record.io_status.c_str(); - switch (record.trace_type) { - case TraceType::kIOGeneral: - break; - case TraceType::kIOFileNameAndFileSize: - ss << ", File Size: " << record.file_size; - FALLTHROUGH_INTENDED; - case TraceType::kIOFileName: { - if (!record.file_name.empty()) { - ss << ", File Name: " << record.file_name.c_str(); - } - break; + // Each bit in io_op_data stores which corresponding info from IOTraceOp will + // be added in the trace. Foreg, if bit at position 1 is set then + // IOTraceOp::kIOLen (length) will be logged in the record (Since + // IOTraceOp::kIOLen = 1 in the enum). So find all the set positions in + // io_op_data one by one and, update corresponsing info in the trace record, + // unset that bit to find other set bits until io_op_data = 0. + /* Read remaining options based on io_op_data set by file operation */ + int64_t io_op_data = static_cast(record.io_op_data); + while (io_op_data) { + // Find the rightmost set bit. + uint32_t set_pos = static_cast(log2(io_op_data & -io_op_data)); + switch (set_pos) { + case IOTraceOp::kIOFileSize: + ss << ", File Size: " << record.file_size; + break; + case IOTraceOp::kIOLen: + ss << ", Length: " << record.len; + break; + case IOTraceOp::kIOOffset: + ss << ", Offset: " << record.offset; + break; + default: + assert(false); } - case TraceType::kIOLenAndOffset: - ss << ", Offset: " << record.offset; - FALLTHROUGH_INTENDED; - case TraceType::kIOLen: - ss << ", Length: " << record.len; - break; - default: - assert(false); + // unset the rightmost bit. + io_op_data &= (io_op_data - 1); } ss << "\n"; fprintf(stdout, "%s", ss.str().c_str()); diff --git a/trace_replay/io_tracer.cc b/trace_replay/io_tracer.cc index ae45b1f59..b665592f9 100644 --- a/trace_replay/io_tracer.cc +++ b/trace_replay/io_tracer.cc @@ -31,32 +31,43 @@ Status IOTraceWriter::WriteIOOp(const IOTraceRecord& record) { Trace trace; trace.ts = record.access_timestamp; trace.type = record.trace_type; + PutFixed64(&trace.payload, record.io_op_data); Slice file_operation(record.file_operation); PutLengthPrefixedSlice(&trace.payload, file_operation); PutFixed64(&trace.payload, record.latency); Slice io_status(record.io_status); PutLengthPrefixedSlice(&trace.payload, io_status); - /* Write remaining options based on trace_type set by file operation */ - switch (record.trace_type) { - case TraceType::kIOGeneral: - break; - case TraceType::kIOFileNameAndFileSize: - PutFixed64(&trace.payload, record.file_size); - FALLTHROUGH_INTENDED; - case TraceType::kIOFileName: { - Slice file_name(record.file_name); - PutLengthPrefixedSlice(&trace.payload, file_name); - break; + Slice file_name(record.file_name); + PutLengthPrefixedSlice(&trace.payload, file_name); + + // Each bit in io_op_data stores which corresponding info from IOTraceOp will + // be added in the trace. Foreg, if bit at position 1 is set then + // IOTraceOp::kIOLen (length) will be logged in the record (Since + // IOTraceOp::kIOLen = 1 in the enum). So find all the set positions in + // io_op_data one by one and, update corresponsing info in the trace record, + // unset that bit to find other set bits until io_op_data = 0. + /* Write remaining options based on io_op_data set by file operation */ + int64_t io_op_data = static_cast(record.io_op_data); + while (io_op_data) { + // Find the rightmost set bit. + uint32_t set_pos = static_cast(log2(io_op_data & -io_op_data)); + switch (set_pos) { + case IOTraceOp::kIOFileSize: + PutFixed64(&trace.payload, record.file_size); + break; + case IOTraceOp::kIOLen: + PutFixed64(&trace.payload, record.len); + break; + case IOTraceOp::kIOOffset: + PutFixed64(&trace.payload, record.offset); + break; + default: + assert(false); } - case TraceType::kIOLenAndOffset: - PutFixed64(&trace.payload, record.offset); - FALLTHROUGH_INTENDED; - case TraceType::kIOLen: - PutFixed64(&trace.payload, record.len); - break; - default: - assert(false); + // unset the rightmost bit. + io_op_data &= (io_op_data - 1); } + std::string encoded_trace; TracerHelper::EncodeTrace(trace, &encoded_trace); return trace_writer_->Write(encoded_trace); @@ -135,6 +146,10 @@ Status IOTraceReader::ReadIOOp(IOTraceRecord* record) { record->trace_type = trace.type; Slice enc_slice = Slice(trace.payload); + if (!GetFixed64(&enc_slice, &record->io_op_data)) { + return Status::Incomplete( + "Incomplete access record: Failed to read trace data."); + } Slice file_operation; if (!GetLengthPrefixedSlice(&enc_slice, &file_operation)) { return Status::Incomplete( @@ -151,40 +166,49 @@ Status IOTraceReader::ReadIOOp(IOTraceRecord* record) { "Incomplete access record: Failed to read IO status."); } record->io_status = io_status.ToString(); - /* Read remaining options based on trace_type set by file operation */ - switch (record->trace_type) { - case TraceType::kIOGeneral: - break; - case TraceType::kIOFileNameAndFileSize: - if (!GetFixed64(&enc_slice, &record->file_size)) { - return Status::Incomplete( - "Incomplete access record: Failed to read file size."); - } - FALLTHROUGH_INTENDED; - case TraceType::kIOFileName: { - Slice file_name; - if (!GetLengthPrefixedSlice(&enc_slice, &file_name)) { - return Status::Incomplete( - "Incomplete access record: Failed to read file name."); - } - record->file_name = file_name.ToString(); - break; + Slice file_name; + if (!GetLengthPrefixedSlice(&enc_slice, &file_name)) { + return Status::Incomplete( + "Incomplete access record: Failed to read file name."); + } + record->file_name = file_name.ToString(); + + // Each bit in io_op_data stores which corresponding info from IOTraceOp will + // be added in the trace. Foreg, if bit at position 1 is set then + // IOTraceOp::kIOLen (length) will be logged in the record (Since + // IOTraceOp::kIOLen = 1 in the enum). So find all the set positions in + // io_op_data one by one and, update corresponsing info in the trace record, + // unset that bit to find other set bits until io_op_data = 0. + /* Read remaining options based on io_op_data set by file operation */ + // Assuming 63 bits will be used at max. + int64_t io_op_data = static_cast(record->io_op_data); + while (io_op_data) { + // Find the rightmost set bit. + uint32_t set_pos = static_cast(log2(io_op_data & -io_op_data)); + switch (set_pos) { + case IOTraceOp::kIOFileSize: + if (!GetFixed64(&enc_slice, &record->file_size)) { + return Status::Incomplete( + "Incomplete access record: Failed to read file size."); + } + break; + case IOTraceOp::kIOLen: + if (!GetFixed64(&enc_slice, &record->len)) { + return Status::Incomplete( + "Incomplete access record: Failed to read length."); + } + break; + case IOTraceOp::kIOOffset: + if (!GetFixed64(&enc_slice, &record->offset)) { + return Status::Incomplete( + "Incomplete access record: Failed to read offset."); + } + break; + default: + assert(false); } - case TraceType::kIOLenAndOffset: - if (!GetFixed64(&enc_slice, &record->offset)) { - return Status::Incomplete( - "Incomplete access record: Failed to read offset."); - } - FALLTHROUGH_INTENDED; - case TraceType::kIOLen: { - if (!GetFixed64(&enc_slice, &record->len)) { - return Status::Incomplete( - "Incomplete access record: Failed to read length."); - } - break; - } - default: - assert(false); + // unset the rightmost bit. + io_op_data &= (io_op_data - 1); } return Status::OK(); } diff --git a/trace_replay/io_tracer.h b/trace_replay/io_tracer.h index cc6d491a6..8518a230c 100644 --- a/trace_replay/io_tracer.h +++ b/trace_replay/io_tracer.h @@ -16,15 +16,37 @@ namespace ROCKSDB_NAMESPACE { +/* In order to log new data in trace record for specified operations, do + following: + 1. Add new data in IOTraceOP (say kIONewData= 3) + 2. Log it in IOTraceWriter::WriteIOOp, and read that in + IOTraceReader::ReadIOOp and + IOTraceRecordParser::PrintHumanReadableIOTraceRecord in the switch case. + 3. In the FileSystemTracer APIs where this data will be logged with, update + io_op_data |= (1 << IOTraceOp::kIONewData). +*/ +enum IOTraceOp : char { + // The value of each enum represents the bitwise position for + // IOTraceRecord.io_op_data. + kIOFileSize = 0, + kIOLen = 1, + kIOOffset = 2, +}; + struct IOTraceRecord { // Required fields for all accesses. uint64_t access_timestamp = 0; TraceType trace_type = TraceType::kTraceMax; + // Each bit in io_op_data stores which corresponding info from IOTraceOp will + // be added in the trace. Foreg, if bit at position 1 is set then + // IOTraceOp::kIOLen (length) will be logged in the record. + uint64_t io_op_data = 0; std::string file_operation; uint64_t latency = 0; std::string io_status; - // Required fields for read. + // Stores file name instead of full path. std::string file_name; + // Fields added to record based on IO operation. uint64_t len = 0; uint64_t offset = 0; uint64_t file_size = 0; @@ -32,21 +54,12 @@ struct IOTraceRecord { IOTraceRecord() {} IOTraceRecord(const uint64_t& _access_timestamp, const TraceType& _trace_type, - const std::string& _file_operation, const uint64_t& _latency, - const std::string& _io_status, const std::string& _file_name) - : access_timestamp(_access_timestamp), - trace_type(_trace_type), - file_operation(_file_operation), - latency(_latency), - io_status(_io_status), - file_name(_file_name) {} - - IOTraceRecord(const uint64_t& _access_timestamp, const TraceType& _trace_type, - const std::string& _file_operation, const uint64_t& _latency, - const std::string& _io_status, const std::string& _file_name, - const uint64_t& _file_size) + const uint64_t& _io_op_data, const std::string& _file_operation, + const uint64_t& _latency, const std::string& _io_status, + const std::string& _file_name, const uint64_t& _file_size = 0) : access_timestamp(_access_timestamp), trace_type(_trace_type), + io_op_data(_io_op_data), file_operation(_file_operation), latency(_latency), io_status(_io_status), @@ -54,14 +67,17 @@ struct IOTraceRecord { file_size(_file_size) {} IOTraceRecord(const uint64_t& _access_timestamp, const TraceType& _trace_type, - const std::string& _file_operation, const uint64_t& _latency, - const std::string& _io_status, const uint64_t& _len = 0, - const uint64_t& _offset = 0) + const uint64_t& _io_op_data, const std::string& _file_operation, + const uint64_t& _latency, const std::string& _io_status, + const std::string& _file_name, const uint64_t& _len, + const uint64_t& _offset) : access_timestamp(_access_timestamp), trace_type(_trace_type), + io_op_data(_io_op_data), file_operation(_file_operation), latency(_latency), io_status(_io_status), + file_name(_file_name), len(_len), offset(_offset) {} }; diff --git a/trace_replay/io_tracer_test.cc b/trace_replay/io_tracer_test.cc index cefc83899..8994b1acd 100644 --- a/trace_replay/io_tracer_test.cc +++ b/trace_replay/io_tracer_test.cc @@ -52,7 +52,10 @@ class IOTracerTest : public testing::Test { assert(writer); for (uint64_t i = 0; i < nrecords; i++) { IOTraceRecord record; - record.trace_type = TraceType::kIOLenAndOffset; + record.io_op_data = 0; + record.trace_type = TraceType::kIOTracer; + record.io_op_data |= (1 << IOTraceOp::kIOLen); + record.io_op_data |= (1 << IOTraceOp::kIOOffset); record.file_operation = GetFileOperation(i); record.io_status = IOStatus::OK().ToString(); record.file_name = kDummyFile + std::to_string(i); @@ -80,10 +83,117 @@ class IOTracerTest : public testing::Test { std::string test_path_; }; +TEST_F(IOTracerTest, MultipleRecordsWithDifferentIOOpOptions) { + std::string file_name = kDummyFile + std::to_string(5); + { + TraceOptions trace_opt; + std::unique_ptr trace_writer; + ASSERT_OK(NewFileTraceWriter(env_, env_options_, trace_file_path_, + &trace_writer)); + IOTracer writer; + ASSERT_OK(writer.StartIOTrace(env_, trace_opt, std::move(trace_writer))); + + // Write general record. + IOTraceRecord record0(0, TraceType::kIOTracer, 0 /*io_op_data*/, + GetFileOperation(0), 155 /*latency*/, + IOStatus::OK().ToString(), file_name); + writer.WriteIOOp(record0); + + // Write record with FileSize. + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOFileSize); + IOTraceRecord record1(0, TraceType::kIOTracer, io_op_data, + GetFileOperation(1), 10 /*latency*/, + IOStatus::OK().ToString(), file_name, + 256 /*file_size*/); + writer.WriteIOOp(record1); + + // Write record with Length. + io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + IOTraceRecord record2(0, TraceType::kIOTracer, io_op_data, + GetFileOperation(2), 10 /*latency*/, + IOStatus::OK().ToString(), file_name, 100 /*length*/, + 200 /*offset*/); + writer.WriteIOOp(record2); + + // Write record with Length and offset. + io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOLen); + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord record3(0, TraceType::kIOTracer, io_op_data, + GetFileOperation(3), 10 /*latency*/, + IOStatus::OK().ToString(), file_name, 120 /*length*/, + 17 /*offset*/); + writer.WriteIOOp(record3); + + // Write record with offset. + io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOOffset); + IOTraceRecord record4(0, TraceType::kIOTracer, io_op_data, + GetFileOperation(4), 10 /*latency*/, + IOStatus::OK().ToString(), file_name, 13 /*length*/, + 50 /*offset*/); + writer.WriteIOOp(record4); + ASSERT_OK(env_->FileExists(trace_file_path_)); + } + { + // Verify trace file is generated correctly. + std::unique_ptr trace_reader; + ASSERT_OK(NewFileTraceReader(env_, env_options_, trace_file_path_, + &trace_reader)); + IOTraceReader reader(std::move(trace_reader)); + IOTraceHeader header; + ASSERT_OK(reader.ReadHeader(&header)); + ASSERT_EQ(kMajorVersion, static_cast(header.rocksdb_major_version)); + ASSERT_EQ(kMinorVersion, static_cast(header.rocksdb_minor_version)); + + // Read general record. + IOTraceRecord record0; + ASSERT_OK(reader.ReadIOOp(&record0)); + ASSERT_EQ(record0.file_operation, GetFileOperation(0)); + ASSERT_EQ(record0.latency, 155); + ASSERT_EQ(record0.file_name, file_name); + + // Read record with FileSize. + IOTraceRecord record1; + ASSERT_OK(reader.ReadIOOp(&record1)); + ASSERT_EQ(record1.file_size, 256); + ASSERT_EQ(record1.len, 0); + ASSERT_EQ(record1.offset, 0); + + // Read record with Length. + IOTraceRecord record2; + ASSERT_OK(reader.ReadIOOp(&record2)); + ASSERT_EQ(record2.len, 100); + ASSERT_EQ(record2.file_size, 0); + ASSERT_EQ(record2.offset, 0); + + // Read record with Length and offset. + IOTraceRecord record3; + ASSERT_OK(reader.ReadIOOp(&record3)); + ASSERT_EQ(record3.len, 120); + ASSERT_EQ(record3.file_size, 0); + ASSERT_EQ(record3.offset, 17); + + // Read record with offset. + IOTraceRecord record4; + ASSERT_OK(reader.ReadIOOp(&record4)); + ASSERT_EQ(record4.len, 0); + ASSERT_EQ(record4.file_size, 0); + ASSERT_EQ(record4.offset, 50); + + // Read one more record and it should report error. + IOTraceRecord record5; + ASSERT_NOK(reader.ReadIOOp(&record5)); + } +} + TEST_F(IOTracerTest, AtomicWrite) { std::string file_name = kDummyFile + std::to_string(0); { - IOTraceRecord record(0, TraceType::kIOFileName, GetFileOperation(0), 0, + IOTraceRecord record(0, TraceType::kIOTracer, 0 /*io_op_data*/, + GetFileOperation(0), 10 /*latency*/, IOStatus::OK().ToString(), file_name); TraceOptions trace_opt; std::unique_ptr trace_writer; @@ -115,9 +225,11 @@ TEST_F(IOTracerTest, AtomicWrite) { } TEST_F(IOTracerTest, AtomicWriteBeforeStartTrace) { + std::string file_name = kDummyFile + std::to_string(0); { - IOTraceRecord record(0, TraceType::kIOGeneral, GetFileOperation(0), 0, - IOStatus::OK().ToString()); + IOTraceRecord record(0, TraceType::kIOTracer, 0 /*io_op_data*/, + GetFileOperation(0), 0, IOStatus::OK().ToString(), + file_name); std::unique_ptr trace_writer; ASSERT_OK(NewFileTraceWriter(env_, env_options_, trace_file_path_, &trace_writer)); @@ -139,10 +251,13 @@ TEST_F(IOTracerTest, AtomicWriteBeforeStartTrace) { } TEST_F(IOTracerTest, AtomicNoWriteAfterEndTrace) { + std::string file_name = kDummyFile + std::to_string(0); { - IOTraceRecord record(0, TraceType::kIOFileNameAndFileSize, - GetFileOperation(2), 0 /*latency*/, - IOStatus::OK().ToString(), "", 10 /*file_size*/); + uint64_t io_op_data = 0; + io_op_data |= (1 << IOTraceOp::kIOFileSize); + IOTraceRecord record( + 0, TraceType::kIOTracer, io_op_data, GetFileOperation(2), 0 /*latency*/, + IOStatus::OK().ToString(), file_name, 10 /*file_size*/); TraceOptions trace_opt; std::unique_ptr trace_writer; ASSERT_OK(NewFileTraceWriter(env_, env_options_, trace_file_path_, diff --git a/trace_replay/trace_replay.h b/trace_replay/trace_replay.h index 3c3be1cd1..fc1c5cbf0 100644 --- a/trace_replay/trace_replay.h +++ b/trace_replay/trace_replay.h @@ -46,12 +46,8 @@ enum TraceType : char { kBlockTraceDataBlock = 9, kBlockTraceUncompressionDictBlock = 10, kBlockTraceRangeDeletionBlock = 11, - // IO Trace related types based on options that will be added in trace file. - kIOGeneral = 12, - kIOFileName = 13, - kIOFileNameAndFileSize = 14, - kIOLen = 15, - kIOLenAndOffset = 16, + // For IOTracing. + kIOTracer = 12, // All trace types should be added before kTraceMax kTraceMax, };