From e090131b8705124e8ab78de076f4e8f25ba7746e Mon Sep 17 00:00:00 2001 From: Maxime Coste Date: Sat, 12 Aug 2023 13:06:53 +1000 Subject: [PATCH] Add a ProfileScope helper class to replace most profiling uses --- src/command_manager.cc | 10 ++++------ src/commands.cc | 12 ++++-------- src/hook_manager.cc | 14 ++++---------- src/main.cc | 12 +++++------- src/profile.hh | 38 ++++++++++++++++++++++++++++++++++++++ src/window.cc | 17 +++++------------ 6 files changed, 60 insertions(+), 43 deletions(-) create mode 100644 src/profile.hh diff --git a/src/command_manager.cc b/src/command_manager.cc index e1b44888..68ea6c63 100644 --- a/src/command_manager.cc +++ b/src/command_manager.cc @@ -8,6 +8,7 @@ #include "file.hh" #include "optional.hh" #include "option_types.hh" +#include "profile.hh" #include "ranges.hh" #include "regex.hh" #include "register_manager.hh" @@ -525,12 +526,9 @@ void CommandManager::execute_single_command(CommandParameters params, if (debug_flags & DebugFlags::Commands) write_to_debug_buffer(format("command {}", join(params, ' '))); - auto profile = on_scope_end([&, start = (debug_flags & DebugFlags::Profile) ? Clock::now() : Clock::time_point{}] { - if (not (debug_flags & DebugFlags::Profile)) - return; - auto full = std::chrono::duration_cast(Clock::now() - start); - write_to_debug_buffer(format("command {} took {} us", params[0], full.count())); - }); + ProfileScope profile{debug_flags, [&](std::chrono::microseconds duration) { + write_to_debug_buffer(format("command {} took {} us", params[0], duration.count())); + }}; command_it->value.func({{params.begin()+1, params.end()}, command_it->value.param_desc}, context, shell_context); diff --git a/src/commands.cc b/src/commands.cc index 519d040c..16d04f2d 100644 --- a/src/commands.cc +++ b/src/commands.cc @@ -20,6 +20,7 @@ #include "option_manager.hh" #include "option_types.hh" #include "parameters_parser.hh" +#include "profile.hh" #include "ranges.hh" #include "ranked_match.hh" #include "regex.hh" @@ -1639,9 +1640,9 @@ const CommandDesc source_cmd = { filename_completer, [](const ParametersParser& parser, Context& context, const ShellContext&) { - const DebugFlags debug_flags = context.options()["debug"].get(); - const bool profile = debug_flags & DebugFlags::Profile; - auto start_time = profile ? Clock::now() : Clock::time_point{}; + ProfileScope profile{context, [&](std::chrono::microseconds duration) { + write_to_debug_buffer(format("sourcing '{}' took {} us", parser[0], (size_t)duration.count())); + }}; String path = real_path(parse_filename(parser[0])); MappedFile file_content{path}; @@ -1656,11 +1657,6 @@ const CommandDesc source_cmd = { write_to_debug_buffer(format("{}:{}", parser[0], err.what())); throw; } - - using namespace std::chrono; - if (profile) - write_to_debug_buffer(format("sourcing '{}' took {} us", parser[0], - (size_t)duration_cast(Clock::now() - start_time).count())); } }; diff --git a/src/hook_manager.cc b/src/hook_manager.cc index afab5461..a1b29434 100644 --- a/src/hook_manager.cc +++ b/src/hook_manager.cc @@ -8,6 +8,7 @@ #include "face_registry.hh" #include "option.hh" #include "option_types.hh" +#include "profile.hh" #include "ranges.hh" #include "regex.hh" @@ -138,9 +139,9 @@ void HookManager::run_hook(Hook hook, StringView param, Context& context) m_hooks_trash.clear(); }); - const DebugFlags debug_flags = context.options()["debug"].get(); - const bool profile = debug_flags & DebugFlags::Profile; - auto start_time = profile ? Clock::now() : TimePoint{}; + ProfileScope profile{context, [&](std::chrono::microseconds duration) { + write_to_debug_buffer(format("hook '{}({})' took {} us", hook_name, param, (size_t)duration.count())); + }}; bool hook_error = false; for (auto& to_run : hooks_to_run) @@ -171,13 +172,6 @@ void HookManager::run_hook(Hook hook, StringView param, Context& context) context.print_status({ format("Error running hooks for '{}' '{}', see *debug* buffer", hook_name, param), context.faces()["Error"] }); - - if (profile) - { - auto end_time = Clock::now(); - auto full = std::chrono::duration_cast(end_time - start_time); - write_to_debug_buffer(format("hook '{}({})' took {} us", hook_name, param, (size_t)full.count())); - } } } diff --git a/src/main.cc b/src/main.cc index a6762a2d..2e844d62 100644 --- a/src/main.cc +++ b/src/main.cc @@ -16,6 +16,7 @@ #include "terminal_ui.hh" #include "option_types.hh" #include "parameters_parser.hh" +#include "profile.hh" #include "ranges.hh" #include "regex.hh" #include "register_manager.hh" @@ -806,14 +807,11 @@ int run_server(StringView session, StringView server_init, write_to_debug_buffer("*** This is the debug buffer, where debug info will be written ***"); #ifdef KAK_DEBUG - const auto start_time = Clock::now(); - UnitTest::run_all_tests(); - - if (debug_flags & DebugFlags::Profile) { - using namespace std::chrono; - write_to_debug_buffer(format("running the unit tests took {} ms", - duration_cast(Clock::now() - start_time).count())); + ProfileScope profile{debug_flags, [&](std::chrono::microseconds duration) { + write_to_debug_buffer(format("running the unit tests took {} ms", duration.count())); + }}; + UnitTest::run_all_tests(); } #endif diff --git a/src/profile.hh b/src/profile.hh new file mode 100644 index 00000000..7feff017 --- /dev/null +++ b/src/profile.hh @@ -0,0 +1,38 @@ +#ifndef profile_hh_INCLUDED +#define profile_hh_INCLUDED + +#include "option.hh" +#include "clock.hh" + +namespace Kakoune +{ + +template +class ProfileScope +{ +public: + ProfileScope(const DebugFlags debug_flags, Callback&& callback, bool active = true) + : m_active{active and debug_flags & DebugFlags::Profile}, + m_start_time(m_active ? Clock::now() : Clock::time_point{}), + m_callback{std::move(callback)} + {} + + ProfileScope(const Context& context, Callback&& callback, bool active = true) + : ProfileScope{context.options()["debug"].get(), std::move(callback), active} + {} + + ~ProfileScope() + { + if (m_active) + m_callback(std::chrono::duration_cast(Clock::now() - m_start_time)); + } + +private: + bool m_active; + Clock::time_point m_start_time; + Callback m_callback; +}; + +} + +#endif // profile_hh_INCLUDED diff --git a/src/window.cc b/src/window.cc index 7926183f..2a0469cf 100644 --- a/src/window.cc +++ b/src/window.cc @@ -10,6 +10,7 @@ #include "buffer_utils.hh" #include "option.hh" #include "option_types.hh" +#include "profile.hh" #include @@ -119,10 +120,10 @@ bool Window::needs_redraw(const Context& context) const const DisplayBuffer& Window::update_display_buffer(const Context& context) { - const bool profile = context.options()["debug"].get() & - DebugFlags::Profile; - - auto start_time = profile ? Clock::now() : Clock::time_point{}; + ProfileScope profile{context, [&](std::chrono::microseconds duration) { + write_to_debug_buffer(format("window display update for '{}' took {} us", + buffer().display_name(), (size_t)duration.count())); + }, not (buffer().flags() & Buffer::Flags::Debug)}; if (m_display_buffer.timestamp() != -1) { @@ -168,14 +169,6 @@ const DisplayBuffer& Window::update_display_buffer(const Context& context) set_position({setup.first_line, setup.first_column}); m_last_setup = build_setup(context); - if (profile and not (buffer().flags() & Buffer::Flags::Debug)) - { - using namespace std::chrono; - auto duration = duration_cast(Clock::now() - start_time); - write_to_debug_buffer(format("window display update for '{}' took {} us", - buffer().display_name(), (size_t)duration.count())); - } - return m_display_buffer; }