Add file system performance monitor

This commit is contained in:
Marcus Holland-Moritz 2023-06-28 22:37:47 +02:00
parent 0c26a57ca5
commit 5ae78b9315
7 changed files with 575 additions and 20 deletions

View File

@ -25,6 +25,7 @@ include(CheckCXXSourceCompiles)
option(WITH_TESTS "build with tests" OFF)
option(WITH_BENCHMARKS "build with benchmarks" OFF)
option(ENABLE_PERFMON "enable performance monitor in all tools" ON)
if(WIN32)
set(PREFER_SYSTEM_LIBFMT ON)
set(PREFER_SYSTEM_LIBARCHIVE ON)
@ -443,6 +444,7 @@ list(
src/dwarfs/option_map.cpp
src/dwarfs/options.cpp
src/dwarfs/os_access_generic.cpp
src/dwarfs/performance_monitor.cpp
src/dwarfs/progress.cpp
src/dwarfs/scanner.cpp
src/dwarfs/similarity.cpp
@ -788,6 +790,10 @@ foreach(tgt dwarfs dwarfs_compression dwarfs_tool ${BINARY_TARGETS} ${MAIN_TARGE
target_compile_definitions(${tgt} PRIVATE DWARFS_USE_EXCEPTION_TRACER)
endif()
if(ENABLE_PERFMON)
target_compile_definitions(${tgt} PRIVATE DWARFS_PERFMON_ENABLED=1)
endif()
if("${CMAKE_CXX_COMPILER_ID}" STREQUAL "GNU" OR
"${CMAKE_CXX_COMPILER_ID}" STREQUAL "Clang")
target_compile_options(${tgt} PRIVATE -Wall -Wextra -pedantic)

View File

@ -51,6 +51,7 @@ struct vfs_stat;
class filesystem_writer;
class logger;
class mmif;
class performance_monitor;
class progress;
class filesystem_v2 {
@ -60,7 +61,8 @@ class filesystem_v2 {
filesystem_v2(logger& lgr, std::shared_ptr<mmif> mm);
filesystem_v2(logger& lgr, std::shared_ptr<mmif> mm,
const filesystem_options& options, int inode_offset = 0);
const filesystem_options& options, int inode_offset = 0,
std::shared_ptr<performance_monitor const> perfmon = nullptr);
static void rewrite(logger& lgr, progress& prog, std::shared_ptr<mmif> mm,
filesystem_writer& writer, rewrite_options const& opts);

View File

@ -0,0 +1,164 @@
/* vim:set ts=2 sw=2 sts=2 et: */
/**
* \author Marcus Holland-Moritz (github@mhxnet.de)
* \copyright Copyright (c) Marcus Holland-Moritz
*
* This file is part of dwarfs.
*
* dwarfs is free software: you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation, either version 3 of the License, or
* (at your option) any later version.
*
* dwarfs is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with dwarfs. If not, see <https://www.gnu.org/licenses/>.
*/
#pragma once
#include <cstdint>
#include <iosfwd>
#include <memory>
#include <string>
#include <unordered_set>
namespace dwarfs {
class performance_monitor {
public:
using timer_id = size_t;
using time_type = uint64_t;
static std::unique_ptr<performance_monitor>
create(std::unordered_set<std::string> const& enabled_namespaces);
virtual ~performance_monitor() = default;
virtual time_type now() const = 0;
virtual void add_sample(timer_id id, time_type start) const = 0;
virtual void summarize(std::ostream& os) const = 0;
virtual bool is_enabled(std::string const& ns) const = 0;
virtual timer_id
setup_timer(std::string const& ns, std::string const& name) const = 0;
};
class performance_monitor_proxy {
public:
class section_timer {
public:
section_timer() = default;
section_timer(performance_monitor const* mon,
performance_monitor::timer_id id)
: mon_{mon}
, id_{id}
, start_{mon_->now()} {}
~section_timer() {
if (mon_) {
mon_->add_sample(id_, start_);
}
}
private:
performance_monitor const* mon_{nullptr};
performance_monitor::timer_id id_;
performance_monitor::time_type start_;
};
performance_monitor_proxy() = default;
performance_monitor_proxy(std::shared_ptr<performance_monitor const> mon,
std::string const& proxy_namespace);
performance_monitor::timer_id setup_timer(std::string const& name) const {
return mon_ ? mon_->setup_timer(namespace_, name) : 0;
}
section_timer scoped_section(performance_monitor::timer_id id) const {
return mon_ ? section_timer(mon_.get(), id) : section_timer();
}
private:
std::shared_ptr<performance_monitor const> mon_;
std::string namespace_;
};
#ifndef DWARFS_PERFMON_ENABLED
#define DWARFS_PERFMON_ENABLED 0
#endif
#if DWARFS_PERFMON_ENABLED
#define PERFMON_ARG(monitor) monitor
#define PERFMON_CREATE(monitor, enabled_namespaces) \
std::shared_ptr<performance_monitor> monitor = \
performance_monitor::create(enabled_namespaces);
#define PERFMON_PROXY_DECL(instname) performance_monitor_proxy instname;
#define PERFMON_PROXY_INIT(instname, monitor, name_space) \
, instname { monitor, name_space }
#define PERFMON_TIMER_DECL(id) \
performance_monitor::timer_id const perfmon_##id##_id_;
#define PERFMON_TIMER_INIT(instname, id) \
, perfmon_##id##_id_ { instname.setup_timer(#id) }
#define PERFMON_SCOPED_SECTION(instname, id) \
auto perfmon_scoped_section_ = instname.scoped_section(perfmon_##id##_id_);
#define PERFMON_PROXY_SETUP(instname, monitor, name_space) \
instname = performance_monitor_proxy(monitor, name_space);
#define PERFMON_PROXY_INSTNAME perfmon_inst_
#define PERFMON_EXT_PROXY_DECL PERFMON_PROXY_DECL(PERFMON_PROXY_INSTNAME)
#define PERFMON_EXT_TIMER_DECL(id) \
performance_monitor::timer_id perfmon_##id##_id_;
#define PERFMON_EXT_TIMER_SETUP(scope, id) \
(scope).perfmon_##id##_id_ = (scope).PERFMON_PROXY_INSTNAME.setup_timer(#id);
#define PERFMON_EXT_SCOPED_SECTION(scope, id) \
auto perfmon_scoped_section_ = \
(scope).PERFMON_PROXY_INSTNAME.scoped_section( \
(scope).perfmon_##id##_id_);
#define PERFMON_EXT_PROXY_SETUP(scope, monitor, name_space) \
PERFMON_PROXY_SETUP((scope).PERFMON_PROXY_INSTNAME, monitor, name_space)
#define PERFMON_CLS_PROXY_DECL PERFMON_PROXY_DECL(PERFMON_PROXY_INSTNAME)
#define PERFMON_CLS_PROXY_INIT(monitor, name_space) \
PERFMON_PROXY_INIT(PERFMON_PROXY_INSTNAME, monitor, name_space)
#define PERFMON_CLS_TIMER_DECL(id) PERFMON_TIMER_DECL(id)
#define PERFMON_CLS_TIMER_INIT(id) \
PERFMON_TIMER_INIT(PERFMON_PROXY_INSTNAME, id)
#define PERFMON_CLS_SCOPED_SECTION(id) \
PERFMON_SCOPED_SECTION(PERFMON_PROXY_INSTNAME, id)
#else
#define PERFMON_ARG(monitor) nullptr
#define PERFMON_CREATE(monitor, enabled_namespaces)
#define PERFMON_PROXY_DECL(instname)
#define PERFMON_PROXY_INIT(instname, monitor, name_space)
#define PERFMON_TIMER_DECL(id)
#define PERFMON_TIMER_INIT(instname, id)
#define PERFMON_SCOPED_SECTION(instname, id)
#define PERFMON_PROXY_SETUP(instname, monitor, name_space)
#define PERFMON_EXT_PROXY_DECL
#define PERFMON_EXT_TIMER_DECL(id)
#define PERFMON_EXT_TIMER_SETUP(scope, id)
#define PERFMON_EXT_SCOPED_SECTION(scope, id)
#define PERFMON_EXT_PROXY_SETUP(scope, monitor, name_space)
#define PERFMON_CLS_PROXY_DECL
#define PERFMON_CLS_PROXY_INIT(monitor, name_space)
#define PERFMON_CLS_TIMER_DECL(id)
#define PERFMON_CLS_TIMER_INIT(id)
#define PERFMON_CLS_SCOPED_SECTION(id)
#endif
} // namespace dwarfs

View File

@ -23,6 +23,7 @@
#include <cstddef>
#include <cstring>
#include <functional>
#include <iostream>
#include <mutex>
#include <unordered_map>
#include <vector>
@ -42,6 +43,7 @@
#include "dwarfs/metadata_v2.h"
#include "dwarfs/mmif.h"
#include "dwarfs/options.h"
#include "dwarfs/performance_monitor.h"
#include "dwarfs/progress.h"
#include "dwarfs/worker_group.h"
@ -318,7 +320,8 @@ template <typename LoggerPolicy>
class filesystem_ final : public filesystem_v2::impl {
public:
filesystem_(logger& lgr, std::shared_ptr<mmif> mm,
const filesystem_options& options, int inode_offset);
const filesystem_options& options, int inode_offset,
std::shared_ptr<performance_monitor const> perfmon);
void dump(std::ostream& os, int detail_level) const override;
folly::dynamic metadata_as_dynamic() const override;
@ -365,6 +368,22 @@ class filesystem_ final : public filesystem_v2::impl {
std::vector<uint8_t> meta_buffer_;
std::optional<std::span<uint8_t const>> header_;
mutable std::unique_ptr<filesystem_info const> fsinfo_;
PERFMON_CLS_PROXY_DECL
PERFMON_CLS_TIMER_DECL(find_path)
PERFMON_CLS_TIMER_DECL(find_inode)
PERFMON_CLS_TIMER_DECL(find_inode_name)
PERFMON_CLS_TIMER_DECL(getattr)
PERFMON_CLS_TIMER_DECL(access)
PERFMON_CLS_TIMER_DECL(opendir)
PERFMON_CLS_TIMER_DECL(readdir)
PERFMON_CLS_TIMER_DECL(dirsize)
PERFMON_CLS_TIMER_DECL(readlink)
PERFMON_CLS_TIMER_DECL(readlink_expected)
PERFMON_CLS_TIMER_DECL(statvfs)
PERFMON_CLS_TIMER_DECL(open)
PERFMON_CLS_TIMER_DECL(read)
PERFMON_CLS_TIMER_DECL(readv_iovec)
PERFMON_CLS_TIMER_DECL(readv_future)
};
template <typename LoggerPolicy>
@ -395,12 +414,30 @@ filesystem_info const& filesystem_<LoggerPolicy>::get_info() const {
}
template <typename LoggerPolicy>
filesystem_<LoggerPolicy>::filesystem_(logger& lgr, std::shared_ptr<mmif> mm,
const filesystem_options& options,
int inode_offset)
filesystem_<LoggerPolicy>::filesystem_(
logger& lgr, std::shared_ptr<mmif> mm, const filesystem_options& options,
int inode_offset,
std::shared_ptr<performance_monitor const> perfmon [[maybe_unused]])
: LOG_PROXY_INIT(lgr)
, mm_(std::move(mm))
, parser_(mm_, options.image_offset) {
, parser_(mm_, options.image_offset)
// clang-format off
PERFMON_CLS_PROXY_INIT(perfmon, "filesystem_v2")
PERFMON_CLS_TIMER_INIT(find_path)
PERFMON_CLS_TIMER_INIT(find_inode)
PERFMON_CLS_TIMER_INIT(find_inode_name)
PERFMON_CLS_TIMER_INIT(getattr)
PERFMON_CLS_TIMER_INIT(access)
PERFMON_CLS_TIMER_INIT(opendir)
PERFMON_CLS_TIMER_INIT(readdir)
PERFMON_CLS_TIMER_INIT(dirsize)
PERFMON_CLS_TIMER_INIT(readlink)
PERFMON_CLS_TIMER_INIT(readlink_expected)
PERFMON_CLS_TIMER_INIT(statvfs)
PERFMON_CLS_TIMER_INIT(open)
PERFMON_CLS_TIMER_INIT(read)
PERFMON_CLS_TIMER_INIT(readv_iovec)
PERFMON_CLS_TIMER_INIT(readv_future) { // clang-format on
block_cache cache(lgr, mm_, options.block_cache);
if (parser_.has_index()) {
@ -481,52 +518,61 @@ void filesystem_<LoggerPolicy>::walk_data_order(
template <typename LoggerPolicy>
std::optional<inode_view>
filesystem_<LoggerPolicy>::find(const char* path) const {
PERFMON_CLS_SCOPED_SECTION(find_path)
return meta_.find(path);
}
template <typename LoggerPolicy>
std::optional<inode_view> filesystem_<LoggerPolicy>::find(int inode) const {
PERFMON_CLS_SCOPED_SECTION(find_inode)
return meta_.find(inode);
}
template <typename LoggerPolicy>
std::optional<inode_view>
filesystem_<LoggerPolicy>::find(int inode, const char* name) const {
PERFMON_CLS_SCOPED_SECTION(find_inode_name)
return meta_.find(inode, name);
}
template <typename LoggerPolicy>
int filesystem_<LoggerPolicy>::getattr(inode_view entry,
file_stat* stbuf) const {
PERFMON_CLS_SCOPED_SECTION(getattr)
return meta_.getattr(entry, stbuf);
}
template <typename LoggerPolicy>
int filesystem_<LoggerPolicy>::access(inode_view entry, int mode, uid_t uid,
gid_t gid) const {
PERFMON_CLS_SCOPED_SECTION(access)
return meta_.access(entry, mode, uid, gid);
}
template <typename LoggerPolicy>
std::optional<directory_view>
filesystem_<LoggerPolicy>::opendir(inode_view entry) const {
PERFMON_CLS_SCOPED_SECTION(opendir)
return meta_.opendir(entry);
}
template <typename LoggerPolicy>
std::optional<std::pair<inode_view, std::string>>
filesystem_<LoggerPolicy>::readdir(directory_view dir, size_t offset) const {
PERFMON_CLS_SCOPED_SECTION(readdir)
return meta_.readdir(dir, offset);
}
template <typename LoggerPolicy>
size_t filesystem_<LoggerPolicy>::dirsize(directory_view dir) const {
PERFMON_CLS_SCOPED_SECTION(dirsize)
return meta_.dirsize(dir);
}
template <typename LoggerPolicy>
int filesystem_<LoggerPolicy>::readlink(inode_view entry, std::string* buf,
readlink_mode mode) const {
PERFMON_CLS_SCOPED_SECTION(readlink)
return meta_.readlink(entry, buf, mode);
}
@ -534,23 +580,27 @@ template <typename LoggerPolicy>
folly::Expected<std::string, int>
filesystem_<LoggerPolicy>::readlink(inode_view entry,
readlink_mode mode) const {
PERFMON_CLS_SCOPED_SECTION(readlink_expected)
return meta_.readlink(entry, mode);
}
template <typename LoggerPolicy>
int filesystem_<LoggerPolicy>::statvfs(vfs_stat* stbuf) const {
PERFMON_CLS_SCOPED_SECTION(statvfs)
// TODO: not sure if that's the right abstraction...
return meta_.statvfs(stbuf);
}
template <typename LoggerPolicy>
int filesystem_<LoggerPolicy>::open(inode_view entry) const {
PERFMON_CLS_SCOPED_SECTION(open)
return meta_.open(entry);
}
template <typename LoggerPolicy>
ssize_t filesystem_<LoggerPolicy>::read(uint32_t inode, char* buf, size_t size,
file_off_t offset) const {
PERFMON_CLS_SCOPED_SECTION(read)
if (auto chunks = meta_.get_chunks(inode)) {
return ir_.read(buf, size, offset, *chunks);
}
@ -560,6 +610,7 @@ ssize_t filesystem_<LoggerPolicy>::read(uint32_t inode, char* buf, size_t size,
template <typename LoggerPolicy>
ssize_t filesystem_<LoggerPolicy>::readv(uint32_t inode, iovec_read_buf& buf,
size_t size, file_off_t offset) const {
PERFMON_CLS_SCOPED_SECTION(readv_iovec)
if (auto chunks = meta_.get_chunks(inode)) {
return ir_.readv(buf, size, offset, *chunks);
}
@ -570,6 +621,7 @@ template <typename LoggerPolicy>
folly::Expected<std::vector<std::future<block_range>>, int>
filesystem_<LoggerPolicy>::readv(uint32_t inode, size_t size,
file_off_t offset) const {
PERFMON_CLS_SCOPED_SECTION(readv_future)
if (auto chunks = meta_.get_chunks(inode)) {
return ir_.readv(size, offset, *chunks);
}
@ -589,10 +641,11 @@ filesystem_v2::filesystem_v2(logger& lgr, std::shared_ptr<mmif> mm)
filesystem_v2::filesystem_v2(logger& lgr, std::shared_ptr<mmif> mm,
const filesystem_options& options,
int inode_offset)
int inode_offset,
std::shared_ptr<performance_monitor const> perfmon)
: impl_(make_unique_logging_object<filesystem_v2::impl, filesystem_,
logger_policies>(
lgr, std::move(mm), options, inode_offset)) {}
lgr, std::move(mm), options, inode_offset, std::move(perfmon))) {}
void filesystem_v2::rewrite(logger& lgr, progress& prog,
std::shared_ptr<mmif> mm, filesystem_writer& writer,

View File

@ -0,0 +1,209 @@
/* vim:set ts=2 sw=2 sts=2 et: */
/**
* \author Marcus Holland-Moritz (github@mhxnet.de)
* \copyright Copyright (c) Marcus Holland-Moritz
*
* This file is part of dwarfs.
*
* dwarfs is free software: you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation, either version 3 of the License, or
* (at your option) any later version.
*
* dwarfs is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with dwarfs. If not, see <https://www.gnu.org/licenses/>.
*/
#include <algorithm>
#include <atomic>
#include <deque>
#include <mutex>
#include <string_view>
#ifdef _WIN32
#include <folly/portability/Windows.h>
#else
#include <sys/time.h>
#endif
#include <folly/lang/Bits.h>
#include <folly/stats/Histogram.h>
#include "dwarfs/performance_monitor.h"
#include "dwarfs/util.h"
namespace dwarfs {
namespace {
class single_timer {
public:
static constexpr uint64_t const histogram_interval = 1;
single_timer(std::string const& name_space, std::string const& name)
: log_hist_{1, 0, 64}
, namespace_{name_space}
, name_{name} {
total_time_.store(0);
}
void add_sample(uint64_t elapsed) {
total_time_.fetch_add(elapsed);
if ((samples_.fetch_add(1) % histogram_interval) == 0) {
auto log_time = folly::findLastSet(elapsed);
std::lock_guard lock(log_hist_mutex_);
log_hist_.addValue(log_time);
}
}
std::string_view get_namespace() const { return namespace_; }
std::string_view name() const { return name_; }
uint64_t total_latency() const { return total_time_.load(); }
void summarize(std::ostream& os, double timebase) const {
if (samples_.load() == 0) {
return;
}
size_t log_p50, log_p90, log_p99;
{
std::lock_guard lock(log_hist_mutex_);
log_p50 = log_hist_.getPercentileEstimate(0.5);
log_p90 = log_hist_.getPercentileEstimate(0.9);
log_p99 = log_hist_.getPercentileEstimate(0.99);
}
auto samples = samples_.load();
auto total_time = total_time_.load();
auto tot = timebase * total_time;
auto avg = tot / samples;
auto p50 = timebase * (UINT64_C(1) << log_p50);
auto p90 = timebase * (UINT64_C(1) << log_p90);
auto p99 = timebase * (UINT64_C(1) << log_p99);
os << "[" << namespace_ << "." << name_ << "]\n";
os << " samples: " << samples << "\n";
os << " overall: " << time_with_unit(tot) << "\n";
os << " avg latency: " << time_with_unit(avg) << "\n";
os << " p50 latency: " << time_with_unit(p50) << "\n";
os << " p90 latency: " << time_with_unit(p90) << "\n";
os << " p99 latency: " << time_with_unit(p99) << "\n\n";
}
private:
std::atomic<uint64_t> samples_;
std::atomic<uint64_t> total_time_;
folly::Histogram<size_t> log_hist_;
std::mutex mutable log_hist_mutex_;
std::string const namespace_;
std::string const name_;
};
} // namespace
class performance_monitor_impl : public performance_monitor {
public:
using timer_id = performance_monitor::timer_id;
using time_type = performance_monitor::time_type;
performance_monitor_impl(std::unordered_set<std::string> enabled_namespaces)
: timebase_{get_timebase()}
, enabled_namespaces_{std::move(enabled_namespaces)} {}
timer_id
setup_timer(std::string const& ns, std::string const& name) const override {
std::lock_guard lock(timers_mx_);
timer_id rv = timers_.size();
timers_.emplace_back(ns, name);
return rv;
}
time_type now() const override {
#ifdef _WIN32
::LARGE_INTEGER ticks;
::QueryPerformanceCounter(&ticks);
return ticks.QuadPart;
#else
struct timespec ts;
::clock_gettime(CLOCK_MONOTONIC_RAW, &ts);
return UINT64_C(1'000'000'000) * ts.tv_sec + ts.tv_nsec;
#endif
}
void add_sample(timer_id id, time_type start) const override {
auto elapsed = now() - start;
// No need to acquire the mutex here as existing timers
// never move in the deque.
timers_[id].add_sample(elapsed);
}
void summarize(std::ostream& os) const override {
int count;
{
std::lock_guard lock(timers_mx_);
count = timers_.size();
}
std::vector<std::tuple<std::string_view, uint64_t, int>> ts;
for (int i = 0; i < count; ++i) {
auto& t = timers_[i];
ts.emplace_back(t.get_namespace(), t.total_latency(), i);
}
std::sort(ts.begin(), ts.end(), [](auto const& a, auto const& b) {
return std::get<0>(a) < std::get<0>(b) ||
(std::get<0>(a) == std::get<0>(b) &&
std::get<1>(a) > std::get<1>(b));
});
for (auto const& t : ts) {
timers_[std::get<2>(t)].summarize(os, timebase_);
}
}
bool is_enabled(std::string const& ns) const override {
return enabled_namespaces_.find(ns) != enabled_namespaces_.end();
}
private:
static double get_timebase() {
#ifdef _WIN32
::LARGE_INTEGER freq;
::QueryPerformanceFrequency(&freq);
return 1.0 / freq.QuadPart;
#else
return 1e-9;
#endif
}
std::deque<single_timer> mutable timers_;
std::mutex mutable timers_mx_;
double const timebase_;
std::unordered_set<std::string> const enabled_namespaces_;
};
performance_monitor_proxy::performance_monitor_proxy(
std::shared_ptr<performance_monitor const> mon,
std::string const& mon_namespace)
: mon_{mon && mon->is_enabled(mon_namespace) ? std::move(mon) : nullptr}
, namespace_{mon_namespace} {}
std::unique_ptr<performance_monitor> performance_monitor::create(
std::unordered_set<std::string> const& enabled_namespaces) {
return enabled_namespaces.empty()
? nullptr
: std::make_unique<performance_monitor_impl>(
std::move(enabled_namespaces));
}
} // namespace dwarfs

View File

@ -34,6 +34,7 @@
#include <fmt/format.h>
#include <folly/Conv.h>
#include <folly/String.h>
#include <folly/experimental/symbolizer/SignalHandler.h>
#ifndef DWARFS_FUSE_LOWLEVEL
@ -69,6 +70,7 @@
#include "dwarfs/metadata_v2.h"
#include "dwarfs/mmap.h"
#include "dwarfs/options.h"
#include "dwarfs/performance_monitor.h"
#include "dwarfs/tool.h"
#include "dwarfs/util.h"
#include "dwarfs/version.h"
@ -102,6 +104,9 @@ struct options {
char const* cache_tidy_strategy_str{nullptr}; // TODO: const?? -> use string?
char const* cache_tidy_interval_str{nullptr}; // TODO: const?? -> use string?
char const* cache_tidy_max_age_str{nullptr}; // TODO: const?? -> use string?
#if DWARFS_PERFMON_ENABLED
char const* perfmon_enabled_str{nullptr}; // TODO: const?? -> use string?
#endif
int enable_nlink{0};
int readonly{0};
int cache_image{0};
@ -123,6 +128,19 @@ struct dwarfs_userdata {
options opts;
stream_logger lgr;
filesystem_v2 fs;
std::shared_ptr<performance_monitor> perfmon;
PERFMON_EXT_PROXY_DECL
PERFMON_EXT_TIMER_DECL(op_init)
PERFMON_EXT_TIMER_DECL(op_lookup)
PERFMON_EXT_TIMER_DECL(op_getattr)
PERFMON_EXT_TIMER_DECL(op_access)
PERFMON_EXT_TIMER_DECL(op_readlink)
PERFMON_EXT_TIMER_DECL(op_open)
PERFMON_EXT_TIMER_DECL(op_read)
PERFMON_EXT_TIMER_DECL(op_readdir)
PERFMON_EXT_TIMER_DECL(op_statfs)
PERFMON_EXT_TIMER_DECL(op_getxattr)
PERFMON_EXT_TIMER_DECL(op_listxattr)
};
// TODO: better error handling
@ -147,6 +165,9 @@ constexpr struct ::fuse_opt dwarfs_opts[] = {
DWARFS_OPT("no_cache_image", cache_image, 0),
DWARFS_OPT("cache_files", cache_files, 1),
DWARFS_OPT("no_cache_files", cache_files, 0),
#if DWARFS_PERFMON_ENABLED
DWARFS_OPT("perfmon=%s", perfmon_enabled_str, 0),
#endif
FUSE_OPT_END};
std::unordered_map<std::string_view, cache_tidy_strategy> const
@ -159,8 +180,9 @@ std::unordered_map<std::string_view, cache_tidy_strategy> const
namespace {
constexpr std::string_view pid_xattr{"user.dwarfs.driver.pid"};
constexpr std::string_view perfmon_xattr{"user.dwarfs.driver.perfmon"};
}
} // namespace
#if DWARFS_FUSE_LOWLEVEL
#define dUSERDATA \
@ -174,6 +196,7 @@ constexpr std::string_view pid_xattr{"user.dwarfs.driver.pid"};
template <typename LoggerPolicy>
void op_init_common(void* data) {
auto userdata = reinterpret_cast<dwarfs_userdata*>(data);
PERFMON_EXT_SCOPED_SECTION(*userdata, op_init)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__;
@ -209,6 +232,7 @@ void* op_init(struct fuse_conn_info* /*conn*/, struct fuse_config* /*cfg*/) {
template <typename LoggerPolicy>
void op_lookup(fuse_req_t req, fuse_ino_t parent, char const* name) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_lookup)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << parent << ", " << name << ")";
@ -283,6 +307,7 @@ int op_getattr_common(LogProxy& log_, dwarfs_userdata* userdata,
template <typename LoggerPolicy>
void op_getattr(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info*) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_getattr)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << ino << ")";
@ -302,6 +327,7 @@ void op_getattr(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info*) {
template <typename LoggerPolicy>
int op_getattr(char const* path, native_stat* st, struct fuse_file_info*) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_getattr)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << path << ")";
@ -335,6 +361,7 @@ int op_access_common(LogProxy& log_, dwarfs_userdata* userdata, int mode,
template <typename LoggerPolicy>
void op_access(fuse_req_t req, fuse_ino_t ino, int mode) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_access)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << ino << ")";
@ -351,6 +378,7 @@ void op_access(fuse_req_t req, fuse_ino_t ino, int mode) {
template <typename LoggerPolicy>
int op_access(char const* path, int mode) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_access)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << path << ")";
@ -387,6 +415,7 @@ int op_readlink_common(LogProxy& log_, dwarfs_userdata* userdata,
template <typename LoggerPolicy>
void op_readlink(fuse_req_t req, fuse_ino_t ino) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_readlink)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__;
@ -407,6 +436,7 @@ void op_readlink(fuse_req_t req, fuse_ino_t ino) {
template <typename LoggerPolicy>
int op_readlink(char const* path, char* buf, size_t buflen) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_readlink)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__;
@ -460,6 +490,7 @@ int op_open_common(LogProxy& log_, dwarfs_userdata* userdata,
template <typename LoggerPolicy>
void op_open(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info* fi) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_open)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__;
@ -477,6 +508,7 @@ void op_open(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info* fi) {
template <typename LoggerPolicy>
int op_open(char const* path, struct fuse_file_info* fi) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_open)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__;
@ -491,6 +523,7 @@ template <typename LoggerPolicy>
void op_read(fuse_req_t req, fuse_ino_t ino, size_t size, file_off_t off,
struct fuse_file_info* fi) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_read)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__;
@ -535,6 +568,7 @@ template <typename LoggerPolicy>
int op_read(char const* path, char* buf, size_t size, native_off_t off,
struct fuse_file_info* fi) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_read)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__;
@ -569,6 +603,7 @@ template <typename LoggerPolicy>
void op_readdir(fuse_req_t req, fuse_ino_t ino, size_t size, file_off_t off,
struct fuse_file_info* /*fi*/) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_readdir)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << ino << ", " << size << ", " << off << ")";
@ -637,6 +672,7 @@ int op_readdir(char const* path, void* buf, fuse_fill_dir_t filler,
native_off_t off, struct fuse_file_info* /*fi*/,
enum fuse_readdir_flags /*flags*/) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_readdir)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << path << ")";
@ -726,6 +762,7 @@ int op_statfs_common(LogProxy& log_, dwarfs_userdata* userdata,
template <typename LoggerPolicy>
void op_statfs(fuse_req_t req, fuse_ino_t /*ino*/) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_statfs)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__;
@ -744,6 +781,7 @@ void op_statfs(fuse_req_t req, fuse_ino_t /*ino*/) {
template <typename LoggerPolicy>
int op_statfs(char const* path, native_statvfs* st) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_statfs)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << path << ")";
@ -758,6 +796,7 @@ template <typename LoggerPolicy>
void op_getxattr(fuse_req_t req, fuse_ino_t ino, char const* name,
size_t size) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_getxattr)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << ino << ", " << name << ", " << size << ")";
@ -765,14 +804,34 @@ void op_getxattr(fuse_req_t req, fuse_ino_t ino, char const* name,
int err = ENODATA;
try {
if (ino == FUSE_ROOT_ID && name == pid_xattr) {
auto pidstr = std::to_string(::getpid());
if (size > 0) {
fuse_reply_buf(req, pidstr.data(), pidstr.size());
} else {
fuse_reply_xattr(req, pidstr.size());
if (ino == FUSE_ROOT_ID) {
if (name == pid_xattr) {
auto pidstr = std::to_string(::getpid());
if (size > 0) {
fuse_reply_buf(req, pidstr.data(), pidstr.size());
} else {
fuse_reply_xattr(req, pidstr.size());
}
return;
} else if (name == perfmon_xattr) {
#if DWARFS_PERFMON_ENABLED
std::ostringstream oss;
if (userdata->perfmon) {
userdata->perfmon->summarize(oss);
} else {
oss << "performance monitor is disabled";
}
auto summary = oss.str();
#else
auto summary = std::string("no performance monitor support");
#endif
if (size > 0) {
fuse_reply_buf(req, summary.data(), summary.size());
} else {
fuse_reply_xattr(req, summary.size());
}
return;
}
return;
}
} catch (dwarfs::system_error const& e) {
LOG_ERROR << e.what();
@ -788,6 +847,7 @@ void op_getxattr(fuse_req_t req, fuse_ino_t ino, char const* name,
template <typename LoggerPolicy>
int op_getxattr(char const* path, char const* name, char* value, size_t size) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_getxattr)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << path << ", " << name << ", " << size << ")";
@ -821,11 +881,13 @@ int op_getxattr(char const* path, char const* name, char* value, size_t size) {
template <typename LoggerPolicy>
int op_listxattr(char const* path, char* list, size_t size) {
dUSERDATA;
PERFMON_EXT_SCOPED_SECTION(*userdata, op_listxattr)
LOG_PROXY(LoggerPolicy, userdata->lgr);
LOG_DEBUG << __func__ << "(" << path << ", " << size << ")";
const std::string all_xattr = std::string(pid_xattr) + '\0';
const std::string all_xattr =
std::string(pid_xattr) + '\0' + std::string(perfmon_xattr) + '\0';
if (size > 0) {
if (size < all_xattr.size()) {
@ -861,6 +923,9 @@ void usage(char const* progname) {
<< " -o tidy_strategy=NAME (none)|time|swap\n"
<< " -o tidy_interval=TIME interval for cache tidying (5m)\n"
<< " -o tidy_max_age=TIME tidy blocks after this time (10m)\n"
#if DWARFS_PERFMON_ENABLED
<< " -o perfmon=name[,...] enable performance monitor\n"
#endif
<< "\n";
#if DWARFS_FUSE_LOWLEVEL && FUSE_USE_VERSION >= 30
@ -1071,8 +1136,33 @@ void load_filesystem(dwarfs_userdata& userdata) {
#endif
;
userdata.fs = filesystem_v2(
userdata.lgr, std::make_shared<mmap>(opts.fsimage), fsopts, inode_offset);
std::unordered_set<std::string> perfmon_enabled;
#if DWARFS_PERFMON_ENABLED
if (opts.perfmon_enabled_str) {
folly::splitTo<std::string>(
',', opts.perfmon_enabled_str,
std::inserter(perfmon_enabled, perfmon_enabled.begin()));
}
#endif
userdata.perfmon = performance_monitor::create(perfmon_enabled);
PERFMON_EXT_PROXY_SETUP(userdata, userdata.perfmon, "fuse")
PERFMON_EXT_TIMER_SETUP(userdata, op_init)
PERFMON_EXT_TIMER_SETUP(userdata, op_lookup)
PERFMON_EXT_TIMER_SETUP(userdata, op_getattr)
PERFMON_EXT_TIMER_SETUP(userdata, op_access)
PERFMON_EXT_TIMER_SETUP(userdata, op_readlink)
PERFMON_EXT_TIMER_SETUP(userdata, op_open)
PERFMON_EXT_TIMER_SETUP(userdata, op_read)
PERFMON_EXT_TIMER_SETUP(userdata, op_readdir)
PERFMON_EXT_TIMER_SETUP(userdata, op_statfs)
PERFMON_EXT_TIMER_SETUP(userdata, op_getxattr)
PERFMON_EXT_TIMER_SETUP(userdata, op_listxattr)
userdata.fs =
filesystem_v2(userdata.lgr, std::make_shared<mmap>(opts.fsimage), fsopts,
inode_offset, userdata.perfmon);
ti << "file system initialized";
}
@ -1198,6 +1288,12 @@ int dwarfs_main(int argc, char** argv) {
return 1;
}
SCOPE_EXIT {
if (userdata.perfmon) {
userdata.perfmon->summarize(std::cerr);
}
};
#if FUSE_USE_VERSION >= 30
#if DWARFS_FUSE_LOWLEVEL
return run_fuse(args, fuse_opts, userdata);

View File

@ -32,6 +32,7 @@
#include "dwarfs/logger.h"
#include "dwarfs/mmap.h"
#include "dwarfs/options.h"
#include "dwarfs/performance_monitor.h"
#include "dwarfs/tool.h"
#include "dwarfs/util.h"
#include "dwarfs_tool_main.h"
@ -43,6 +44,9 @@ namespace dwarfs {
int dwarfsextract_main(int argc, sys_char** argv) {
std::string filesystem, output, format, cache_size_str, log_level,
image_offset;
#if DWARFS_PERFMON_ENABLED
std::string perfmon_str;
#endif
size_t num_workers;
bool continue_on_error{false}, disable_integrity_check{false},
stdout_progress{false};
@ -80,6 +84,11 @@ int dwarfsextract_main(int argc, sys_char** argv) {
("log-level,l",
po::value<std::string>(&log_level)->default_value("warn"),
"log level (error, warn, info, debug, trace)")
#if DWARFS_PERFMON_ENABLED
("perfmon",
po::value<std::string>(&perfmon_str),
"enable performance monitor")
#endif
("help,h",
"output help message and exit");
// clang-format on
@ -118,7 +127,19 @@ int dwarfsextract_main(int argc, sys_char** argv) {
fsopts.block_cache.disable_block_integrity_check = disable_integrity_check;
fsopts.metadata.enable_nlink = true;
filesystem_v2 fs(lgr, std::make_shared<mmap>(filesystem), fsopts);
std::unordered_set<std::string> perfmon_enabled;
#if DWARFS_PERFMON_ENABLED
if (!perfmon_str.empty()) {
folly::splitTo<std::string>(
',', perfmon_str,
std::inserter(perfmon_enabled, perfmon_enabled.begin()));
}
#endif
std::shared_ptr<performance_monitor> perfmon =
performance_monitor::create(perfmon_enabled);
filesystem_v2 fs(lgr, std::make_shared<mmap>(filesystem), fsopts, 0,
perfmon);
filesystem_extractor fsx(lgr);
if (format.empty()) {
@ -157,6 +178,10 @@ int dwarfsextract_main(int argc, sys_char** argv) {
rv = fsx.extract(fs, fsx_opts) ? 0 : 2;
fsx.close();
if (perfmon) {
perfmon->summarize(std::cerr);
}
} catch (runtime_error const& e) {
std::cerr << folly::exceptionStr(e) << "\n";
return 1;