Skip to content

Commit

Permalink
refactor(logger): make timed_loggers more efficient if unused
Browse files Browse the repository at this point in the history
  • Loading branch information
mhx committed Oct 19, 2024
1 parent 31ba743 commit c1f5c08
Show file tree
Hide file tree
Showing 3 changed files with 68 additions and 41 deletions.
50 changes: 9 additions & 41 deletions include/dwarfs/logger.h
Original file line number Diff line number Diff line change
Expand Up @@ -22,9 +22,7 @@
#pragma once

#include <atomic>
#include <chrono>
#include <cstddef>
#include <ctime>
#include <iosfwd>
#include <memory>
#include <mutex>
Expand All @@ -37,10 +35,7 @@
#include <type_traits>
#include <utility>

#include <boost/chrono/thread_clock.hpp>

#include <dwarfs/detail/logging_class_factory.h>
#include <dwarfs/util.h>

namespace dwarfs {

Expand Down Expand Up @@ -162,53 +157,26 @@ class level_log_entry {

class timed_level_log_entry {
public:
using thread_clock = boost::chrono::thread_clock;

timed_level_log_entry(logger& lgr, logger::level_type level,
std::source_location loc, bool with_cpu = false)
: lgr_(lgr)
, level_(level)
, start_time_(std::chrono::high_resolution_clock::now())
, with_cpu_(with_cpu)
, loc_(loc) {
if (with_cpu) {
cpu_start_time_ = thread_clock::now();
}
}

std::source_location loc, bool with_cpu = false);
timed_level_log_entry(timed_level_log_entry const&) = delete;

~timed_level_log_entry() {
if (output_) {
std::chrono::duration<double> sec =
std::chrono::high_resolution_clock::now() - start_time_;
oss_ << " [" << time_with_unit(sec.count());
if (with_cpu_) {
boost::chrono::duration<double> cpu_time_sec =
thread_clock::now() - cpu_start_time_;
oss_ << ", " << time_with_unit(cpu_time_sec.count()) << " CPU";
}
oss_ << "]";
lgr_.write(level_, oss_.str(), loc_);
}
}
~timed_level_log_entry();

template <typename T>
timed_level_log_entry& operator<<(const T& val) {
output_ = true;
oss_ << val;
if (state_) {
output_ = true;
oss_ << val;
}
return *this;
}

private:
logger& lgr_;
class state;

std::ostringstream oss_;
logger::level_type const level_;
std::chrono::time_point<std::chrono::high_resolution_clock> start_time_;
thread_clock::time_point cpu_start_time_;
bool output_{false};
bool const with_cpu_;
std::source_location const loc_;
std::unique_ptr<state const> state_;
};

class no_log_entry {
Expand Down
58 changes: 58 additions & 0 deletions src/logger.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
* along with dwarfs. If not, see <https://www.gnu.org/licenses/>.
*/

#include <chrono>
#include <cstring>
#include <exception>
#include <iterator>
Expand All @@ -27,6 +28,8 @@
#include <folly/Conv.h>
#include <folly/small_vector.h>

#include <boost/chrono/thread_clock.hpp>

#include <dwarfs/config.h>

#ifdef DWARFS_STACKTRACE_ENABLED
Expand Down Expand Up @@ -288,6 +291,61 @@ void stream_logger::set_threshold(level_type threshold) {
}
}

class timed_level_log_entry::state {
public:
using thread_clock = boost::chrono::thread_clock;

state(logger& lgr, logger::level_type level, std::source_location loc,
bool with_cpu)
: lgr_{lgr}
, level_{level}
, start_time_{std::chrono::high_resolution_clock::now()}
, cpu_start_time_{cpu_now(with_cpu)}
, loc_{loc} {}

void log(std::ostringstream& oss) const {
std::chrono::duration<double> sec =
std::chrono::high_resolution_clock::now() - start_time_;
oss << " [" << time_with_unit(sec.count());
if (cpu_start_time_) {
boost::chrono::duration<double> cpu_time_sec =
thread_clock::now() - cpu_start_time_.value();
oss << ", " << time_with_unit(cpu_time_sec.count()) << " CPU";
}
oss << "]";
lgr_.write(level_, oss.str(), loc_);
}

private:
static std::optional<thread_clock::time_point> cpu_now(bool with_cpu) {
if (with_cpu) {
return thread_clock::now();
}
return std::nullopt;
}

logger& lgr_;
logger::level_type const level_;
std::chrono::time_point<std::chrono::high_resolution_clock> const start_time_;
std::optional<thread_clock::time_point> const cpu_start_time_;
std::source_location const loc_;
};

timed_level_log_entry::timed_level_log_entry(logger& lgr,
logger::level_type level,
std::source_location loc,
bool with_cpu) {
if (level <= lgr.threshold()) {
state_ = std::make_unique<state>(lgr, level, loc, with_cpu);
}
}

timed_level_log_entry::~timed_level_log_entry() {
if (state_ && output_) {
state_->log(oss_);
}
}

namespace detail {

bool logging_class_factory::is_policy_name(logger const& lgr,
Expand Down
1 change: 1 addition & 0 deletions src/utility/rewrite_filesystem.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
#include <dwarfs/history.h>
#include <dwarfs/logger.h>
#include <dwarfs/reader/filesystem_v2.h>
#include <dwarfs/util.h>
#include <dwarfs/utility/rewrite_options.h>
#include <dwarfs/writer/category_resolver.h>
#include <dwarfs/writer/filesystem_writer.h>
Expand Down

0 comments on commit c1f5c08

Please sign in to comment.