rocksdb/env/file_system_tracer.cc
Merlin Mao f58d276764 Make TraceRecord and Replayer public (#8611)
Summary:
New public interfaces:
`TraceRecord` and `TraceRecord::Handler`, available in "rocksdb/trace_record.h".
`Replayer`, available in `rocksdb/utilities/replayer.h`.

User can use `DB::NewDefaultReplayer()` to create a Replayer to auto/manual replay a trace file.

Unit tests:
- `./db_test2 --gtest_filter="DBTest2.TraceAndReplay"`: Updated with the internal API changes.
- `./db_test2 --gtest_filter="DBTest2.TraceAndManualReplay"`: New for manual replay.

Pull Request resolved: https://github.com/facebook/rocksdb/pull/8611

Reviewed By: ajkr

Differential Revision: D30266329

Pulled By: autopear

fbshipit-source-id: 1ecb3cbbedae0f6a67c18f0cc82e002b4d81b6f8
2021-08-11 19:32:46 -07:00

520 lines
22 KiB
C++

// Copyright (c) 2019-present, Facebook, Inc. All rights reserved.
// This source code is licensed under both the GPLv2 (found in the
// COPYING file in the root directory) and Apache 2.0 License
// (found in the LICENSE.Apache file in the root directory).
#include "env/file_system_tracer.h"
#include "rocksdb/file_system.h"
#include "rocksdb/system_clock.h"
#include "rocksdb/trace_record.h"
namespace ROCKSDB_NAMESPACE {
IOStatus FileSystemTracingWrapper::NewSequentialFile(
const std::string& fname, const FileOptions& file_opts,
std::unique_ptr<FSSequentialFile>* result, IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->NewSequentialFile(fname, file_opts, result, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
fname.substr(fname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::NewRandomAccessFile(
const std::string& fname, const FileOptions& file_opts,
std::unique_ptr<FSRandomAccessFile>* result, IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->NewRandomAccessFile(fname, file_opts, result, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
fname.substr(fname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::NewWritableFile(
const std::string& fname, const FileOptions& file_opts,
std::unique_ptr<FSWritableFile>* result, IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->NewWritableFile(fname, file_opts, result, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
fname.substr(fname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::ReopenWritableFile(
const std::string& fname, const FileOptions& file_opts,
std::unique_ptr<FSWritableFile>* result, IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->ReopenWritableFile(fname, file_opts, result, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
fname.substr(fname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::ReuseWritableFile(
const std::string& fname, const std::string& old_fname,
const FileOptions& file_opts, std::unique_ptr<FSWritableFile>* result,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s =
target()->ReuseWritableFile(fname, old_fname, file_opts, result, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
fname.substr(fname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::NewRandomRWFile(
const std::string& fname, const FileOptions& file_opts,
std::unique_ptr<FSRandomRWFile>* result, IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->NewRandomRWFile(fname, file_opts, result, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
fname.substr(fname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::NewDirectory(
const std::string& name, const IOOptions& io_opts,
std::unique_ptr<FSDirectory>* result, IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->NewDirectory(name, io_opts, result, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
name.substr(name.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::GetChildren(const std::string& dir,
const IOOptions& io_opts,
std::vector<std::string>* r,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->GetChildren(dir, io_opts, r, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
dir.substr(dir.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::DeleteFile(const std::string& fname,
const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->DeleteFile(fname, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
fname.substr(fname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::CreateDir(const std::string& dirname,
const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->CreateDir(dirname, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
dirname.substr(dirname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::CreateDirIfMissing(
const std::string& dirname, const IOOptions& options, IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->CreateDirIfMissing(dirname, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
dirname.substr(dirname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::DeleteDir(const std::string& dirname,
const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->DeleteDir(dirname, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
dirname.substr(dirname.find_last_of("/\\") + 1));
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::GetFileSize(const std::string& fname,
const IOOptions& options,
uint64_t* file_size,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->GetFileSize(fname, options, file_size, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOFileSize);
IOTraceRecord io_record(
clock_->NowNanos(), TraceType::kIOTracer, io_op_data, __func__, elapsed,
s.ToString(), fname.substr(fname.find_last_of("/\\") + 1), *file_size);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FileSystemTracingWrapper::Truncate(const std::string& fname,
size_t size,
const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Truncate(fname, size, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOFileSize);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(),
fname.substr(fname.find_last_of("/\\") + 1), size);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSSequentialFileTracingWrapper::Read(size_t n,
const IOOptions& options,
Slice* result, char* scratch,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Read(n, options, result, scratch, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_,
result->size(), 0 /*Offset*/);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSSequentialFileTracingWrapper::InvalidateCache(size_t offset,
size_t length) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->InvalidateCache(offset, length);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
io_op_data |= (1 << IOTraceOp::kIOOffset);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_, length,
offset);
io_tracer_->WriteIOOp(io_record, nullptr /*dbg*/);
return s;
}
IOStatus FSSequentialFileTracingWrapper::PositionedRead(
uint64_t offset, size_t n, const IOOptions& options, Slice* result,
char* scratch, IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s =
target()->PositionedRead(offset, n, options, result, scratch, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
io_op_data |= (1 << IOTraceOp::kIOOffset);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_,
result->size(), offset);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSRandomAccessFileTracingWrapper::Read(uint64_t offset, size_t n,
const IOOptions& options,
Slice* result, char* scratch,
IODebugContext* dbg) const {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Read(offset, n, options, result, scratch, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
io_op_data |= (1 << IOTraceOp::kIOOffset);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_, n,
offset);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSRandomAccessFileTracingWrapper::MultiRead(FSReadRequest* reqs,
size_t num_reqs,
const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
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(
clock_->NowNanos(), TraceType::kIOTracer, io_op_data, __func__, latency,
reqs[i].status.ToString(), file_name_, reqs[i].len, reqs[i].offset);
io_tracer_->WriteIOOp(io_record, dbg);
}
return s;
}
IOStatus FSRandomAccessFileTracingWrapper::Prefetch(uint64_t offset, size_t n,
const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Prefetch(offset, n, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
io_op_data |= (1 << IOTraceOp::kIOOffset);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_, n,
offset);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSRandomAccessFileTracingWrapper::InvalidateCache(size_t offset,
size_t length) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->InvalidateCache(offset, length);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
io_op_data |= (1 << IOTraceOp::kIOOffset);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_, length,
static_cast<uint64_t>(offset));
io_tracer_->WriteIOOp(io_record, nullptr /*dbg*/);
return s;
}
IOStatus FSWritableFileTracingWrapper::Append(const Slice& data,
const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Append(data, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_,
data.size(), 0 /*Offset*/);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSWritableFileTracingWrapper::PositionedAppend(
const Slice& data, uint64_t offset, const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->PositionedAppend(data, offset, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
io_op_data |= (1 << IOTraceOp::kIOOffset);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_,
data.size(), offset);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSWritableFileTracingWrapper::Truncate(uint64_t size,
const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Truncate(size, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_, size,
0 /*Offset*/);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSWritableFileTracingWrapper::Close(const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Close(options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
file_name_);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
uint64_t FSWritableFileTracingWrapper::GetFileSize(const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
uint64_t file_size = target()->GetFileSize(options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOFileSize);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, "OK", file_name_, file_size);
io_tracer_->WriteIOOp(io_record, dbg);
return file_size;
}
IOStatus FSWritableFileTracingWrapper::InvalidateCache(size_t offset,
size_t length) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->InvalidateCache(offset, length);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
io_op_data |= (1 << IOTraceOp::kIOOffset);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_, length,
static_cast<uint64_t>(offset));
io_tracer_->WriteIOOp(io_record, nullptr /*dbg*/);
return s;
}
IOStatus FSRandomRWFileTracingWrapper::Write(uint64_t offset, const Slice& data,
const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Write(offset, data, options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
io_op_data |= (1 << IOTraceOp::kIOOffset);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_,
data.size(), offset);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSRandomRWFileTracingWrapper::Read(uint64_t offset, size_t n,
const IOOptions& options,
Slice* result, char* scratch,
IODebugContext* dbg) const {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Read(offset, n, options, result, scratch, dbg);
uint64_t elapsed = timer.ElapsedNanos();
uint64_t io_op_data = 0;
io_op_data |= (1 << IOTraceOp::kIOLen);
io_op_data |= (1 << IOTraceOp::kIOOffset);
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer, io_op_data,
__func__, elapsed, s.ToString(), file_name_, n,
offset);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSRandomRWFileTracingWrapper::Flush(const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Flush(options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
file_name_);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSRandomRWFileTracingWrapper::Close(const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Close(options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
file_name_);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSRandomRWFileTracingWrapper::Sync(const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Sync(options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
file_name_);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
IOStatus FSRandomRWFileTracingWrapper::Fsync(const IOOptions& options,
IODebugContext* dbg) {
StopWatchNano timer(clock_);
timer.Start();
IOStatus s = target()->Fsync(options, dbg);
uint64_t elapsed = timer.ElapsedNanos();
IOTraceRecord io_record(clock_->NowNanos(), TraceType::kIOTracer,
0 /*io_op_data*/, __func__, elapsed, s.ToString(),
file_name_);
io_tracer_->WriteIOOp(io_record, dbg);
return s;
}
} // namespace ROCKSDB_NAMESPACE