diff --git a/osquery/dispatcher/scheduler.cpp b/osquery/dispatcher/scheduler.cpp index 21bbebb6c3d..91f7e612003 100644 --- a/osquery/dispatcher/scheduler.cpp +++ b/osquery/dispatcher/scheduler.cpp @@ -185,8 +185,12 @@ void SchedulerRunner::start() { if (query.splayed_interval > 0 && i % query.splayed_interval == 0) { TablePlugin::kCacheInterval = query.splayed_interval; TablePlugin::kCacheStep = i; - launchWithProfiling( - name, std::bind(launchQuery, std::ref(name), std::ref(query))); + { + CodeProfiler codeProfiler( + (boost::format("scheduler.executing_query.%s") % name).str()); + const auto status = launchQuery(name, query); + codeProfiler.appendName(status.ok() ? ".success" : ".failure"); + }; } })); // Configuration decorators run on 60 second intervals only. diff --git a/osquery/profiler/posix/profiler.cpp b/osquery/profiler/posix/profiler.cpp index 7d0f0895e68..4863d5d32a0 100644 --- a/osquery/profiler/posix/profiler.cpp +++ b/osquery/profiler/posix/profiler.cpp @@ -42,6 +42,39 @@ int getRusageWho() { #endif } +enum class RusageError { FatalError = 1 }; + +static Expected callRusage() { + struct rusage stats; + const int who = getRusageWho(); + auto rusage_status = getrusage(who, &stats); + if (rusage_status != -1) { + return stats; + } else { + return createError(RusageError::FatalError, "") + << "Linux query profiling failed. error code: " << rusage_status + << " message: " << boost::io::quoted(strerror(errno)); + } +} + +class CodeProfilerData { + public: + CodeProfilerData() + : rusage_data_(callRusage()), + wall_time_(std::chrono::steady_clock::now()) {} + + const std::chrono::time_point& getWallTime() { + return wall_time_; + } + Expected takeRusageData() { + return std::move(rusage_data_); + } + + private: + Expected rusage_data_; + std::chrono::time_point wall_time_; +}; + void recordRusageStatDifference(int64_t start_stat, int64_t end_stat, const std::string& stat_name) { @@ -99,68 +132,42 @@ void recordRusageStatDifference(const struct rusage& start_stats, monitoring_path_prefix + ".time.system"); } -enum class RusageError { FatalError = 1 }; -Expected callRusage() { - struct rusage stats; - const int who = getRusageWho(); - auto rusage_status = getrusage(who, &stats); - if (rusage_status != -1) { - return stats; - } else { - return createError(RusageError::FatalError, "") - << "Linux query profiling failed. error code: " << rusage_status - << " message: " << boost::io::quoted(strerror(errno)); - } -} - -Status launchQueryWithPosixProfiling(const std::string& name, - std::function launcher) { - auto rusage_start = callRusage(); - +void recordRusageStatDifference(CodeProfilerData& start_stats, + CodeProfilerData& end_stats, + const std::string& monitoring_path_prefix) { + auto rusage_start = start_stats.takeRusageData(); if (!rusage_start) { LOG(ERROR) << "rusage_start error: " << rusage_start.getError().getFullMessageRecursive(); - } - - const auto start_time_point = std::chrono::steady_clock::now(); - - const auto status = launcher(); - - const auto query_duration = - std::chrono::duration_cast( - std::chrono::steady_clock::now() - start_time_point); - - const auto monitoring_path_prefix = - (boost::format("scheduler.executing_query.%s.%s") % name % - (status.ok() ? "success" : "failure")) - .str(); - - if (rusage_start) { - const auto rusage_end = callRusage(); - - if (rusage_end) { - recordRusageStatDifference( - *rusage_start, *rusage_end, monitoring_path_prefix); - } else { + } else { + auto rusage_end = end_stats.takeRusageData(); + if (!rusage_end) { LOG(ERROR) << "rusage_end error: " << rusage_end.getError().getFullMessageRecursive(); + } else { + recordRusageStatDifference( + *rusage_start, *rusage_end, monitoring_path_prefix); } } - monitoring::record(monitoring_path_prefix + ".time.real.millis", + const auto query_duration = + std::chrono::duration_cast( + end_stats.getWallTime() - start_stats.getWallTime()); + monitoring::record(monitoring_path_prefix + ".time.wall.millis", query_duration.count(), monitoring::PreAggregationType::Min); - - return status; } + } // namespace -Status launchWithProfiling(const std::string& name, - std::function launcher) { +CodeProfiler::CodeProfiler(std::string name) + : name_(name), code_profiler_data_(new CodeProfilerData()) {} + +CodeProfiler::~CodeProfiler() { if (Killswitch::get().isPosixProfilingEnabled()) { - return launchQueryWithPosixProfiling(name, launcher); - } else { - return launcher(); // Just execute the query + CodeProfilerData code_profiler_data_end; + recordRusageStatDifference( + *code_profiler_data_, code_profiler_data_end, name_); } } diff --git a/osquery/profiler/profiler.h b/osquery/profiler/profiler.h index c7f64d4decb..f9b4fc6d4ae 100644 --- a/osquery/profiler/profiler.h +++ b/osquery/profiler/profiler.h @@ -10,13 +10,27 @@ #pragma once -#include +#include #include -#include - namespace osquery { - -Status launchWithProfiling(const std::string& name, - std::function launcher); +namespace { +class CodeProfilerData; } + +class CodeProfiler final { + public: + CodeProfiler(std::string name); + + ~CodeProfiler(); + + void appendName(const std::string& appendName) { + name_ += appendName; + } + + private: + std::string name_; + std::unique_ptr code_profiler_data_; +}; + +} // namespace osquery diff --git a/osquery/profiler/windows/profiler.cpp b/osquery/profiler/windows/profiler.cpp index 5378b2776fa..c62bd397f2b 100644 --- a/osquery/profiler/windows/profiler.cpp +++ b/osquery/profiler/windows/profiler.cpp @@ -17,23 +17,38 @@ #include namespace osquery { +namespace { -Status launchWithProfiling(const std::string& name, - std::function launcher) { - const auto start_time_point = std::chrono::steady_clock::now(); - const auto status = launcher(); - const auto monitoring_path_prefix = - (boost::format("scheduler.executing_query.%s.%s") % name % - (status.ok() ? "success" : "failure")) - .str(); - const auto query_duration = - std::chrono::duration_cast( - std::chrono::steady_clock::now() - start_time_point); +class CodeProfilerData { + public: + CodeProfilerData() : wall_time_(std::chrono::steady_clock::now()) {} + + const std::chrono::time_point& getWallTime() { + return wall_time_; + } + + private: + std::chrono::time_point wall_time_; +}; + +} // namespace + +CodeProfiler::CodeProfiler(std::string name) + : name_(name), code_profiler_data_(new CodeProfilerData()) {} + +CodeProfiler::~CodeProfiler() { if (Killswitch::get().isWindowsProfilingEnabled()) { - monitoring::record(monitoring_path_prefix + ".time.real.millis", + CodeProfilerData code_profiler_data_end; + + const auto query_duration = + std::chrono::duration_cast( + code_profiler_data_end.getWallTime() - + code_profiler_data_->getWallTime()); + + monitoring::record(monitoring_path_prefix + ".time.wall.millis", query_duration.count(), monitoring::PreAggregationType::Min); } - return status; } + } // namespace osquery