From a469662b2a1cd8c25c268fa769e46c6a8b1e8eb4 Mon Sep 17 00:00:00 2001 From: Pere Diaz Bou Date: Mon, 6 Mar 2023 10:25:21 +0100 Subject: [PATCH 1/2] msgr: AsyncMessenger add faulted connections metrics Add msgr_connection_idle_timeouts and msgr_connection_ready_timeouts labeled perfcounters to keep track of failed connections with prometheus metrics. Signed-off-by: Pere Diaz Bou Fixes: https://tracker.ceph.com/issues/59076 (cherry picked from commit 587ee4225ed41744685a10567e308caaac617425) --- src/msg/async/AsyncConnection.cc | 3 +++ src/msg/async/AsyncConnection.h | 1 + src/msg/async/ProtocolV1.cc | 1 + src/msg/async/ProtocolV2.cc | 1 + src/msg/async/Stack.h | 46 +++++++++++++++++++++++++++++--- 5 files changed, 48 insertions(+), 4 deletions(-) diff --git a/src/msg/async/AsyncConnection.cc b/src/msg/async/AsyncConnection.cc index 8051f5907ef11..683be086efada 100644 --- a/src/msg/async/AsyncConnection.cc +++ b/src/msg/async/AsyncConnection.cc @@ -116,6 +116,7 @@ AsyncConnection::AsyncConnection(CephContext *cct, AsyncMessenger *m, DispatchQu : Connection(cct, m), delay_state(NULL), async_msgr(m), conn_id(q->get_id()), logger(w->get_perf_counter()), + labeled_logger(w->get_labeled_perf_counter()), state(STATE_NONE), port(-1), dispatch_queue(q), recv_buf(NULL), recv_max_prefetch(std::max(msgr->cct->_conf->ms_tcp_prefetch_max_size, TCP_PREFETCH_MIN_SIZE)), @@ -791,6 +792,7 @@ void AsyncConnection::tick(uint64_t id) << target_addr << ", fault." << dendl; protocol->fault(); + labeled_logger->inc(l_msgr_connection_ready_timeouts); } else { last_tick_id = center->create_time_event(connect_timeout_us, tick_handler); } @@ -803,6 +805,7 @@ void AsyncConnection::tick(uint64_t id) << " us, fault." << dendl; protocol->fault(); + labeled_logger->inc(l_msgr_connection_idle_timeouts); } else { last_tick_id = center->create_time_event(inactive_timeout_us, tick_handler); } diff --git a/src/msg/async/AsyncConnection.h b/src/msg/async/AsyncConnection.h index 82c29985b18d9..78a590f8ca393 100644 --- a/src/msg/async/AsyncConnection.h +++ b/src/msg/async/AsyncConnection.h @@ -173,6 +173,7 @@ class AsyncConnection : public Connection { AsyncMessenger *async_msgr; uint64_t conn_id; PerfCounters *logger; + PerfCounters *labeled_logger; int state; ConnectedSocket cs; int port; diff --git a/src/msg/async/ProtocolV1.cc b/src/msg/async/ProtocolV1.cc index 9376d46b0bd2e..b45ad8ca5155f 100644 --- a/src/msg/async/ProtocolV1.cc +++ b/src/msg/async/ProtocolV1.cc @@ -2414,6 +2414,7 @@ CtPtr ProtocolV1::replace(const AsyncConnectionRef& existing, existing->worker->references--; new_worker->references++; existing->logger = new_worker->get_perf_counter(); + existing->labeled_logger = new_worker->get_labeled_perf_counter(); existing->worker = new_worker; existing->center = new_center; if (existing->delay_state) diff --git a/src/msg/async/ProtocolV2.cc b/src/msg/async/ProtocolV2.cc index 7cda9637d90f0..08426b796b88b 100644 --- a/src/msg/async/ProtocolV2.cc +++ b/src/msg/async/ProtocolV2.cc @@ -2808,6 +2808,7 @@ CtPtr ProtocolV2::reuse_connection(const AsyncConnectionRef& existing, existing->worker->references--; new_worker->references++; existing->logger = new_worker->get_perf_counter(); + existing->labeled_logger = new_worker->get_labeled_perf_counter(); existing->worker = new_worker; existing->center = new_center; if (existing->delay_state) diff --git a/src/msg/async/Stack.h b/src/msg/async/Stack.h index 376a87c726877..e19b6c89ce790 100644 --- a/src/msg/async/Stack.h +++ b/src/msg/async/Stack.h @@ -17,10 +17,12 @@ #ifndef CEPH_MSG_ASYNC_STACK_H #define CEPH_MSG_ASYNC_STACK_H -#include "include/spinlock.h" #include "common/perf_counters.h" -#include "msg/msg_types.h" +#include "common/perf_counters_key.h" +#include "include/spinlock.h" #include "msg/async/Event.h" +#include "msg/msg_types.h" +#include class Worker; class ConnectedSocketImpl { @@ -214,6 +216,15 @@ enum { l_msgr_last, }; +enum { + l_msgr_labeled_first = l_msgr_last + 1, + + l_msgr_connection_ready_timeouts, + l_msgr_connection_idle_timeouts, + + l_msgr_labeled_last, +}; + class Worker { std::mutex init_lock; std::condition_variable init_cond; @@ -224,6 +235,7 @@ class Worker { CephContext *cct; PerfCounters *perf_logger; + PerfCounters *perf_labeled_logger; unsigned id; std::atomic_uint references; @@ -233,9 +245,11 @@ class Worker { Worker& operator=(const Worker&) = delete; Worker(CephContext *c, unsigned worker_id) - : cct(c), perf_logger(NULL), id(worker_id), references(0), center(c) { + : cct(c), id(worker_id), references(0), center(c) { char name[128]; - sprintf(name, "AsyncMessenger::Worker-%u", id); + char name_prefix[] = "AsyncMessenger::Worker"; + sprintf(name, "%s-%u", name_prefix, id); + // initialize perf_logger PerfCountersBuilder plb(cct, name, l_msgr_first, l_msgr_last); @@ -259,12 +273,35 @@ class Worker { perf_logger = plb.create_perf_counters(); cct->get_perfcounters_collection()->add(perf_logger); + + // Add labeled perfcounters + std::string labels = ceph::perf_counters::key_create( + name_prefix, {{"id", std::to_string(id)}}); + PerfCountersBuilder plb_labeled( + cct, labels, l_msgr_labeled_first, + l_msgr_labeled_last); + + plb_labeled.add_u64_counter( + l_msgr_connection_ready_timeouts, "msgr_connection_ready_timeouts", + "Number of not yet ready connections declared as dead", NULL, + PerfCountersBuilder::PRIO_USEFUL); + plb_labeled.add_u64_counter( + l_msgr_connection_idle_timeouts, "msgr_connection_idle_timeouts", + "Number of connections closed due to idleness", NULL, + PerfCountersBuilder::PRIO_USEFUL); + + perf_labeled_logger = plb_labeled.create_perf_counters(); + cct->get_perfcounters_collection()->add(perf_labeled_logger); } virtual ~Worker() { if (perf_logger) { cct->get_perfcounters_collection()->remove(perf_logger); delete perf_logger; } + if (perf_labeled_logger) { + cct->get_perfcounters_collection()->remove(perf_labeled_logger); + delete perf_labeled_logger; + } } virtual int listen(entity_addr_t &addr, unsigned addr_slot, @@ -275,6 +312,7 @@ class Worker { virtual void initialize() {} PerfCounters *get_perf_counter() { return perf_logger; } + PerfCounters *get_labeled_perf_counter() { return perf_labeled_logger; } void release_worker() { int oldref = references.fetch_sub(1); ceph_assert(oldref > 0); From 83535ef95f48d0b2bf3bbd6564520ac7fde4ff9b Mon Sep 17 00:00:00 2001 From: Pere Diaz Bou Date: Tue, 18 Apr 2023 10:47:13 +0200 Subject: [PATCH 2/2] mgr/prometheus: rename get_unlabeled_perf_counters, no send labeled pc Signed-off-by: Pere Diaz Bou (cherry picked from commit 4e89ce7e72095548dbbbfe470aa9ec2e8947535c) --- src/mgr/MgrClient.cc | 35 +++++++++++-------- src/msg/async/Stack.h | 2 +- .../dashboard/controllers/perf_counters.py | 2 +- src/pybind/mgr/influx/module.py | 2 +- src/pybind/mgr/mgr_module.py | 2 +- src/pybind/mgr/prometheus/module.py | 2 +- src/pybind/mgr/restful/api/perf.py | 2 +- src/pybind/mgr/telegraf/module.py | 2 +- src/pybind/mgr/telemetry/module.py | 22 ++++++------ 9 files changed, 39 insertions(+), 32 deletions(-) diff --git a/src/mgr/MgrClient.cc b/src/mgr/MgrClient.cc index 6253d26703433..6250ea3b9f18e 100644 --- a/src/mgr/MgrClient.cc +++ b/src/mgr/MgrClient.cc @@ -14,6 +14,7 @@ #include "MgrClient.h" +#include "common/perf_counters_key.h" #include "mgr/MgrContext.h" #include "mon/MonMap.h" @@ -331,6 +332,12 @@ void MgrClient::_send_report() const PerfCounters::perf_counter_data_any_d &ctr, const PerfCounters &perf_counters) { + // FIXME: We don't send labeled perf counters to the mgr currently. + auto labels = ceph::perf_counters::key_labels(perf_counters.get_name()); + if (labels.begin() != labels.end()) { + return false; + } + return perf_counters.get_adjusted_priority(ctr.prio) >= (int)stats_threshold; }; @@ -367,20 +374,20 @@ void MgrClient::_send_report() } if (session->declared.count(path) == 0) { - ldout(cct,20) << " declare " << path << dendl; - PerfCounterType type; - type.path = path; - if (data.description) { - type.description = data.description; - } - if (data.nick) { - type.nick = data.nick; - } - type.type = data.type; - type.priority = perf_counters.get_adjusted_priority(data.prio); - type.unit = data.unit; - report->declare_types.push_back(std::move(type)); - session->declared.insert(path); + ldout(cct, 20) << " declare " << path << dendl; + PerfCounterType type; + type.path = path; + if (data.description) { + type.description = data.description; + } + if (data.nick) { + type.nick = data.nick; + } + type.type = data.type; + type.priority = perf_counters.get_adjusted_priority(data.prio); + type.unit = data.unit; + report->declare_types.push_back(std::move(type)); + session->declared.insert(path); } encode(static_cast(data.u64), report->packed); diff --git a/src/msg/async/Stack.h b/src/msg/async/Stack.h index e19b6c89ce790..6739968f4e2b7 100644 --- a/src/msg/async/Stack.h +++ b/src/msg/async/Stack.h @@ -276,7 +276,7 @@ class Worker { // Add labeled perfcounters std::string labels = ceph::perf_counters::key_create( - name_prefix, {{"id", std::to_string(id)}}); + name_prefix, {{"id", std::to_string(id)}}); PerfCountersBuilder plb_labeled( cct, labels, l_msgr_labeled_first, l_msgr_labeled_last); diff --git a/src/pybind/mgr/dashboard/controllers/perf_counters.py b/src/pybind/mgr/dashboard/controllers/perf_counters.py index 0bd8833669371..ab0bdcb0b32b9 100644 --- a/src/pybind/mgr/dashboard/controllers/perf_counters.py +++ b/src/pybind/mgr/dashboard/controllers/perf_counters.py @@ -79,4 +79,4 @@ class PerfCounters(RESTController): @EndpointDoc("Display Perf Counters", responses={200: PERF_SCHEMA}) def list(self): - return mgr.get_all_perf_counters() + return mgr.get_unlabeled_perf_counters() diff --git a/src/pybind/mgr/influx/module.py b/src/pybind/mgr/influx/module.py index f88261b20b14b..6818783b341a8 100644 --- a/src/pybind/mgr/influx/module.py +++ b/src/pybind/mgr/influx/module.py @@ -253,7 +253,7 @@ def get_pg_summary_pool(self, pool_info: Dict[str, str], now: str) -> Iterator[D } def get_daemon_stats(self, now: str) -> Iterator[Dict[str, Any]]: - for daemon, counters in self.get_all_perf_counters().items(): + for daemon, counters in self.get_unlabeled_perf_counters().items(): svc_type, svc_id = daemon.split(".", 1) metadata = self.get_metadata(svc_type, svc_id) if metadata is not None: diff --git a/src/pybind/mgr/mgr_module.py b/src/pybind/mgr/mgr_module.py index 2fabbae87c52e..f7d0eb0f54402 100644 --- a/src/pybind/mgr/mgr_module.py +++ b/src/pybind/mgr/mgr_module.py @@ -2022,7 +2022,7 @@ def get_latest_avg(self, daemon_type: str, daemon_name: str, counter: str) -> Tu @API.expose @profile_method() - def get_all_perf_counters(self, prio_limit: int = PRIO_USEFUL, + def get_unlabeled_perf_counters(self, prio_limit: int = PRIO_USEFUL, services: Sequence[str] = ("mds", "mon", "osd", "rbd-mirror", "rgw", "tcmu-runner")) -> Dict[str, dict]: diff --git a/src/pybind/mgr/prometheus/module.py b/src/pybind/mgr/prometheus/module.py index f2e97c9d183ad..96f08f027a9ec 100644 --- a/src/pybind/mgr/prometheus/module.py +++ b/src/pybind/mgr/prometheus/module.py @@ -1652,7 +1652,7 @@ def get_perf_counters(self) -> None: """ Get the perf counters for all daemons """ - for daemon, counters in self.get_all_perf_counters().items(): + for daemon, counters in self.get_unlabeled_perf_counters().items(): for path, counter_info in counters.items(): # Skip histograms, they are represented by long running avgs stattype = self._stattype_to_str(counter_info['type']) diff --git a/src/pybind/mgr/restful/api/perf.py b/src/pybind/mgr/restful/api/perf.py index 4224599f66995..c484ac55e445f 100644 --- a/src/pybind/mgr/restful/api/perf.py +++ b/src/pybind/mgr/restful/api/perf.py @@ -18,7 +18,7 @@ def get(self, **kwargs): - 'daemon' -- filter by daemon, accepts Python regexp """ - counters = context.instance.get_all_perf_counters() + counters = context.instance.get_unlabeled_perf_counters() if 'daemon' in kwargs: _re = re.compile(kwargs['daemon']) diff --git a/src/pybind/mgr/telegraf/module.py b/src/pybind/mgr/telegraf/module.py index f640f1d3a0fd8..541ddba4f0737 100644 --- a/src/pybind/mgr/telegraf/module.py +++ b/src/pybind/mgr/telegraf/module.py @@ -72,7 +72,7 @@ def get_pool_stats(self) -> Iterable[Dict[str, Any]]: } def get_daemon_stats(self) -> Iterable[Dict[str, Any]]: - for daemon, counters in self.get_all_perf_counters().items(): + for daemon, counters in self.get_unlabeled_perf_counters().items(): svc_type, svc_id = daemon.split('.', 1) metadata = self.get_metadata(svc_type, svc_id) if not metadata: diff --git a/src/pybind/mgr/telemetry/module.py b/src/pybind/mgr/telemetry/module.py index cd431a2e1cc69..f729b9180cfb6 100644 --- a/src/pybind/mgr/telemetry/module.py +++ b/src/pybind/mgr/telemetry/module.py @@ -794,7 +794,7 @@ def gather_crashinfo(self) -> List[Dict[str, str]]: return crashlist def gather_perf_counters(self, mode: str = 'separated') -> Dict[str, dict]: - # Extract perf counter data with get_all_perf_counters(), a method + # Extract perf counter data with get_unlabeled_perf_counters(), a method # from mgr/mgr_module.py. This method returns a nested dictionary that # looks a lot like perf schema, except with some additional fields. # @@ -810,7 +810,7 @@ def gather_perf_counters(self, mode: str = 'separated') -> Dict[str, dict]: # "value": 88814109 # }, # }, - all_perf_counters = self.get_all_perf_counters() + perf_counters = self.get_unlabeled_perf_counters() # Initialize 'result' dict result: Dict[str, dict] = defaultdict(lambda: defaultdict( @@ -819,7 +819,7 @@ def gather_perf_counters(self, mode: str = 'separated') -> Dict[str, dict]: # 'separated' mode anonymized_daemon_dict = {} - for daemon, all_perf_counters_by_daemon in all_perf_counters.items(): + for daemon, perf_counters_by_daemon in perf_counters.items(): daemon_type = daemon[0:3] # i.e. 'mds', 'osd', 'rgw' if mode == 'separated': @@ -836,7 +836,7 @@ def gather_perf_counters(self, mode: str = 'separated') -> Dict[str, dict]: else: result[daemon_type]['num_combined_daemons'] += 1 - for collection in all_perf_counters_by_daemon: + for collection in perf_counters_by_daemon: # Split the collection to avoid redundancy in final report; i.e.: # bluestore.kv_flush_lat, bluestore.kv_final_lat --> # bluestore: kv_flush_lat, kv_final_lat @@ -856,12 +856,12 @@ def gather_perf_counters(self, mode: str = 'separated') -> Dict[str, dict]: if mode == 'separated': # Add value to result result[daemon][col_0][col_1]['value'] = \ - all_perf_counters_by_daemon[collection]['value'] + perf_counters_by_daemon[collection]['value'] # Check that 'count' exists, as not all counters have a count field. - if 'count' in all_perf_counters_by_daemon[collection]: + if 'count' in perf_counters_by_daemon[collection]: result[daemon][col_0][col_1]['count'] = \ - all_perf_counters_by_daemon[collection]['count'] + perf_counters_by_daemon[collection]['count'] elif mode == 'aggregated': # Not every rgw daemon has the same schema. Specifically, each rgw daemon # has a uniquely-named collection that starts off identically (i.e. @@ -875,14 +875,14 @@ def gather_perf_counters(self, mode: str = 'separated') -> Dict[str, dict]: # the files are of type 'pair' (real-integer-pair, integer-integer pair). # In those cases, the value is a dictionary, and not a number. # i.e. throttle-msgr_dispatch_throttler-hbserver["wait"] - if isinstance(all_perf_counters_by_daemon[collection]['value'], numbers.Number): + if isinstance(perf_counters_by_daemon[collection]['value'], numbers.Number): result[daemon_type][col_0][col_1]['value'] += \ - all_perf_counters_by_daemon[collection]['value'] + perf_counters_by_daemon[collection]['value'] # Check that 'count' exists, as not all counters have a count field. - if 'count' in all_perf_counters_by_daemon[collection]: + if 'count' in perf_counters_by_daemon[collection]: result[daemon_type][col_0][col_1]['count'] += \ - all_perf_counters_by_daemon[collection]['count'] + perf_counters_by_daemon[collection]['count'] else: self.log.error('Incorrect mode specified in gather_perf_counters: {}'.format(mode)) return {}