little statement_cache test changes

include/matador/orm/session.hpp

@@ -70,7 +70,7 @@ public:
 
   template<typename Type>
   utils::result<sql::query_result<Type>, utils::error> find() {
-    auto c = pool_.acquire();
+    const auto c = pool_.acquire();
     if (!c.valid()) {
       return utils::failure(make_error(error_code::NoConnectionAvailable, "Failed to acquire connection."));
     }

source/orm/sql/statement_cache.cpp

@@ -9,13 +9,7 @@
 namespace matador::sql {
 namespace internal {
 class statement_cache_proxy final : public statement_proxy {
-public:
-  struct retry_config {
-    size_t max_attempts{10};
-    std::chrono::milliseconds initial_wait{10};
-    std::chrono::milliseconds max_wait{250};
-  };
-
+private:
   struct execution_metrics {
     std::chrono::steady_clock::time_point lock_attempt_start;
     std::chrono::steady_clock::time_point lock_acquired{};
@@ -24,6 +18,13 @@ public:
     size_t lock_attempts{0};
   };
 
+public:
+  struct retry_config {
+    size_t max_attempts{10};
+    std::chrono::milliseconds initial_wait{10};
+    std::chrono::milliseconds max_wait{250};
+  };
+
   statement_cache_proxy(utils::message_bus &bus, std::unique_ptr<statement_impl>&& stmt, connection_pool &pool, const size_t connection_id)
   : statement_proxy(std::move(stmt))
   , pool_(pool)
@@ -48,7 +49,6 @@ public:
       bus_.publish(statement_lock_acquired_event{query, now, now - metrics.lock_attempt_start});
 
       auto guard = statement_guard(*this);
-      metrics.execution_start = std::chrono::steady_clock::now();
       if (const auto conn = pool_.acquire(connection_id_); !conn.valid()) {
         return utils::failure(utils::error{
           error_code::EXECUTE_FAILED,
@@ -56,6 +56,7 @@ public:
         });
       }
 
+      metrics.execution_start = std::chrono::steady_clock::now();
       auto execution_result = statement_->execute(bindings);
       metrics.execution_end = std::chrono::steady_clock::now();
 

test/orm/backend/test_statement.cpp

@@ -13,8 +13,9 @@ test_statement::test_statement(const sql::query_context &query)
 utils::result<size_t, utils::error> test_statement::execute(const sql::parameter_binder &/*bindings*/) {
   using namespace std::chrono_literals;
   std::mt19937 rng(query_.sql.size());
-  std::uniform_int_distribution dist(10, 40);
-  std::this_thread::sleep_for(std::chrono::milliseconds(dist(rng)));
+  std::uniform_int_distribution dist(10, 50);
+  std::this_thread::sleep_for(std::chrono::milliseconds(50));
+  // std::this_thread::sleep_for(std::chrono::milliseconds(dist(rng)));
   return utils::ok(static_cast<size_t>(8));
 }
 

test/orm/sql/StatementCacheTest.cpp

@@ -38,20 +38,33 @@ public:
 
   }
 
-  double get_average_lock_wait_time() const {
+  std::chrono::milliseconds get_average_lock_wait_time() const {
     std::lock_guard lock(mutex_);
     if (lock_failure_count_ == 0) {
-      return 0.0;
+      return std::chrono::milliseconds{0};
     }
-    return std::chrono::duration<double>(total_lock_wait_time_).count() / lock_failure_count_;
+    const auto millis = std::chrono::duration_cast<std::chrono::milliseconds>(total_lock_wait_time_);
+    return std::chrono::milliseconds(millis.count() / lock_failure_count_);
   }
 
-  double get_average_execution_time() const {
+  std::chrono::milliseconds get_average_execution_time() const {
     std::lock_guard lock(mutex_);
     if (execution_count_ == 0) {
-      return 0.0;
+      return std::chrono::milliseconds{0};
     }
-    return std::chrono::duration<double>(total_execution_time_).count() / execution_count_;
+
+    const auto millis = std::chrono::duration_cast<std::chrono::milliseconds>(total_execution_time_);
+    return std::chrono::milliseconds(millis.count() / execution_count_);
+  }
+
+  std::chrono::milliseconds get_total_lock_wait_time() const {
+      std::lock_guard lock(mutex_);
+      return std::chrono::duration_cast<std::chrono::milliseconds>(total_lock_wait_time_);
+  }
+
+  std::chrono::milliseconds get_total_execution_time() const {
+      std::lock_guard lock(mutex_);
+      return std::chrono::duration_cast<std::chrono::milliseconds>(total_execution_time_);
   }
 
   size_t get_lock_failure_count() const {
@@ -266,8 +279,10 @@ TEST_CASE("Multithreaded stress test", "[statement][cache][stress]") {
 
   std::cout << "[Performance] Executed " << (thread_count * iterations) << " statements in " << duration.count() << " ms (lock failed: " << lock_failed_count << ", execute failed: " << exec_failed_count << ")\n";
 
-  std::cout << "Average lock wait time: " << metrics.get_average_lock_wait_time() << "s\n";
-  std::cout << "Average execution time: " << metrics.get_average_execution_time() << "s\n";
+  std::cout << "Average lock wait time: " << metrics.get_average_lock_wait_time().count() << "ms\n";
+  std::cout << "Total lock wait time: " << metrics.get_total_lock_wait_time().count() << "ms\n";
+  std::cout << "Average execution time: " << metrics.get_average_execution_time().count() << "ms\n";
+  std::cout << "Total execution time: " << metrics.get_total_execution_time().count() << "ms\n";
   std::cout << "Number of lock failures: " << metrics.get_lock_failure_count() << "\n";
 
   // Some events should be generated