From 94d175908a705171fbc6d3ae3332008e144055d3 Mon Sep 17 00:00:00 2001 From: zhangjianwei Date: Fri, 15 Sep 2023 13:50:57 +0800 Subject: [PATCH] src/msg: fix high CPU consumption of msgr worker thread problem analysis: - std::multimap time_events - time precision is nanoseconds - in EventCenter::process_events function - end_time > now : Nanosecond comparison - std::chrono::microseconds>(end_time - now) : - but converted to microseconds difference - so timeout_microseconds = 0 - epoll_wait(..., 0) not sleep - rados bench count : 6000 - Proportion of 0 events processed - 41898337 / 44796903 = 93.52% - osd single msgr worker thread cpu high to 100% solution: - due to epoll_wait is milliseconds - add ms_time_events_min_wait_interval to control how long time_events should wait at least - so default value aligned to 1000 microseconds - rados bench count : 6000 - Proportion of 0 events processed - 424466 / 4489181 = 9.45% - osd single msgr worker thread cpu high to 30~40% issue: https://tracker.ceph.com/issues/62512 co-author: yanghonggang Signed-off-by: zhangjianwei --- src/common/options/global.yaml.in | 17 +++++++++++++++++ src/msg/async/Event.cc | 2 ++ src/msg/async/ProtocolV1.cc | 7 ++++--- src/msg/async/ProtocolV2.cc | 7 ++++--- 4 files changed, 27 insertions(+), 6 deletions(-) diff --git a/src/common/options/global.yaml.in b/src/common/options/global.yaml.in index fba6d72455e..cbdb1185da6 100644 --- a/src/common/options/global.yaml.in +++ b/src/common/options/global.yaml.in @@ -1276,6 +1276,23 @@ options: desc: Inject a network congestions that stuck with N times operations default: 0 with_legacy: true +- name: ms_time_events_min_wait_interval + type: uint + level: dev + desc: In microseconds, msgr-worker's time_events min wait time for epoll_wait timeout + default: 1000 + min: 0 + max: 60000000 + with_legacy: true +- name: ms_client_throttle_retry_time_interval + type: uint + level: dev + desc: In microseconds, user client, the time interval between the next retry + when the throttle get_or_fail. + default: 5000 + min: 1000 + max: 60000000 + with_legacy: true - name: ms_blackhole_osd type: bool level: dev diff --git a/src/msg/async/Event.cc b/src/msg/async/Event.cc index 926fdcdb1cc..08e117ea54a 100644 --- a/src/msg/async/Event.cc +++ b/src/msg/async/Event.cc @@ -404,6 +404,8 @@ int EventCenter::process_events(unsigned timeout_microseconds, ceph::timespan * if (end_time > now) { timeout_microseconds = std::chrono::duration_cast(end_time - now).count(); + timeout_microseconds = std::max(timeout_microseconds, + cct->_conf->ms_time_events_min_wait_interval); } else { timeout_microseconds = 0; } diff --git a/src/msg/async/ProtocolV1.cc b/src/msg/async/ProtocolV1.cc index b45ad8ca515..0ddd267926d 100644 --- a/src/msg/async/ProtocolV1.cc +++ b/src/msg/async/ProtocolV1.cc @@ -677,7 +677,7 @@ CtPtr ProtocolV1::throttle_message() { // short time, so we can wait a ms. if (connection->register_time_events.empty()) { connection->register_time_events.insert( - connection->center->create_time_event(1000, + connection->center->create_time_event(cct->_conf->ms_client_throttle_retry_time_interval, connection->wakeup_handler)); } return nullptr; @@ -710,7 +710,8 @@ CtPtr ProtocolV1::throttle_bytes() { if (connection->register_time_events.empty()) { connection->register_time_events.insert( connection->center->create_time_event( - 1000, connection->wakeup_handler)); + cct->_conf->ms_client_throttle_retry_time_interval, + connection->wakeup_handler)); } return nullptr; } @@ -737,7 +738,7 @@ CtPtr ProtocolV1::throttle_dispatch_queue() { // short time, so we can wait a ms. if (connection->register_time_events.empty()) { connection->register_time_events.insert( - connection->center->create_time_event(1000, + connection->center->create_time_event(cct->_conf->ms_client_throttle_retry_time_interval, connection->wakeup_handler)); } return nullptr; diff --git a/src/msg/async/ProtocolV2.cc b/src/msg/async/ProtocolV2.cc index 08426b796b8..7a459363a0e 100644 --- a/src/msg/async/ProtocolV2.cc +++ b/src/msg/async/ProtocolV2.cc @@ -1552,7 +1552,7 @@ CtPtr ProtocolV2::throttle_message() { // short time, so we can wait a ms. if (connection->register_time_events.empty()) { connection->register_time_events.insert( - connection->center->create_time_event(1000, + connection->center->create_time_event(cct->_conf->ms_client_throttle_retry_time_interval, connection->wakeup_handler)); } return nullptr; @@ -1584,7 +1584,8 @@ CtPtr ProtocolV2::throttle_bytes() { if (connection->register_time_events.empty()) { connection->register_time_events.insert( connection->center->create_time_event( - 1000, connection->wakeup_handler)); + cct->_conf->ms_client_throttle_retry_time_interval, + connection->wakeup_handler)); } return nullptr; } @@ -1612,7 +1613,7 @@ CtPtr ProtocolV2::throttle_dispatch_queue() { // short time, so we can wait a ms. if (connection->register_time_events.empty()) { connection->register_time_events.insert( - connection->center->create_time_event(1000, + connection->center->create_time_event(cct->_conf->ms_client_throttle_retry_time_interval, connection->wakeup_handler)); } return nullptr; -- 2.39.5