[k2] add temporary stats for confdata and instance cache calls

Author: apolyakov

runtime-light/state/instance-state.cpp

@@ -244,4 +244,8 @@ kphp::coro::task<> InstanceState::run_instance_epilogue() noexcept {
   while (!ignore_answer_request_await_set.empty()) {
     co_await ignore_answer_request_await_set.next();
   }
+
+  // TEMPORARY: log instance-cache and confdata timings
+  kphp::log::info("instance stats (approximately): confdata -> {}ms, instance cache -> {}ms", confdata_instance_state.time_ns >> 20,
+                  instance_cache_instance_state.time_ns >> 20);
 }

runtime-light/stdlib/confdata/confdata-functions.cpp

@@ -6,10 +6,12 @@
 
 #include <algorithm>
 #include <cstddef>
+#include <memory>
 #include <span>
 #include <string_view>
 #include <utility>
 
+#include "common/containers/final_action.h"
 #include "runtime-common/core/allocator/script-allocator.h"
 #include "runtime-common/core/runtime-core.h"
 #include "runtime-common/core/std/containers.h"
@@ -52,11 +54,20 @@ kphp::coro::task<mixed> f$confdata_get_value(string key) noexcept {
     co_return mixed{};
   }
 
-  auto& confdata_key_cache{ConfdataInstanceState::get().key_cache()};
+  auto& confdata_instance_st{ConfdataInstanceState::get()};
+  auto& confdata_key_cache{confdata_instance_st.key_cache()};
   if (auto it{confdata_key_cache.find(key)}; it != confdata_key_cache.end()) {
     co_return it->second;
   }
 
+  k2::SystemTime start_time{};
+  k2::system_time(std::addressof(start_time));
+  const auto finalizer{vk::finally([&start_time, &confdata_instance_st] noexcept {
+    k2::SystemTime end_time{};
+    k2::system_time(std::addressof(end_time));
+    confdata_instance_st.time_ns += (end_time.since_epoch_ns - start_time.since_epoch_ns);
+  })};
+
   tl::ConfdataGet confdata_get{.key = {.value = {key.c_str(), key.size()}}};
   tl::storer tls{confdata_get.footprint()};
   confdata_get.store(tls);
@@ -93,11 +104,20 @@ kphp::coro::task<array<mixed>> f$confdata_get_values_by_any_wildcard(string wild
     co_return array<mixed>{};
   }
 
-  auto& confdata_wildcard_cache{ConfdataInstanceState::get().wildcard_cache()};
+  auto& confdata_instance_st{ConfdataInstanceState::get()};
+  auto& confdata_wildcard_cache{confdata_instance_st.wildcard_cache()};
   if (auto it{confdata_wildcard_cache.find(wildcard)}; it != confdata_wildcard_cache.end()) {
     co_return it->second;
   }
 
+  k2::SystemTime start_time{};
+  k2::system_time(std::addressof(start_time));
+  const auto finalizer{vk::finally([&start_time, &confdata_instance_st] noexcept {
+    k2::SystemTime end_time{};
+    k2::system_time(std::addressof(end_time));
+    confdata_instance_st.time_ns += (end_time.since_epoch_ns - start_time.since_epoch_ns);
+  })};
+
   const std::string_view wildcard_view{wildcard.c_str(), wildcard.size()};
 
   const tl::ConfdataGetWildcard confdata_get_wildcard{.wildcard = {.value = wildcard_view}};

runtime-light/stdlib/confdata/confdata-state.h

@@ -18,6 +18,8 @@ class ConfdataInstanceState final : private vk::not_copyable {
   kphp::stl::unordered_map<string, array<mixed>, kphp::memory::script_allocator, hasher_type> m_wildcard_cache;
 
 public:
+  size_t time_ns{};
+
   ConfdataInstanceState() noexcept = default;
 
   auto& key_cache() noexcept {

runtime-light/stdlib/instance-cache/instance-cache-functions.h

@@ -46,6 +46,15 @@ kphp::coro::task<bool> f$instance_cache_store(string key, InstanceType instance,
     ttl = 0;
   }
 
+  auto& instance_cache_st{InstanceCacheInstanceState::get()};
+  k2::SystemTime start_time{};
+  k2::system_time(std::addressof(start_time));
+  const auto finalizer{vk::finally([&start_time, &instance_cache_st] noexcept {
+    k2::SystemTime end_time{};
+    k2::system_time(std::addressof(end_time));
+    instance_cache_st.time_ns += (end_time.since_epoch_ns - start_time.since_epoch_ns);
+  })};
+
   auto serialized_instance{f$instance_serialize(instance)};
   if (!serialized_instance.has_value()) [[unlikely]] {
     kphp::log::warning("can't serialize instance: key -> {}", key.c_str());
@@ -78,12 +87,21 @@ kphp::coro::task<bool> f$instance_cache_store(string key, InstanceType instance,
 
 template<typename InstanceType>
 kphp::coro::task<InstanceType> f$instance_cache_fetch(string /*class_name*/, string key, bool /*even_if_expired*/ = false) noexcept {
-  auto& request_cache{InstanceCacheInstanceState::get().request_cache};
+  auto& instance_cache_st{InstanceCacheInstanceState::get()};
+  auto& request_cache{instance_cache_st.request_cache};
   if (auto it{request_cache.find(key)}; it != request_cache.end()) {
     auto cached_instance{from_mixed<InstanceType>(it->second, {})};
     co_return std::move(cached_instance);
   }
 
+  k2::SystemTime start_time{};
+  k2::system_time(std::addressof(start_time));
+  const auto finalizer{vk::finally([&start_time, &instance_cache_st] noexcept {
+    k2::SystemTime end_time{};
+    k2::system_time(std::addressof(end_time));
+    instance_cache_st.time_ns += (end_time.since_epoch_ns - start_time.since_epoch_ns);
+  })};
+
   tl::CacheFetch cache_fetch{.key = tl::string{.value = {key.c_str(), key.size()}}};
   tl::storer tls{cache_fetch.footprint()};
   cache_fetch.store(tls);

runtime-light/stdlib/instance-cache/instance-cache-state.h

@@ -12,6 +12,7 @@
 #include "runtime-common/core/std/containers.h"
 
 struct InstanceCacheInstanceState final : private vk::not_copyable {
+  size_t time_ns{};
   kphp::stl::unordered_map<string, mixed, kphp::memory::script_allocator, decltype([](const string& s) noexcept { return static_cast<size_t>(s.hash()); })>
       request_cache;