From 1f40d0c06c4f292d205bc6cc846161e0706a871b Mon Sep 17 00:00:00 2001 From: Patrick Donnelly Date: Wed, 23 Oct 2024 23:15:39 -0400 Subject: [PATCH 1/4] log: concatenate thread names and print once per thread Fixes: 0be8d01c9ddde0d7d24edd34dc75f6cfc861b5ba Fixes: https://tracker.ceph.com/issues/68691 Signed-off-by: Patrick Donnelly --- src/log/Log.cc | 13 +++++++++---- 1 file changed, 9 insertions(+), 4 deletions(-) diff --git a/src/log/Log.cc b/src/log/Log.cc index 49dd03c06c0..8afccee6392 100644 --- a/src/log/Log.cc +++ b/src/log/Log.cc @@ -31,6 +31,7 @@ #include #include +#include #define MAX_LOG_BUF 65536 @@ -493,13 +494,14 @@ void Log::dump_recent() _flush(m_flush, false); _log_message("--- begin dump of recent events ---", true); - std::set> recent_pthread_ids; + std::map > recent_pthread_ids; { EntryVector t; t.insert(t.end(), std::make_move_iterator(m_recent.begin()), std::make_move_iterator(m_recent.end())); m_recent.clear(); for (const auto& e : t) { - recent_pthread_ids.emplace(std::make_pair(e.m_thread, e.m_thread_name)); + auto& set = recent_pthread_ids[e.m_thread]; + set.insert(e.m_thread_name); } _flush(t, true); } @@ -515,11 +517,14 @@ void Log::dump_recent() m_stderr_log, m_stderr_crash), true); _log_message("--- pthread ID / name mapping for recent threads ---", true); - for (auto& [pthread_id, pthread_name] : recent_pthread_ids) + for (const auto& [pthread_id, pthread_names] : recent_pthread_ids) { // we want the ID to be printed in the same format as we use for a log entry. // The reason is easier grepping. - _log_message(fmt::format(" {:x} / {}", tid_to_int(pthread_id), pthread_name), true); + auto msg = fmt::format(" {:x} / {}", + tid_to_int(pthread_id), + fmt::join(pthread_names, ", ")); + _log_message(msg, true); } _log_message(fmt::format(" max_recent {:9}", m_recent.capacity()), true); From 7de5af59c2741b4203cc17f619ca53096c97b8ff Mon Sep 17 00:00:00 2001 From: Patrick Donnelly Date: Wed, 23 Oct 2024 23:16:03 -0400 Subject: [PATCH 2/4] common: cache pthread names This provides common ceph entrypoints for the pthread_[gs]name functions which will also cache a thread_local copy. This also removes the pthread_t parameter which precipitated the bug i50743. Obviously, the overall goal here is to avoid system calls. See-also: https://tracker.ceph.com/issues/50743 Fixes: 0be8d01c9ddde0d7d24edd34dc75f6cfc861b5ba Fixes: https://tracker.ceph.com/issues/68691 Signed-off-by: Patrick Donnelly --- src/ceph_mds.cc | 2 +- src/ceph_mgr.cc | 2 +- src/ceph_mon.cc | 2 +- src/ceph_nvmeof_monitor_client.cc | 2 +- src/client/SyntheticClient.cc | 2 +- src/common/Thread.cc | 22 +-------- src/common/Thread.h | 10 +--- src/common/assert.cc | 12 ++--- src/common/ceph_timer.h | 2 +- src/common/code_environment.cc | 7 +-- src/common/compat.cc | 63 ++++++++++++++++++++++++ src/common/obj_bencher.cc | 4 +- src/crimson/os/alienstore/thread_pool.cc | 2 +- src/global/signal_handler.cc | 2 +- src/include/compat.h | 51 ++----------------- src/log/Entry.h | 6 +-- src/log/Log.cc | 2 +- src/mds/Beacon.cc | 2 +- src/msg/async/Stack.h | 2 +- src/msg/async/rdma/RDMAStack.cc | 2 +- src/rgw/driver/rados/rgw_notify.cc | 11 ++--- src/rgw/rgw_amqp.cc | 9 ++-- src/rgw/rgw_kafka.cc | 7 +-- src/rgw/rgw_lua_background.cc | 6 +-- src/rgw/rgw_ratelimit.h | 4 +- 25 files changed, 102 insertions(+), 134 deletions(-) diff --git a/src/ceph_mds.cc b/src/ceph_mds.cc index 5a917fa807c..ba8726a2be3 100644 --- a/src/ceph_mds.cc +++ b/src/ceph_mds.cc @@ -81,7 +81,7 @@ static void handle_mds_signal(int signum) int main(int argc, const char **argv) { - ceph_pthread_setname(pthread_self(), "ceph-mds"); + ceph_pthread_setname("ceph-mds"); auto args = argv_to_vec(argc, argv); if (args.empty()) { diff --git a/src/ceph_mgr.cc b/src/ceph_mgr.cc index 67bda0c51be..bd2c643bc6b 100644 --- a/src/ceph_mgr.cc +++ b/src/ceph_mgr.cc @@ -41,7 +41,7 @@ static void usage() */ int main(int argc, const char **argv) { - ceph_pthread_setname(pthread_self(), "ceph-mgr"); + ceph_pthread_setname("ceph-mgr"); auto args = argv_to_vec(argc, argv); if (args.empty()) { diff --git a/src/ceph_mon.cc b/src/ceph_mon.cc index 279fdb20ccb..63eb252e38f 100644 --- a/src/ceph_mon.cc +++ b/src/ceph_mon.cc @@ -250,7 +250,7 @@ int main(int argc, const char **argv) { // reset our process name, in case we did a respawn, so that it's not // left as "exe". - ceph_pthread_setname(pthread_self(), "ceph-mon"); + ceph_pthread_setname("ceph-mon"); int err; diff --git a/src/ceph_nvmeof_monitor_client.cc b/src/ceph_nvmeof_monitor_client.cc index 05457998cb8..fa41bed08ad 100644 --- a/src/ceph_nvmeof_monitor_client.cc +++ b/src/ceph_nvmeof_monitor_client.cc @@ -45,7 +45,7 @@ static void usage() */ int main(int argc, const char **argv) { - ceph_pthread_setname(pthread_self(), "ceph-nvmeof-monitor-client"); + ceph_pthread_setname("ceph-nvmeof-monitor-client"); auto args = argv_to_vec(argc, argv); if (args.empty()) { diff --git a/src/client/SyntheticClient.cc b/src/client/SyntheticClient.cc index 3b408dd3f2d..6b315d2dee3 100644 --- a/src/client/SyntheticClient.cc +++ b/src/client/SyntheticClient.cc @@ -290,6 +290,7 @@ SyntheticClient::SyntheticClient(StandaloneClient *client, int w) void *synthetic_client_thread_entry(void *ptr) { + ceph_pthread_setname("client"); SyntheticClient *sc = static_cast(ptr); //int r = sc->run(); @@ -945,7 +946,6 @@ int SyntheticClient::start_thread() pthread_create(&thread_id, NULL, synthetic_client_thread_entry, this); ceph_assert(thread_id); - ceph_pthread_setname(thread_id, "client"); return 0; } diff --git a/src/common/Thread.cc b/src/common/Thread.cc index 3903e8c0ed7..c714aa0aa87 100644 --- a/src/common/Thread.cc +++ b/src/common/Thread.cc @@ -83,7 +83,7 @@ void *Thread::entry_wrapper() if (pid && cpuid >= 0) _set_affinity(cpuid); - ceph_pthread_setname(pthread_self(), Thread::thread_name.c_str()); + ceph_pthread_setname(thread_name.c_str()); return entry(); } @@ -154,7 +154,7 @@ int Thread::try_create(size_t stacksize) void Thread::create(const char *name, size_t stacksize) { ceph_assert(strlen(name) < 16); - Thread::thread_name = name; + thread_name = name; int ret = try_create(stacksize); if (ret != 0) { @@ -203,24 +203,6 @@ int Thread::set_affinity(int id) // Functions for std::thread // ========================= -void set_thread_name(std::thread& t, const std::string& s) { - int r = ceph_pthread_setname(t.native_handle(), s.c_str()); - if (r != 0) { - throw std::system_error(r, std::generic_category()); - } -} -std::string get_thread_name(const std::thread& t) { - std::string s(256, '\0'); - - int r = ceph_pthread_getname(const_cast(t).native_handle(), - s.data(), s.length()); - if (r != 0) { - throw std::system_error(r, std::generic_category()); - } - s.resize(std::strlen(s.data())); - return s; -} - void kill(std::thread& t, int signal) { auto r = ceph_pthread_kill(t.native_handle(), signal); diff --git a/src/common/Thread.h b/src/common/Thread.h index d3892c1b36b..e15f2981cf8 100644 --- a/src/common/Thread.h +++ b/src/common/Thread.h @@ -27,7 +27,6 @@ #include "include/ceph_assert.h" #include "include/compat.h" -#include "include/spinlock.h" extern pid_t ceph_gettid(); @@ -36,7 +35,7 @@ class Thread { pthread_t thread_id; pid_t pid; int cpuid; - static inline thread_local std::string thread_name; + std::string thread_name; void *entry_wrapper(); @@ -64,15 +63,10 @@ class Thread { int join(void **prval = 0); int detach(); int set_affinity(int cpuid); - static const std::string get_thread_name() { - return Thread::thread_name; - } }; // Functions for with std::thread -void set_thread_name(std::thread& t, const std::string& s); -std::string get_thread_name(const std::thread& t); void kill(std::thread& t, int signal); template @@ -81,7 +75,7 @@ std::thread make_named_thread(std::string_view n, Args&& ...args) { return std::thread([n = std::string(n)](auto&& fun, auto&& ...args) { - ceph_pthread_setname(pthread_self(), n.data()); + ceph_pthread_setname(n.data()); std::invoke(std::forward(fun), std::forward(args)...); }, std::forward(fun), std::forward(args)...); diff --git a/src/common/assert.cc b/src/common/assert.cc index 7fb4c2d726b..68ad99c878e 100644 --- a/src/common/assert.cc +++ b/src/common/assert.cc @@ -44,8 +44,7 @@ namespace ceph { g_assert_line = line; g_assert_func = func; g_assert_thread = (unsigned long long)pthread_self(); - ceph_pthread_getname(pthread_self(), g_assert_thread_name, - sizeof(g_assert_thread_name)); + ceph_pthread_getname(g_assert_thread_name, sizeof(g_assert_thread_name)); ostringstream tss; tss << ceph_clock_now(); @@ -122,8 +121,7 @@ namespace ceph { g_assert_line = line; g_assert_func = func; g_assert_thread = (unsigned long long)pthread_self(); - ceph_pthread_getname(pthread_self(), g_assert_thread_name, - sizeof(g_assert_thread_name)); + ceph_pthread_getname(g_assert_thread_name, sizeof(g_assert_thread_name)); BufAppender ba(g_assert_msg, sizeof(g_assert_msg)); BackTrace *bt = new ClibBackTrace(1); @@ -168,8 +166,7 @@ namespace ceph { g_assert_line = line; g_assert_func = func; g_assert_thread = (unsigned long long)pthread_self(); - ceph_pthread_getname(pthread_self(), g_assert_thread_name, - sizeof(g_assert_thread_name)); + ceph_pthread_getname(g_assert_thread_name, sizeof(g_assert_thread_name)); BackTrace *bt = new ClibBackTrace(1); snprintf(g_assert_msg, sizeof(g_assert_msg), @@ -210,8 +207,7 @@ namespace ceph { g_assert_line = line; g_assert_func = func; g_assert_thread = (unsigned long long)pthread_self(); - ceph_pthread_getname(pthread_self(), g_assert_thread_name, - sizeof(g_assert_thread_name)); + ceph_pthread_getname(g_assert_thread_name, sizeof(g_assert_thread_name)); BufAppender ba(g_assert_msg, sizeof(g_assert_msg)); BackTrace *bt = new ClibBackTrace(1); diff --git a/src/common/ceph_timer.h b/src/common/ceph_timer.h index bc324bfa243..7fb2c7bac12 100644 --- a/src/common/ceph_timer.h +++ b/src/common/ceph_timer.h @@ -98,6 +98,7 @@ class timer { std::thread thread; void timer_thread() { + ceph_pthread_setname("ceph_timer"); std::unique_lock l(lock); while (!suspended) { auto now = TC::now(); @@ -155,7 +156,6 @@ class timer { public: timer() : suspended(false) { thread = std::thread(&timer::timer_thread, this); - set_thread_name(thread, "ceph_timer"); } // Create a suspended timer, jobs will be executed in order when diff --git a/src/common/code_environment.cc b/src/common/code_environment.cc index 14d55f60c30..21633fc5d41 100644 --- a/src/common/code_environment.cc +++ b/src/common/code_environment.cc @@ -11,6 +11,7 @@ * Foundation. See file COPYING. * */ +#include "include/compat.h" #include "common/code_environment.h" @@ -18,10 +19,6 @@ #include "acconfig.h" -#ifdef HAVE_PTHREAD_GETNAME_NP -#include -#endif - #include code_environment_t g_code_env = CODE_ENVIRONMENT_UTILITY; @@ -57,7 +54,7 @@ int get_process_name(char *buf, int len) } // FIPS zeroization audit 20191115: this memset is not security related. memset(buf, 0, len); - return pthread_getname_np(pthread_self(), buf, len); + return ceph_pthread_getname(buf, len); } #elif defined(HAVE_GETPROGNAME) diff --git a/src/common/compat.cc b/src/common/compat.cc index 82b57ad94b5..84a395c5a19 100644 --- a/src/common/compat.cc +++ b/src/common/compat.cc @@ -565,3 +565,66 @@ ssize_t get_self_exe_path(char* path, int buff_length) { } #endif /* _WIN32 */ + + +static thread_local char cached_thread_name[256]{}; + +int ceph_pthread_setname(char const* name) +{ + strncpy(cached_thread_name, name, sizeof cached_thread_name - 1); +#if defined(_WIN32) && defined(__clang__) && \ + !defined(_LIBCPP_HAS_THREAD_API_PTHREAD) + // In this case, llvm doesn't use the pthread api for std::thread. + // We cannot use native_handle() with the pthread api, nor can we pass + // it to Windows API functions. + return 0; +#elif defined(HAVE_PTHREAD_SETNAME_NP) + #if defined(__APPLE__) + return pthread_setname_np(name); + #else + return pthread_setname_np(pthread_self(), name); + #endif +#elif defined(HAVE_PTHREAD_SET_NAME_NP) + pthread_set_name_np(pthread_self(), name); \ + return 0; +#else + return 0; +#endif +} + +int ceph_pthread_getname(char* name, size_t len) +{ + if (cached_thread_name[0]) { + if (len > 0) { + strncpy(name, cached_thread_name, len); + name[len-1] = 0; + } + return 0; + } else { +#if defined(_WIN32) && defined(__clang__) && \ + !defined(_LIBCPP_HAS_THREAD_API_PTHREAD) + if (len > 0) { + strcpy(name, ""); + } + return 0; +#elif defined(HAVE_PTHREAD_GETNAME_NP) || defined(HAVE_PTHREAD_GET_NAME_NP) +# if defined(HAVE_PTHREAD_GETNAME_NP) + int rc = pthread_getname_np(pthread_self(), cached_thread_name, sizeof cached_thread_name); +# else + int rc = pthread_get_name_np(pthread_self(), cached_thread_name, sizeof cached_thread_name); +# endif + if (rc == 0) { + strncpy(name, cached_thread_name, len); + name[len-1] = 0; + return 0; + } else { + return rc; + } +#else + if (len > 0) { + strcpy(name, ""); + } + return 0; +#endif + } +} diff --git a/src/common/obj_bencher.cc b/src/common/obj_bencher.cc index 32ecc958618..f5e744e2339 100644 --- a/src/common/obj_bencher.cc +++ b/src/common/obj_bencher.cc @@ -99,6 +99,7 @@ ostream& ObjBencher::out(ostream& os) } void *ObjBencher::status_printer(void *_bencher) { + ceph_pthread_setname("OB::stat_print"); ObjBencher *bencher = static_cast(_bencher); bench_data& data = bencher->data; Formatter *formatter = bencher->formatter; @@ -453,7 +454,6 @@ int ObjBencher::write_bench(int secondsToRun, pthread_t print_thread; pthread_create(&print_thread, NULL, ObjBencher::status_printer, (void *)this); - ceph_pthread_setname(print_thread, "write_stat"); std::unique_lock locker{lock}; data.finished = 0; data.start_time = mono_clock::now(); @@ -691,7 +691,6 @@ int ObjBencher::seq_read_bench( pthread_t print_thread; pthread_create(&print_thread, NULL, status_printer, (void *)this); - ceph_pthread_setname(print_thread, "seq_read_stat"); mono_time finish_time = data.start_time + time_to_run; //start initial reads @@ -903,7 +902,6 @@ int ObjBencher::rand_read_bench( pthread_t print_thread; pthread_create(&print_thread, NULL, status_printer, (void *)this); - ceph_pthread_setname(print_thread, "rand_read_stat"); mono_time finish_time = data.start_time + time_to_run; //start initial reads diff --git a/src/crimson/os/alienstore/thread_pool.cc b/src/crimson/os/alienstore/thread_pool.cc index 5cf9590e61e..277055ec51e 100644 --- a/src/crimson/os/alienstore/thread_pool.cc +++ b/src/crimson/os/alienstore/thread_pool.cc @@ -27,7 +27,7 @@ ThreadPool::ThreadPool(size_t n_threads, pin(*cpus); } block_sighup(); - (void) pthread_setname_np(pthread_self(), "alien-store-tp"); + (void) ceph_pthread_setname("alien-store-tp"); loop(queue_max_wait, i); }); } diff --git a/src/global/signal_handler.cc b/src/global/signal_handler.cc index d3387267871..b8149718724 100644 --- a/src/global/signal_handler.cc +++ b/src/global/signal_handler.cc @@ -307,7 +307,7 @@ static void handle_oneshot_fatal_signal(int signum) char buf[1024]; char pthread_name[16] = {0}; //limited by 16B include terminating null byte. - int r = ceph_pthread_getname(pthread_self(), pthread_name, sizeof(pthread_name)); + int r = ceph_pthread_getname(pthread_name, sizeof(pthread_name)); (void)r; #if defined(__sun) char message[SIG2STR_MAX]; diff --git a/src/include/compat.h b/src/include/compat.h index 53285243d91..a7d10fc5425 100644 --- a/src/include/compat.h +++ b/src/include/compat.h @@ -179,58 +179,10 @@ struct cpu_set_t; #define MSG_DONTWAIT MSG_NONBLOCK #endif -/* compiler warning free success noop */ -#define pthread_setname_noop_helper(thread, name) ({ \ - int __i = 0; \ - __i; }) - -#define pthread_getname_noop_helper(thread, name, len) ({ \ - if (name != NULL) \ - *name = '\0'; \ - 0; }) - #define pthread_kill_unsupported_helper(thread, signal) ({ \ int __i = -ENOTSUP; \ __i; }) -#if defined(_WIN32) && defined(__clang__) && \ - !defined(_LIBCPP_HAS_THREAD_API_PTHREAD) - // In this case, llvm doesn't use the pthread api for std::thread. - // We cannot use native_handle() with the pthread api, nor can we pass - // it to Windows API functions. - #define ceph_pthread_setname pthread_setname_noop_helper -#elif defined(HAVE_PTHREAD_SETNAME_NP) - #if defined(__APPLE__) - #define ceph_pthread_setname(thread, name) ({ \ - int __result = 0; \ - if (thread == pthread_self()) \ - __result = pthread_setname_np(name); \ - __result; }) - #else - #define ceph_pthread_setname pthread_setname_np - #endif -#elif defined(HAVE_PTHREAD_SET_NAME_NP) - /* Fix a small name diff and return 0 */ - #define ceph_pthread_setname(thread, name) ({ \ - pthread_set_name_np(thread, name); \ - 0; }) -#else - #define ceph_pthread_setname pthread_setname_noop_helper -#endif - -#if defined(_WIN32) && defined(__clang__) && \ - !defined(_LIBCPP_HAS_THREAD_API_PTHREAD) - #define ceph_pthread_getname pthread_getname_noop_helper -#elif defined(HAVE_PTHREAD_GETNAME_NP) - #define ceph_pthread_getname pthread_getname_np -#elif defined(HAVE_PTHREAD_GET_NAME_NP) - #define ceph_pthread_getname(thread, name, len) ({ \ - pthread_get_name_np(thread, name, len); \ - 0; }) -#else - #define ceph_pthread_getname pthread_getname_noop_helper -#endif - #if defined(_WIN32) && defined(__clang__) && \ !defined(_LIBCPP_HAS_THREAD_API_PTHREAD) #define ceph_pthread_kill pthread_kill_unsupported_helper @@ -244,6 +196,9 @@ int ceph_posix_fallocate(int fd, off_t offset, off_t len); extern "C" { #endif +int ceph_pthread_getname(char* name, size_t size); +int ceph_pthread_setname(const char* name); + int pipe_cloexec(int pipefd[2], int flags); char *ceph_strerror_r(int errnum, char *buf, size_t buflen); unsigned get_page_size(); diff --git a/src/log/Entry.h b/src/log/Entry.h index db39eca0ef3..eeb25c5f593 100644 --- a/src/log/Entry.h +++ b/src/log/Entry.h @@ -24,6 +24,7 @@ namespace logging { class Entry { public: using time = log_time; + using thread_name_t = std::array; Entry() = delete; Entry(short pr, short sub) : @@ -32,8 +33,7 @@ public: m_prio(pr), m_subsys(sub) { - strncpy(m_thread_name, Thread::get_thread_name().data(), 16); - m_thread_name[15] = '\0'; + ceph_pthread_getname(m_thread_name.data(), m_thread_name.size()); } Entry(const Entry &) = default; Entry& operator=(const Entry &) = default; @@ -47,7 +47,7 @@ public: time m_stamp; pthread_t m_thread; short m_prio, m_subsys; - char m_thread_name[16]; + thread_name_t m_thread_name{}; static log_clock& clock() { static log_clock clock; diff --git a/src/log/Log.cc b/src/log/Log.cc index 8afccee6392..2ac0b4b4095 100644 --- a/src/log/Log.cc +++ b/src/log/Log.cc @@ -501,7 +501,7 @@ void Log::dump_recent() m_recent.clear(); for (const auto& e : t) { auto& set = recent_pthread_ids[e.m_thread]; - set.insert(e.m_thread_name); + set.insert(e.m_thread_name.data()); } _flush(t, true); } diff --git a/src/mds/Beacon.cc b/src/mds/Beacon.cc index 642d3428a27..d79e6f3b8cb 100644 --- a/src/mds/Beacon.cc +++ b/src/mds/Beacon.cc @@ -74,7 +74,7 @@ void Beacon::init(const MDSMap &mdsmap) _notify_mdsmap(mdsmap); sender = std::thread([this]() { - ceph_pthread_setname(pthread_self(), "beacon"); + ceph_pthread_setname("beacon"); std::unique_lock lock(mutex); bool sent; while (!finished) { diff --git a/src/msg/async/Stack.h b/src/msg/async/Stack.h index 6739968f4e2..5f8bbc172df 100644 --- a/src/msg/async/Stack.h +++ b/src/msg/async/Stack.h @@ -352,7 +352,7 @@ class NetworkStack { static constexpr int TASK_COMM_LEN = 16; char tp_name[TASK_COMM_LEN]; sprintf(tp_name, "msgr-worker-%u", id); - ceph_pthread_setname(pthread_self(), tp_name); + ceph_pthread_setname(tp_name); } protected: diff --git a/src/msg/async/rdma/RDMAStack.cc b/src/msg/async/rdma/RDMAStack.cc index 12db599d684..789a624cf90 100644 --- a/src/msg/async/rdma/RDMAStack.cc +++ b/src/msg/async/rdma/RDMAStack.cc @@ -92,7 +92,6 @@ void RDMADispatcher::polling_start() ceph_assert(rx_cq); t = std::thread(&RDMADispatcher::polling, this); - ceph_pthread_setname(t.native_handle(), "rdma-polling"); } void RDMADispatcher::polling_stop() @@ -263,6 +262,7 @@ int RDMADispatcher::post_chunks_to_rq(int num, QueuePair *qp) void RDMADispatcher::polling() { + ceph_pthread_setname("rdma-polling"); static int MAX_COMPLETIONS = 32; ibv_wc wc[MAX_COMPLETIONS]; diff --git a/src/rgw/driver/rados/rgw_notify.cc b/src/rgw/driver/rados/rgw_notify.cc index 7b31fd72bd4..5734284d1a3 100644 --- a/src/rgw/driver/rados/rgw_notify.cc +++ b/src/rgw/driver/rados/rgw_notify.cc @@ -21,6 +21,7 @@ #include "common/dout.h" #include "rgw_url.h" #include +#include #define dout_subsys ceph_subsys_rgw_notification @@ -769,9 +770,10 @@ public: }); // start the worker threads to do the actual queue processing - const std::string WORKER_THREAD_NAME = "notif-worker"; for (auto worker_id = 0U; worker_id < worker_count; ++worker_id) { - workers.emplace_back([this]() { + workers.emplace_back([this,worker_id]() { + const auto thread_name = fmt::format("notif-worker-{}", worker_id); + ceph_pthread_setname(thread_name.c_str()); try { io_context.run(); } catch (const std::exception& err) { @@ -779,11 +781,6 @@ public: throw err; } }); - const auto thread_name = WORKER_THREAD_NAME+std::to_string(worker_id); - if (const auto rc = ceph_pthread_setname(workers.back().native_handle(), thread_name.c_str()); rc != 0) { - ldpp_dout(this, 1) << "ERROR: failed to set notification manager thread name to: " << thread_name - << ". error: " << rc << dendl; - } } ldpp_dout(this, 10) << "INfO: started notification manager with: " << worker_count << " workers" << dendl; } diff --git a/src/rgw/rgw_amqp.cc b/src/rgw/rgw_amqp.cc index 7504d47c6c9..5bc5d173c73 100644 --- a/src/rgw/rgw_amqp.cc +++ b/src/rgw/rgw_amqp.cc @@ -650,6 +650,9 @@ private: // (4) TODO reconnect on connection errors // (5) TODO cleanup timedout callbacks void run() noexcept { + // give the runner thread a name for easier debugging + ceph_pthread_setname("amqp_manager"); + amqp_frame_t frame; while (!stopped) { @@ -838,12 +841,6 @@ public: // This is to prevent rehashing so that iterators are not invalidated // when a new connection is added. connections.max_load_factor(10.0); - // give the runner thread a name for easier debugging - const char* thread_name = "amqp_manager"; - if (const auto rc = ceph_pthread_setname(runner.native_handle(), thread_name); rc != 0) { - ldout(cct, 1) << "ERROR: failed to set amqp manager thread name to: " << thread_name - << ". error: " << rc << dendl; - } } // non copyable diff --git a/src/rgw/rgw_kafka.cc b/src/rgw/rgw_kafka.cc index c0ec3dc2c55..0807993338d 100644 --- a/src/rgw/rgw_kafka.cc +++ b/src/rgw/rgw_kafka.cc @@ -503,6 +503,7 @@ private: } void run() noexcept { + ceph_pthread_setname("kafka_manager"); while (!stopped) { // publish all messages in the queue @@ -575,12 +576,6 @@ public: // This is to prevent rehashing so that iterators are not invalidated // when a new connection is added. connections.max_load_factor(10.0); - // give the runner thread a name for easier debugging - const char* thread_name = "kafka_manager"; - if (const auto rc = ceph_pthread_setname(runner.native_handle(), thread_name); rc != 0) { - ldout(cct, 1) << "ERROR: failed to set kafka manager thread name to: " << thread_name - << ". error: " << rc << dendl; - } } // non copyable diff --git a/src/rgw/rgw_lua_background.cc b/src/rgw/rgw_lua_background.cc index ef97a5d6f65..c5b815f93f5 100644 --- a/src/rgw/rgw_lua_background.cc +++ b/src/rgw/rgw_lua_background.cc @@ -83,11 +83,6 @@ void Background::start() { } started = true; runner = std::thread(&Background::run, this); - const char* thread_name = "lua_background"; - if (const auto rc = ceph_pthread_setname(runner.native_handle(), thread_name); rc != 0) { - ldout(cct, 1) << "ERROR: failed to set lua background thread name to: " << thread_name - << ". error: " << rc << dendl; - } } void Background::pause() { @@ -127,6 +122,7 @@ const BackgroundMapValue& Background::get_table_value(const std::string& key) co //(2) Executes the script //(3) Sleep (configurable) void Background::run() { + ceph_pthread_setname("lua_background"); const DoutPrefixProvider* const dpp = &dp; lua_state_guard lguard(cct->_conf->rgw_lua_max_memory_per_state, dpp); auto L = lguard.get(); diff --git a/src/rgw/rgw_ratelimit.h b/src/rgw/rgw_ratelimit.h index 0db1813f050..beb0eb3b1d2 100644 --- a/src/rgw/rgw_ratelimit.h +++ b/src/rgw/rgw_ratelimit.h @@ -239,6 +239,7 @@ class ActiveRateLimiter : public DoutPrefix { std::atomic_uint8_t current_active = 0; std::shared_ptr ratelimit[2]; void replace_active() { + ceph_pthread_setname("ratelimit_gc"); using namespace std::chrono_literals; std::unique_lock lk(cv_m); while (!stopped) { @@ -286,8 +287,5 @@ class ActiveRateLimiter : public DoutPrefix { void start() { ldpp_dout(this, 20) << "starting ratelimit_gc thread" << dendl; runner = std::thread(&ActiveRateLimiter::replace_active, this); - if (const auto rc = ceph_pthread_setname(runner.native_handle(), "ratelimit_gc"); rc != 0) { - ldpp_dout(this, 1) << "ERROR: failed to set ratelimit_gc thread name. error: " << rc << dendl; - } } }; From bfe489ed19d599b67cacb0bdd4958f36661248f2 Mon Sep 17 00:00:00 2001 From: Patrick Donnelly Date: Thu, 24 Oct 2024 12:34:29 -0400 Subject: [PATCH 3/4] log: cache recent threads up to a day In general, a pthread implementation reuses thread ids routinely so the circular_buffer is there to help us see what the thread name was historically (capped at 4 entries). However, to guard against this map from growing without bound, discard entries that are more than a day old. This would happen if a thread logged an Entry and has since disappeared for more than a day. Signed-off-by: Patrick Donnelly --- src/log/Log.cc | 32 ++++++++++++++++++++++++-------- src/log/Log.h | 8 ++++++++ 2 files changed, 32 insertions(+), 8 deletions(-) diff --git a/src/log/Log.cc b/src/log/Log.cc index 2ac0b4b4095..63d5205d9e2 100644 --- a/src/log/Log.cc +++ b/src/log/Log.cc @@ -373,6 +373,7 @@ void Log::_flush_logbuf() void Log::_flush(EntryVector& t, bool crash) { + auto now = mono_clock::now(); long len = 0; if (t.empty()) { assert(m_log_buf.empty()); @@ -444,10 +445,29 @@ void Log::_flush(EntryVector& t, bool crash) m_journald->log_entry(e); } + { + auto [it, _] = m_recent_thread_names.try_emplace(e.m_thread, now, DEFAULT_MAX_THREAD_NAMES); + auto& [t, names] = it->second; + if (names.size() == 0 || names.front() != e.m_thread_name.data()) { + names.push_front(e.m_thread_name.data()); + } + t = now; + } + m_recent.push_back(std::move(e)); } t.clear(); + for (auto it = m_recent_thread_names.begin(); it != m_recent_thread_names.end(); ) { + auto t = it->second.first; + auto since = now - t; + if (since > std::chrono::seconds(60*60*24)) { + it = m_recent_thread_names.erase(it); + } else { + ++it; + } + } + _flush_logbuf(); } @@ -494,15 +514,10 @@ void Log::dump_recent() _flush(m_flush, false); _log_message("--- begin dump of recent events ---", true); - std::map > recent_pthread_ids; { EntryVector t; t.insert(t.end(), std::make_move_iterator(m_recent.begin()), std::make_move_iterator(m_recent.end())); m_recent.clear(); - for (const auto& e : t) { - auto& set = recent_pthread_ids[e.m_thread]; - set.insert(e.m_thread_name.data()); - } _flush(t, true); } @@ -517,13 +532,14 @@ void Log::dump_recent() m_stderr_log, m_stderr_crash), true); _log_message("--- pthread ID / name mapping for recent threads ---", true); - for (const auto& [pthread_id, pthread_names] : recent_pthread_ids) + for (const auto& [tid, t_names] : m_recent_thread_names) { + [[maybe_unused]] auto [t, names] = t_names; // we want the ID to be printed in the same format as we use for a log entry. // The reason is easier grepping. auto msg = fmt::format(" {:x} / {}", - tid_to_int(pthread_id), - fmt::join(pthread_names, ", ")); + tid_to_int(tid), + fmt::join(names, ", ")); _log_message(msg, true); } diff --git a/src/log/Log.h b/src/log/Log.h index 3a60937af55..46d97734305 100644 --- a/src/log/Log.h +++ b/src/log/Log.h @@ -7,6 +7,7 @@ #include #include +#include #include #include #include @@ -14,6 +15,7 @@ #include #include "common/Thread.h" +#include "common/ceph_time.h" #include "common/likely.h" #include "log/Entry.h" @@ -86,9 +88,14 @@ protected: private: using EntryRing = boost::circular_buffer; + using mono_clock = ceph::coarse_mono_clock; + using mono_time = ceph::coarse_mono_time; + + using RecentThreadNames = std::map > >; static const std::size_t DEFAULT_MAX_NEW = 100; static const std::size_t DEFAULT_MAX_RECENT = 10000; + static constexpr std::size_t DEFAULT_MAX_THREAD_NAMES = 4; Log **m_indirect_this; @@ -102,6 +109,7 @@ private: pthread_t m_queue_mutex_holder; pthread_t m_flush_mutex_holder; + RecentThreadNames m_recent_thread_names; // protected by m_flush_mutex EntryVector m_new; ///< new entries EntryRing m_recent; ///< recent (less new) entries we've already written at low detail EntryVector m_flush; ///< entries to be flushed (here to optimize heap allocations) From a2a989aaa5e9780d98ec9c5cabc66ac2c3a387a4 Mon Sep 17 00:00:00 2001 From: Patrick Donnelly Date: Thu, 24 Oct 2024 14:00:10 -0400 Subject: [PATCH 4/4] mds: add or update MDS thread names To be consistent and sensical. Signed-off-by: Patrick Donnelly --- src/mds/Beacon.cc | 2 +- src/mds/MDCache.cc | 1 + src/mds/MDLog.cc | 12 +++++++----- src/mds/MDSRank.cc | 4 ++-- src/mds/MetricAggregator.cc | 1 + src/mds/MetricsHandler.cc | 1 + src/mds/PurgeQueue.cc | 2 +- src/mds/QuiesceAgent.h | 2 +- src/mds/QuiesceDbManager.cc | 2 +- 9 files changed, 16 insertions(+), 11 deletions(-) diff --git a/src/mds/Beacon.cc b/src/mds/Beacon.cc index d79e6f3b8cb..560d606fa33 100644 --- a/src/mds/Beacon.cc +++ b/src/mds/Beacon.cc @@ -74,7 +74,7 @@ void Beacon::init(const MDSMap &mdsmap) _notify_mdsmap(mdsmap); sender = std::thread([this]() { - ceph_pthread_setname("beacon"); + ceph_pthread_setname("mds-beacon"); std::unique_lock lock(mutex); bool sent; while (!finished) { diff --git a/src/mds/MDCache.cc b/src/mds/MDCache.cc index eb2b529dcfa..35e1a10f866 100644 --- a/src/mds/MDCache.cc +++ b/src/mds/MDCache.cc @@ -14378,6 +14378,7 @@ bool MDCache::is_ready_to_trim_cache(void) void MDCache::upkeep_main(void) { + ceph_pthread_setname("mds-cache-trim"); std::unique_lock lock(upkeep_mutex); // create a "memory model" for the upkeep thread. The object maintains diff --git a/src/mds/MDLog.cc b/src/mds/MDLog.cc index 0be568433ef..0eacbfd94a7 100644 --- a/src/mds/MDLog.cc +++ b/src/mds/MDLog.cc @@ -258,7 +258,7 @@ void MDLog::create(MDSContext *c) logger->set(l_mdl_expos, journaler->get_expire_pos()); logger->set(l_mdl_wrpos, journaler->get_write_pos()); - submit_thread.create("md_submit"); + submit_thread.create("mds-log-submit"); } void MDLog::open(MDSContext *c) @@ -267,9 +267,9 @@ void MDLog::open(MDSContext *c) ceph_assert(!recovery_thread.is_started()); recovery_thread.set_completion(c); - recovery_thread.create("md_recov_open"); + recovery_thread.create("mds-log-recvr"); - submit_thread.create("md_submit"); + submit_thread.create("mds-log-submit"); // either append() or replay() will follow. } @@ -311,7 +311,7 @@ void MDLog::reopen(MDSContext *c) recovery_thread.join(); recovery_thread.set_completion(new C_ReopenComplete(this, c)); - recovery_thread.create("md_recov_reopen"); + recovery_thread.create("mds-log-reopen"); } void MDLog::append() @@ -657,6 +657,8 @@ void MDLog::try_to_commit_open_file_table(uint64_t last_seq) } void MDLog::log_trim_upkeep(void) { + ceph_pthread_setname("mds-log-trim"); + dout(10) << dendl; std::unique_lock mds_lock(mds->mds_lock); @@ -1008,7 +1010,7 @@ void MDLog::replay(MDSContext *c) } already_replayed = true; - replay_thread.create("md_log_replay"); + replay_thread.create("mds-log-replay"); } diff --git a/src/mds/MDSRank.cc b/src/mds/MDSRank.cc index c2f3544f97b..3b73105f3e6 100644 --- a/src/mds/MDSRank.cc +++ b/src/mds/MDSRank.cc @@ -496,7 +496,7 @@ MDSRank::MDSRank( objecter->unset_honor_pool_full(); - finisher = new Finisher(cct, "MDSRank", "MR_Finisher"); + finisher = new Finisher(cct, "MDSRank", "mds-rank-fin"); mdcache = new MDCache(this, purge_queue); mdlog = new MDLog(this); @@ -581,7 +581,7 @@ void MDSRankDispatcher::init() // who is interested in it. handle_osd_map(); - progress_thread.create("mds_rank_progr"); + progress_thread.create("mds-rank-progr"); purge_queue.init(); diff --git a/src/mds/MetricAggregator.cc b/src/mds/MetricAggregator.cc index 1d17bbf3e92..6cbd9a094c0 100644 --- a/src/mds/MetricAggregator.cc +++ b/src/mds/MetricAggregator.cc @@ -73,6 +73,7 @@ int MetricAggregator::init() { m_cct->get_perfcounters_collection()->add(m_perf_counters); pinger = std::thread([this]() { + ceph_pthread_setname("mds-ping"); std::unique_lock locker(lock); while (!stopping) { ping_all_active_ranks(); diff --git a/src/mds/MetricsHandler.cc b/src/mds/MetricsHandler.cc index 9ad10b9d6e6..9fc4c6122a4 100644 --- a/src/mds/MetricsHandler.cc +++ b/src/mds/MetricsHandler.cc @@ -51,6 +51,7 @@ void MetricsHandler::init() { dout(10) << dendl; updater = std::thread([this]() { + ceph_pthread_setname("mds-metrics"); std::unique_lock locker(lock); while (!stopping) { double after = g_conf().get_val("mds_metrics_update_interval").count(); diff --git a/src/mds/PurgeQueue.cc b/src/mds/PurgeQueue.cc index 925bff16542..4426d3ca6fe 100644 --- a/src/mds/PurgeQueue.cc +++ b/src/mds/PurgeQueue.cc @@ -122,7 +122,7 @@ PurgeQueue::PurgeQueue( cct(cct_), rank(rank_), metadata_pool(metadata_pool_), - finisher(cct, "PurgeQueue", "PQ_Finisher"), + finisher(cct, "PurgeQueue", "mds-pq-fin"), timer(cct, lock), filer(objecter_, &finisher), objecter(objecter_), diff --git a/src/mds/QuiesceAgent.h b/src/mds/QuiesceAgent.h index 5c07d6d8074..85900e8e71b 100644 --- a/src/mds/QuiesceAgent.h +++ b/src/mds/QuiesceAgent.h @@ -30,7 +30,7 @@ class QuiesceAgent { : quiesce_control(quiesce_control) , stop_agent_thread(false) , agent_thread(this) { - agent_thread.create("quiesce.agt"); + agent_thread.create("mds-q-agt"); }; virtual ~QuiesceAgent() { diff --git a/src/mds/QuiesceDbManager.cc b/src/mds/QuiesceDbManager.cc index 12c83634e54..bb3ae93e378 100644 --- a/src/mds/QuiesceDbManager.cc +++ b/src/mds/QuiesceDbManager.cc @@ -200,7 +200,7 @@ void QuiesceDbManager::update_membership(const QuiesceClusterMembership& new_mem // start the thread dout(5) << "starting the db mgr thread at epoch: " << new_membership.epoch << dendl; db_thread_should_exit = false; - quiesce_db_thread.create("quiesce_db_mgr"); + quiesce_db_thread.create("mds-q-db"); } else if (quiesce_db_thread.is_started()) { submit_condition.notify_all(); }