add stats

net/net-connections.cpp

@@ -65,8 +65,8 @@ int outbound_connections, active_outbound_connections, ready_outbound_connection
 long long outbound_connections_created, inbound_connections_accepted;
 int ready_targets;
 int conn_generation;
-
-static void(*on_active_special_connections_update_callback)() = []{};
+double last_conn_start_processing = 0;
+static void(*on_active_special_connections_update_callback)() = [](){};
 
 const char *unix_socket_directory = "/var/run/engine";
 SAVE_STRING_OPTION_PARSER(OPT_NETWORK, "unix-socket-directory", unix_socket_directory, "path to directory with UNIX sockets");
@@ -1170,6 +1170,7 @@ int accept_new_connections(struct connection *cc) {
                    max_special_connections);
         }
         ++active_special_connections;
+        last_conn_start_processing = get_utime_monotonic();
         on_active_special_connections_update_callback();
         if (active_special_connections >= max_special_connections) {
           return EVA_REMOVE;

net/net-connections.h

@@ -240,6 +240,7 @@ extern int active_connections;
 extern int active_special_connections, max_special_connections;
 extern int outbound_connections, active_outbound_connections, ready_outbound_connections;
 extern int conn_generation;
+extern double last_conn_start_processing;
 extern int ready_targets;
 extern long long total_failed_connections, total_connect_failures, unused_connections_closed;
 extern const char *unix_socket_directory;

server/php-master.cpp

@@ -1121,6 +1121,10 @@ STATS_PROVIDER_TAGGED(kphp_stats, 100, stats_tag_kphp_server) {
   stats->add_gauge_stat("workers.job.processes.working", job_worker_group.running_workers);
   stats->add_gauge_stat("workers.job.processes.working_but_waiting", job_worker_group.waiting_workers);
 
+  auto [avg_script_init_time, avg_connection_process_time] = vk::singleton<ServerStats>::get().collect_script_timeouts_stat();
+  stats->add_gauge_stat("workers.avg_script_init_time_ms", avg_script_init_time);
+  stats->add_gauge_stat("workers.avg_connection_process_time_ms", avg_connection_process_time);
+
   if (stats->need_aggregated_stats()) {
     auto running_stats = server_stats.misc_stat_for_general_workers[1].get_stat();
     stats->add_gauge_stat("workers.general.processes.running.avg_1m", running_stats.running_workers_avg);

server/php-runner.cpp

@@ -427,6 +427,7 @@ void PhpScript::run() noexcept {
   check_net_context_errors();
 
   CurException = Optional<bool>{};
+  PhpScript::last_script_start_time = get_utime_monotonic();
   run_main->run();
   if (CurException.is_null()) {
     set_script_result(nullptr);
@@ -485,6 +486,7 @@ ucontext_t_portable PhpScript::exit_context;
 volatile bool PhpScript::in_script_context = false;
 volatile bool PhpScript::time_limit_exceeded = false;
 volatile bool PhpScript::memory_limit_exceeded = false;
+double PhpScript::last_script_start_time = 0;
 
 static __inline__ void *get_sp() {
   return __builtin_frame_address(0);

server/php-runner.h

@@ -4,8 +4,6 @@
 
 #pragma once
 
-#include <csetjmp>
-
 #include "common/dl-utils-lite.h"
 #include "common/mixin/not_copyable.h"
 #include "common/sanitizer.h"
@@ -100,6 +98,7 @@ class PhpScript {
   volatile static bool in_script_context;
   volatile static bool time_limit_exceeded;
   volatile static bool memory_limit_exceeded;
+  static double last_script_start_time;
 
   run_state_t state{run_state_t::empty};
   const char *error_message{nullptr};
@@ -111,7 +110,6 @@ class PhpScript {
   PhpScriptStack script_stack;
 
   ucontext_t_portable run_context{};
-  sigjmp_buf timeout_handler{};
 
   script_t *run_main{nullptr};
   php_query_data *data{nullptr};

server/php-worker.cpp

@@ -24,6 +24,8 @@
 #include "server/php-worker.h"
 #include "server/server-stats.h"
 
+double PhpWorker::last_worker_init_time = 0;
+
 PhpWorker *active_worker = nullptr;
 
 double PhpWorker::enter_lifecycle() noexcept {
@@ -460,6 +462,7 @@ PhpWorker::PhpWorker(php_worker_mode_t mode_, connection *c, http_query_data *ht
   , mode(mode_)
   , req_id(req_id_)
 {
+  PhpWorker::last_worker_init_time = init_time;
   assert(c != nullptr);
   if (conn->target) {
     target_fd = static_cast<int>(conn->target - Targets);

server/php-worker.h

@@ -33,6 +33,8 @@ enum php_worker_state_t {
  */
 class PhpWorker {
 public:
+  static double last_worker_init_time;
+
   struct connection *conn;
 
   php_query_data *data;

server/server-stats.cpp

@@ -12,13 +12,15 @@
 #include "common/smart_iterators/transform_iterator.h"
 #include "common/wrappers/memory-utils.h"
 #include "net/net-events.h"
+#include "net/net-connections.h"
 
 #include "runtime/curl.h"
 
 #include "server/workers-control.h"
 
 #include "server/json-logger.h"
 #include "server/server-stats.h"
+#include "server/php-worker.h"
 #include "server/statshouse/statshouse-client.h"
 #include "server/statshouse/worker-stats-buffer.h"
 
@@ -129,6 +131,14 @@ struct MiscStat : WithStatType<uint64_t> {
   };
 };
 
+struct TimeoutStat : WithStatType<double> {
+  enum class Key {
+    connection_process_time,
+    script_init_time,
+    types_count
+  };
+};
+
 template<class E, class T = typename E::StatType>
 struct EnumTable : std::array<T, static_cast<size_t>(E::Key::types_count)> {
   using Base = std::array<T, static_cast<size_t>(E::Key::types_count)>;
@@ -190,6 +200,16 @@ EnumTable<VMStat> get_virtual_memory_stat() noexcept {
   return result;
 }
 
+EnumTable<TimeoutStat> get_script_time_stat() noexcept {
+  EnumTable<TimeoutStat> result;
+  double conn_accept_time = last_conn_start_processing;
+  double php_worker_init_time = PhpWorker::last_worker_init_time < last_conn_start_processing ? get_utime_monotonic() : PhpWorker::last_worker_init_time;
+  double php_script_start_time = PhpScript::last_script_start_time < php_worker_init_time ? get_utime_monotonic() : PhpScript::last_script_start_time;
+  result[TimeoutStat::Key::connection_process_time] = (php_script_start_time - conn_accept_time) * 1000;
+  result[TimeoutStat::Key::script_init_time] = (php_script_start_time - php_worker_init_time) * 1000;
+  return result;
+}
+
 EnumTable<MallocStat> get_malloc_stat() noexcept {
   EnumTable<MallocStat> result;
   const auto malloc_info = get_malloc_stats();
@@ -467,12 +487,14 @@ struct WorkerProcessStats : private vk::not_copyable {
   WorkerStatsBundle<MiscStat> misc_stats{};
   WorkerStatsBundle<QueriesStat> query_stats{};
   WorkerStatsBundle<IdleStat> idle_stats{};
+  WorkerStatsBundle<TimeoutStat> script_time_stats{};
 
   void update_worker_stats(uint16_t worker_index) noexcept {
     malloc_stats.set_worker_stats(get_malloc_stat(), worker_index);
     heap_stats.set_worker_stats(get_heap_stat(), worker_index);
     vm_stats.set_worker_stats(get_virtual_memory_stat(), worker_index);
     idle_stats.set_worker_stats(get_idle_stat(), worker_index);
+    script_time_stats.set_worker_stats(get_script_time_stat(), worker_index);
     misc_stats.inc_stat(MiscStat::Key::worker_activity_counter, worker_index);
     misc_stats.set_stat(MiscStat::Key::json_logs_count, worker_index, vk::singleton<JsonLogger>::get().get_json_logs_count());
     misc_stats.set_stat(MiscStat::Key::json_traces_count, worker_index, vk::singleton<JsonLogger>::get().get_json_traces_count());
@@ -925,6 +947,19 @@ std::tuple<uint64_t, uint64_t> ServerStats::collect_json_count_stat() const noex
   return {sum_json_logs_count, sum_json_traces_count};
 }
 
+std::tuple<double, double> ServerStats::collect_script_timeouts_stat() const noexcept {
+  const auto &workers_script_timeouts = shared_stats_->workers.script_time_stats;
+  double sum_script_init_time = 0;
+  double sum_connection_process_time = 0;
+  const auto &workers_control = vk::singleton<WorkersControl>::get();
+  for (uint16_t w = 0; w != workers_control.get_total_workers_count(); ++w) {
+    sum_script_init_time += workers_script_timeouts.get_stat(TimeoutStat::Key::script_init_time, w);
+    sum_connection_process_time += workers_script_timeouts.get_stat(TimeoutStat::Key::connection_process_time, w);
+  }
+  int workers_count = workers_control.get_total_workers_count();
+  return {sum_script_init_time / workers_count, sum_connection_process_time / workers_count};
+}
+
 uint64_t ServerStats::collect_threads_count_stat() const noexcept {
   const auto &workers_misc = shared_stats_->workers.misc_stats;
   uint64_t sum_threads_count = 0;

server/server-stats.h

@@ -50,6 +50,7 @@ class ServerStats : vk::not_copyable {
   };
   WorkersStat collect_workers_stat(WorkerType worker_type) const noexcept;
   std::tuple<uint64_t, uint64_t> collect_json_count_stat() const noexcept;
+  std::tuple<double, double> collect_script_timeouts_stat() const noexcept;
   uint64_t collect_threads_count_stat() const noexcept;
 
 private: