rocksdb/env/file_system_tracer.cc

565 lines
24 KiB
C++
Raw Normal View History

// 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;
}
Provide support for IOTracing for ReadAsync API (#9833) Summary: Same as title Pull Request resolved: https://github.com/facebook/rocksdb/pull/9833 Test Plan: Add unit test and manually check the output of tracing logs For fixed readahead_size it logs as: ``` Access Time : 193352113447923 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 15075 , IO Status: OK, Length: 12288, Offset: 659456 Access Time : 193352113465232 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 14425 , IO Status: OK, Length: 12288, Offset: 671744 Access Time : 193352113481539 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13062 , IO Status: OK, Length: 12288, Offset: 684032 Access Time : 193352113497692 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13649 , IO Status: OK, Length: 12288, Offset: 696320 Access Time : 193352113520043 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 19384 , IO Status: OK, Length: 12288, Offset: 708608 Access Time : 193352113538401 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 15406 , IO Status: OK, Length: 12288, Offset: 720896 Access Time : 193352113554855 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13670 , IO Status: OK, Length: 12288, Offset: 733184 Access Time : 193352113571624 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13855 , IO Status: OK, Length: 12288, Offset: 745472 Access Time : 193352113587924 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13953 , IO Status: OK, Length: 12288, Offset: 757760 Access Time : 193352113603285 , File Name: 000026.sst , File Operation: Prefetch , Latency: 59 , IO Status: Not implemented: Prefetch not supported, Length: 8868, Offset: 898349 ``` For implicit readahead: ``` Access Time : 193351865156587 , File Name: 000026.sst , File Operation: Prefetch , Latency: 48 , IO Status: Not implemented: Prefetch not supported, Length: 12266, Offset: 391174 Access Time : 193351865160354 , File Name: 000026.sst , File Operation: Prefetch , Latency: 51 , IO Status: Not implemented: Prefetch not supported, Length: 12266, Offset: 395248 Access Time : 193351865164253 , File Name: 000026.sst , File Operation: Prefetch , Latency: 49 , IO Status: Not implemented: Prefetch not supported, Length: 12266, Offset: 399322 Access Time : 193351865165461 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 222871 , IO Status: OK, Length: 135168, Offset: 401408 ``` Reviewed By: anand1976 Differential Revision: D35601634 Pulled By: akankshamahajan15 fbshipit-source-id: 5a4f32a850af878efa0767bd5706380152a1f26e
2022-05-26 02:47:03 +00:00
IOStatus FSRandomAccessFileTracingWrapper::ReadAsync(
FSReadRequest& req, const IOOptions& opts,
std::function<void(FSReadRequest&, void*)> cb, void* cb_arg,
Provide support for IOTracing for ReadAsync API (#9833) Summary: Same as title Pull Request resolved: https://github.com/facebook/rocksdb/pull/9833 Test Plan: Add unit test and manually check the output of tracing logs For fixed readahead_size it logs as: ``` Access Time : 193352113447923 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 15075 , IO Status: OK, Length: 12288, Offset: 659456 Access Time : 193352113465232 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 14425 , IO Status: OK, Length: 12288, Offset: 671744 Access Time : 193352113481539 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13062 , IO Status: OK, Length: 12288, Offset: 684032 Access Time : 193352113497692 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13649 , IO Status: OK, Length: 12288, Offset: 696320 Access Time : 193352113520043 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 19384 , IO Status: OK, Length: 12288, Offset: 708608 Access Time : 193352113538401 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 15406 , IO Status: OK, Length: 12288, Offset: 720896 Access Time : 193352113554855 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13670 , IO Status: OK, Length: 12288, Offset: 733184 Access Time : 193352113571624 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13855 , IO Status: OK, Length: 12288, Offset: 745472 Access Time : 193352113587924 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13953 , IO Status: OK, Length: 12288, Offset: 757760 Access Time : 193352113603285 , File Name: 000026.sst , File Operation: Prefetch , Latency: 59 , IO Status: Not implemented: Prefetch not supported, Length: 8868, Offset: 898349 ``` For implicit readahead: ``` Access Time : 193351865156587 , File Name: 000026.sst , File Operation: Prefetch , Latency: 48 , IO Status: Not implemented: Prefetch not supported, Length: 12266, Offset: 391174 Access Time : 193351865160354 , File Name: 000026.sst , File Operation: Prefetch , Latency: 51 , IO Status: Not implemented: Prefetch not supported, Length: 12266, Offset: 395248 Access Time : 193351865164253 , File Name: 000026.sst , File Operation: Prefetch , Latency: 49 , IO Status: Not implemented: Prefetch not supported, Length: 12266, Offset: 399322 Access Time : 193351865165461 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 222871 , IO Status: OK, Length: 135168, Offset: 401408 ``` Reviewed By: anand1976 Differential Revision: D35601634 Pulled By: akankshamahajan15 fbshipit-source-id: 5a4f32a850af878efa0767bd5706380152a1f26e
2022-05-26 02:47:03 +00:00
void** io_handle, IOHandleDeleter* del_fn, IODebugContext* dbg) {
// Create a callback and populate info.
auto read_async_callback =
std::bind(&FSRandomAccessFileTracingWrapper::ReadAsyncCallback, this,
std::placeholders::_1, std::placeholders::_2);
ReadAsyncCallbackInfo* read_async_cb_info = new ReadAsyncCallbackInfo;
read_async_cb_info->cb_ = cb;
read_async_cb_info->cb_arg_ = cb_arg;
read_async_cb_info->start_time_ = clock_->NowNanos();
read_async_cb_info->file_op_ = __func__;
IOStatus s = target()->ReadAsync(req, opts, read_async_callback,
read_async_cb_info, io_handle, del_fn, dbg);
if (!s.ok()) {
delete read_async_cb_info;
}
return s;
}
void FSRandomAccessFileTracingWrapper::ReadAsyncCallback(FSReadRequest& req,
void* cb_arg) {
Provide support for IOTracing for ReadAsync API (#9833) Summary: Same as title Pull Request resolved: https://github.com/facebook/rocksdb/pull/9833 Test Plan: Add unit test and manually check the output of tracing logs For fixed readahead_size it logs as: ``` Access Time : 193352113447923 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 15075 , IO Status: OK, Length: 12288, Offset: 659456 Access Time : 193352113465232 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 14425 , IO Status: OK, Length: 12288, Offset: 671744 Access Time : 193352113481539 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13062 , IO Status: OK, Length: 12288, Offset: 684032 Access Time : 193352113497692 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13649 , IO Status: OK, Length: 12288, Offset: 696320 Access Time : 193352113520043 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 19384 , IO Status: OK, Length: 12288, Offset: 708608 Access Time : 193352113538401 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 15406 , IO Status: OK, Length: 12288, Offset: 720896 Access Time : 193352113554855 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13670 , IO Status: OK, Length: 12288, Offset: 733184 Access Time : 193352113571624 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13855 , IO Status: OK, Length: 12288, Offset: 745472 Access Time : 193352113587924 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 13953 , IO Status: OK, Length: 12288, Offset: 757760 Access Time : 193352113603285 , File Name: 000026.sst , File Operation: Prefetch , Latency: 59 , IO Status: Not implemented: Prefetch not supported, Length: 8868, Offset: 898349 ``` For implicit readahead: ``` Access Time : 193351865156587 , File Name: 000026.sst , File Operation: Prefetch , Latency: 48 , IO Status: Not implemented: Prefetch not supported, Length: 12266, Offset: 391174 Access Time : 193351865160354 , File Name: 000026.sst , File Operation: Prefetch , Latency: 51 , IO Status: Not implemented: Prefetch not supported, Length: 12266, Offset: 395248 Access Time : 193351865164253 , File Name: 000026.sst , File Operation: Prefetch , Latency: 49 , IO Status: Not implemented: Prefetch not supported, Length: 12266, Offset: 399322 Access Time : 193351865165461 , File Name: 000026.sst , File Operation: ReadAsync , Latency: 222871 , IO Status: OK, Length: 135168, Offset: 401408 ``` Reviewed By: anand1976 Differential Revision: D35601634 Pulled By: akankshamahajan15 fbshipit-source-id: 5a4f32a850af878efa0767bd5706380152a1f26e
2022-05-26 02:47:03 +00:00
ReadAsyncCallbackInfo* read_async_cb_info =
static_cast<ReadAsyncCallbackInfo*>(cb_arg);
assert(read_async_cb_info);
assert(read_async_cb_info->cb_);
uint64_t elapsed = clock_->NowNanos() - read_async_cb_info->start_time_;
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,
read_async_cb_info->file_op_, elapsed,
req.status.ToString(), file_name_, req.result.size(),
req.offset);
io_tracer_->WriteIOOp(io_record, nullptr /*dbg*/);
// call the underlying callback.
read_async_cb_info->cb_(req, read_async_cb_info->cb_arg_);
delete read_async_cb_info;
}
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