You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@geode.apache.org by mm...@apache.org on 2022/02/08 14:48:27 UTC

[geode-native] branch develop updated: GEODE-10016: Add map of threadId to threadName (#918)

This is an automated email from the ASF dual-hosted git repository.

mmartell pushed a commit to branch develop
in repository https://gitbox.apache.org/repos/asf/geode-native.git


The following commit(s) were added to refs/heads/develop by this push:
     new f60277d  GEODE-10016: Add map of threadId to threadName (#918)
f60277d is described below

commit f60277dee9a33502a8fe832f5db54a8f9543eb32
Author: Michael Martell <mm...@pivotal.io>
AuthorDate: Tue Feb 8 06:48:17 2022 -0800

    GEODE-10016: Add map of threadId to threadName (#918)
    
    * Save threadName to thread_local storage
    * Per review, get/setThreadName doesn't need tid
    * Add threadName in parens after tid
    * Update gnmsg for threadName
    * Move accessors to Log class
    * Inline threadNames instead of constants
    * Remove getThreadName()
---
 cppcache/src/ClientMetadataService.cpp       |  4 +-
 cppcache/src/DataOutput.cpp                  |  5 +--
 cppcache/src/DistributedSystemImpl.cpp       | 37 ----------------
 cppcache/src/DistributedSystemImpl.hpp       |  2 -
 cppcache/src/EvictionController.cpp          |  3 +-
 cppcache/src/ExpiryTaskManager.cpp           |  6 +--
 cppcache/src/Log.cpp                         | 63 +++++++++++++++++++++++-----
 cppcache/src/Task.hpp                        |  3 +-
 cppcache/src/ThreadPool.cpp                  |  5 +--
 cppcache/src/statistics/HostStatSampler.cpp  |  2 +-
 cppcache/src/statistics/PoolStatsSampler.cpp |  4 +-
 cppcache/src/util/Log.hpp                    |  2 +
 tools/gnmsg/client_message_decoder.py        | 24 +++++++++--
 13 files changed, 84 insertions(+), 76 deletions(-)

diff --git a/cppcache/src/ClientMetadataService.cpp b/cppcache/src/ClientMetadataService.cpp
index 4092cf2..5600c4b 100644
--- a/cppcache/src/ClientMetadataService.cpp
+++ b/cppcache/src/ClientMetadataService.cpp
@@ -37,8 +37,6 @@ namespace client {
 
 const BucketStatus::clock::time_point BucketStatus::m_noTimeout{};
 
-const char* ClientMetadataService::NC_CMDSvcThread = "NC CMDSvcThread";
-
 ClientMetadataService::ClientMetadataService(ThinClientPoolDM* pool)
     : m_run(false),
       m_pool(pool),
@@ -66,7 +64,7 @@ void ClientMetadataService::stop() {
 }
 
 void ClientMetadataService::svc() {
-  DistributedSystemImpl::setThreadName(NC_CMDSvcThread);
+  Log::setThreadName("NC CMDSvcThread");
 
   LOGINFO("ClientMetadataService started for pool " + m_pool->getName());
 
diff --git a/cppcache/src/DataOutput.cpp b/cppcache/src/DataOutput.cpp
index 6b234ce..ea6a071 100644
--- a/cppcache/src/DataOutput.cpp
+++ b/cppcache/src/DataOutput.cpp
@@ -92,10 +92,7 @@ class TSSDataOutput {
   static thread_local TSSDataOutput threadLocalBufferPool;
 };
 
-TSSDataOutput::TSSDataOutput() : m_buffers() {
-  m_buffers.reserve(10);
-  LOGDEBUG("DATAOUTPUT poolsize is %zu", m_buffers.size());
-}
+TSSDataOutput::TSSDataOutput() : m_buffers() { m_buffers.reserve(10); }
 
 TSSDataOutput::~TSSDataOutput() {
   while (!m_buffers.empty()) {
diff --git a/cppcache/src/DistributedSystemImpl.cpp b/cppcache/src/DistributedSystemImpl.cpp
index 6606246..a7338ed 100644
--- a/cppcache/src/DistributedSystemImpl.cpp
+++ b/cppcache/src/DistributedSystemImpl.cpp
@@ -143,43 +143,6 @@ void DistributedSystemImpl::unregisterCliCallback(int appdomainId) {
   }
 }
 
-void DistributedSystemImpl::setThreadName(const std::string& threadName) {
-  if (threadName.empty()) {
-    throw IllegalArgumentException("Thread name is empty.");
-  }
-
-#if defined(HAVE_pthread_setname_np)
-
-  pthread_setname_np(threadName.c_str());
-
-#elif defined(_WIN32)
-
-  const DWORD MS_VC_EXCEPTION = 0x406D1388;
-
-#pragma pack(push, 8)
-  typedef struct tagTHREADNAME_INFO {
-    DWORD dwType;      // Must be 0x1000.
-    LPCSTR szName;     // Pointer to name (in user addr space).
-    DWORD dwThreadID;  // Thread ID (-1=caller thread).
-    DWORD dwFlags;     // Reserved for future use, must be zero.
-  } THREADNAME_INFO;
-#pragma pack(pop)
-
-  THREADNAME_INFO info;
-  info.dwType = 0x1000;
-  info.szName = threadName.c_str();
-  info.dwThreadID = -1;
-  info.dwFlags = 0;
-
-  __try {
-    RaiseException(MS_VC_EXCEPTION, 0, sizeof(info) / sizeof(ULONG_PTR),
-                   (ULONG_PTR*)&info);
-  } __except (EXCEPTION_EXECUTE_HANDLER) {
-  }
-
-#endif
-}
-
 }  // namespace client
 }  // namespace geode
 }  // namespace apache
diff --git a/cppcache/src/DistributedSystemImpl.hpp b/cppcache/src/DistributedSystemImpl.hpp
index e920e38..88b661b 100644
--- a/cppcache/src/DistributedSystemImpl.hpp
+++ b/cppcache/src/DistributedSystemImpl.hpp
@@ -47,8 +47,6 @@ using CliCallbackMethod = std::function<void(Cache&)>;
  */
 class DistributedSystemImpl {
  public:
-  static void setThreadName(const std::string& threadName);
-
   /**
    * @brief destructor
    */
diff --git a/cppcache/src/EvictionController.cpp b/cppcache/src/EvictionController.cpp
index 60c6646..6d9158c 100644
--- a/cppcache/src/EvictionController.cpp
+++ b/cppcache/src/EvictionController.cpp
@@ -28,7 +28,6 @@
 #include "util/Log.hpp"
 
 namespace {
-const char* const NC_EC_Thread = "NC EC Thread";
 const std::chrono::seconds EVICTION_TIMEOUT{1};
 }  // namespace
 
@@ -65,7 +64,7 @@ void EvictionController::stop() {
 
 void EvictionController::svc() {
   std::mutex mutex;
-  DistributedSystemImpl::setThreadName(NC_EC_Thread);
+  Log::setThreadName("NC EC Thread");
 
   while (running_) {
     {
diff --git a/cppcache/src/ExpiryTaskManager.cpp b/cppcache/src/ExpiryTaskManager.cpp
index 04dc994..920c5f0 100644
--- a/cppcache/src/ExpiryTaskManager.cpp
+++ b/cppcache/src/ExpiryTaskManager.cpp
@@ -22,10 +22,6 @@
 #include "DistributedSystemImpl.hpp"
 #include "util/Log.hpp"
 
-namespace {
-const char *NC_ETM_Thread = "NC ETM Thread";
-}
-
 namespace apache {
 namespace geode {
 namespace client {
@@ -51,7 +47,7 @@ void ExpiryTaskManager::start() {
   auto start_future = start_promise.get_future();
   runner_ = std::thread{[this, &start_promise] {
     start_promise.set_value(true);
-    DistributedSystemImpl::setThreadName(NC_ETM_Thread);
+    Log::setThreadName("NC ETM Thread");
 
     LOGFINE("ExpiryTaskManager thread is running.");
     io_context_.run();
diff --git a/cppcache/src/Log.cpp b/cppcache/src/Log.cpp
index 819ea82..0f33b71 100644
--- a/cppcache/src/Log.cpp
+++ b/cppcache/src/Log.cpp
@@ -60,6 +60,8 @@ static FILE* g_log = nullptr;
 
 static std::string g_hostName;
 
+static thread_local std::string g_threadName;
+
 const int __1K__ = 1024;
 const int __1M__ = (__1K__ * __1K__);
 
@@ -369,21 +371,60 @@ LogLevel Log::charsToLevel(const std::string& chars) {
   }
 }
 
+void Log::setThreadName(const std::string& threadName) {
+  if (threadName.empty()) {
+    throw IllegalArgumentException("Thread name is empty.");
+  }
+
+  g_threadName = threadName;
+
+#if defined(HAVE_pthread_setname_np)
+
+  pthread_setname_np(threadName.c_str());
+
+#elif defined(_WIN32)
+
+  const DWORD MS_VC_EXCEPTION = 0x406D1388;
+
+#pragma pack(push, 8)
+  typedef struct tagTHREADNAME_INFO {
+    DWORD dwType;      // Must be 0x1000.
+    LPCSTR szName;     // Pointer to name (in user addr space).
+    DWORD dwThreadID;  // Thread ID (-1=caller thread).
+    DWORD dwFlags;     // Reserved for future use, must be zero.
+  } THREADNAME_INFO;
+#pragma pack(pop)
+
+  THREADNAME_INFO info;
+  info.dwType = 0x1000;
+  info.szName = threadName.c_str();
+  info.dwThreadID = -1;
+  info.dwFlags = 0;
+
+  __try {
+    RaiseException(MS_VC_EXCEPTION, 0, sizeof(info) / sizeof(ULONG_PTR),
+                   (ULONG_PTR*)&info);
+  } __except (EXCEPTION_EXECUTE_HANDLER) {
+  }
+
+#endif
+}
+
 std::string Log::formatLogLine(LogLevel level) {
   std::stringstream msg;
-  const size_t MINBUFSIZE = 128;
-  auto now = std::chrono::system_clock::now();
-  auto secs = std::chrono::system_clock::to_time_t(now);
-  auto microseconds = std::chrono::duration_cast<std::chrono::microseconds>(
-      now - std::chrono::system_clock::from_time_t(secs));
-  auto tm_val = apache::geode::util::chrono::localtime(secs);
-
-  msg << "[" << Log::levelToChars(level) << " "
+  const auto now = std::chrono::system_clock::now();
+  const auto secs = std::chrono::system_clock::to_time_t(now);
+  const auto microseconds =
+      std::chrono::duration_cast<std::chrono::microseconds>(
+          now - std::chrono::system_clock::from_time_t(secs));
+  const auto tm_val = apache::geode::util::chrono::localtime(secs);
+
+  msg << '[' << Log::levelToChars(level) << ' '
       << std::put_time(&tm_val, "%Y/%m/%d %H:%M:%S") << '.' << std::setfill('0')
       << std::setw(6) << microseconds.count() << ' '
-      << std::put_time(&tm_val, "%z  ") << g_hostName << ":"
-      << boost::this_process::get_id() << " " << std::this_thread::get_id()
-      << "] ";
+      << std::put_time(&tm_val, "%z  ") << g_hostName << ':'
+      << boost::this_process::get_id() << ' ' << std::this_thread::get_id()
+      << " (" << g_threadName << ")] ";
 
   return msg.str();
 }
diff --git a/cppcache/src/Task.hpp b/cppcache/src/Task.hpp
index a86783d..1ff0931 100644
--- a/cppcache/src/Task.hpp
+++ b/cppcache/src/Task.hpp
@@ -26,6 +26,7 @@
 
 #include "AppDomainContext.hpp"
 #include "DistributedSystemImpl.hpp"
+#include "./util/Log.hpp"
 
 namespace apache {
 namespace geode {
@@ -68,7 +69,7 @@ class Task {
   }
 
   inline void svc(void) {
-    DistributedSystemImpl::setThreadName(threadName_);
+    Log::setThreadName(threadName_);
 
     if (appDomainContext_) {
       appDomainContext_->run(
diff --git a/cppcache/src/ThreadPool.cpp b/cppcache/src/ThreadPool.cpp
index 6f43baa..887a45a 100644
--- a/cppcache/src/ThreadPool.cpp
+++ b/cppcache/src/ThreadPool.cpp
@@ -17,19 +17,18 @@
 #include "ThreadPool.hpp"
 
 #include "DistributedSystemImpl.hpp"
+#include "util/Log.hpp"
 
 namespace apache {
 namespace geode {
 namespace client {
 
-const char* ThreadPool::NC_Pool_Thread = "NC Pool Thread";
-
 ThreadPool::ThreadPool(size_t threadPoolSize)
     : shutdown_(false), appDomainContext_(createAppDomainContext()) {
   workers_.reserve(threadPoolSize);
 
   std::function<void()> executeWork = [this] {
-    DistributedSystemImpl::setThreadName(NC_Pool_Thread);
+    Log::setThreadName("NC Pool Thread");
     while (true) {
       std::unique_lock<decltype(queueMutex_)> lock(queueMutex_);
       queueCondition_.wait(lock,
diff --git a/cppcache/src/statistics/HostStatSampler.cpp b/cppcache/src/statistics/HostStatSampler.cpp
index d39f448..500c6c6 100644
--- a/cppcache/src/statistics/HostStatSampler.cpp
+++ b/cppcache/src/statistics/HostStatSampler.cpp
@@ -427,7 +427,7 @@ void HostStatSampler::checkDiskLimit() {
 }
 
 void HostStatSampler::svc(void) {
-  client::DistributedSystemImpl::setThreadName("NC HSS Thread");
+  client::Log::setThreadName("NC HSS Thread");
   try {
     // createArchiveFileName instead of getArchiveFileName here because
     // for the first time the sampler needs to add the pid to the filename
diff --git a/cppcache/src/statistics/PoolStatsSampler.cpp b/cppcache/src/statistics/PoolStatsSampler.cpp
index 76bdb01..9da17ca 100644
--- a/cppcache/src/statistics/PoolStatsSampler.cpp
+++ b/cppcache/src/statistics/PoolStatsSampler.cpp
@@ -34,8 +34,6 @@ using std::chrono::high_resolution_clock;
 using std::chrono::milliseconds;
 using std::chrono::nanoseconds;
 
-const char* PoolStatsSampler::NC_PSS_Thread = "NC PSS Thread";
-
 PoolStatsSampler::PoolStatsSampler(milliseconds sampleRate, CacheImpl* cache,
                                    ThinClientPoolDM* distMan)
     : m_running(false),
@@ -47,7 +45,7 @@ PoolStatsSampler::PoolStatsSampler(milliseconds sampleRate, CacheImpl* cache,
           cache->getStatisticsManager().getStatisticsFactory()) {}
 
 void PoolStatsSampler::svc() {
-  client::DistributedSystemImpl::setThreadName(NC_PSS_Thread);
+  client::Log::setThreadName("NC PSS Thread");
   while (!m_stopRequested) {
     auto sampleStart = high_resolution_clock::now();
     putStatsInAdminRegion();
diff --git a/cppcache/src/util/Log.hpp b/cppcache/src/util/Log.hpp
index c1eef51..19f5e64 100644
--- a/cppcache/src/util/Log.hpp
+++ b/cppcache/src/util/Log.hpp
@@ -193,6 +193,8 @@ class APACHE_GEODE_EXPORT Log {
 
   static bool enabled(LogLevel level);
 
+  static void setThreadName(const std::string& threadName);
+
  private:
   static LogLevel s_logLevel;
 
diff --git a/tools/gnmsg/client_message_decoder.py b/tools/gnmsg/client_message_decoder.py
index 4895dcc..20e76f0 100644
--- a/tools/gnmsg/client_message_decoder.py
+++ b/tools/gnmsg/client_message_decoder.py
@@ -79,7 +79,7 @@ class ClientMessageDecoder(DecoderBase):
         ]
 
         self.security_trace_expression_ = re.compile(
-            r"(\d\d\d\d\/\d\d\/\d\d \d\d:\d\d:\d\d\.\d+).*([\d|a-f|A-F|x|X]+)\]\s*TcrMessage::addSecurityPart\s*\[(0x[\d|a-f|A-F]*).*length\s*=\s*(\d+)\s*,\s*encrypted\s+ID\s*=\s*([\d|a-f|A-F]+)"
+            r"(\d\d\d\d\/\d\d\/\d\d \d\d:\d\d:\d\d\.\d+).*([\d|a-f|A-F|x|X]+) .*\]\s*TcrMessage::addSecurityPart\s*\[(0x[\d|a-f|A-F]*).*length\s*=\s*(\d+)\s*,\s*encrypted\s+ID\s*=\s*([\d|a-f|A-F]+)"
         )
 
         self.send_trace_expression_v911_ = re.compile(
@@ -87,7 +87,10 @@ class ClientMessageDecoder(DecoderBase):
         )
 
         self.send_trace_expression_base_ = re.compile(
-            r"(\d\d\d\d\/\d\d\/\d\d \d\d:\d\d:\d\d\.\d+).+:\d+\s+([\d|a-f|A-F|x|X]+)\]\s*TcrConnection::send:\s*\[([\d|a-f|A-F|x|X]+).*sending request to endpoint.*bytes:\s*(.+)"
+            r"(\d\d\d\d\/\d\d\/\d\d \d\d:\d\d:\d\d\.\d+).+:\d+\s+([\d|a-f|A-F|x|X]+).*\]\s*TcrConnection::send:\s*\[([\d|a-f|A-F|x|X]+).*sending request to endpoint.*bytes:\s*(.+)"
+        )
+        self.send_trace_expression_with_thread_name_ = re.compile(
+            r"(\d\d\d\d\/\d\d\/\d\d \d\d:\d\d:\d\d\.\d+).+:\d+\s+([\d|a-f|A-F|x|X]+) \(([\w|\s]+).*\]\s*TcrConnection::send:\s*\[([\d|a-f|A-F|x|X]+).*sending request to endpoint.*bytes:\s*(.+)"
         )
 
     def get_send_trace_parts_v911(self, line, parts):
@@ -105,13 +108,23 @@ class ClientMessageDecoder(DecoderBase):
 
     def get_send_trace_parts_base(self, line, parts):
         result = False
-        match = self.send_trace_expression_base_.search(line)
+        match = self.send_trace_expression_with_thread_name_.search(line)
         if match:
             parts.append(parser.parse(match.group(1)))
             parts.append(match.group(2))
             parts.append(match.group(3))
-            parts.append(match.group(4))
+            parts.append(match.group(4)) 
+            parts.append(match.group(5)) 
             result = True
+        else:
+          match = self.send_trace_expression_base_.search(line)
+          if match:
+              parts.append(parser.parse(match.group(1)))
+              parts.append(match.group(2))
+              parts.append("")
+              parts.append(match.group(3))
+              parts.append(match.group(4))
+              result = True
 
         return result
 
@@ -214,9 +227,12 @@ class ClientMessageDecoder(DecoderBase):
             (
                 send_trace["Timestamp"],
                 send_trace["tid"],
+                send_trace["ThreadName"],
                 send_trace["Connection"],
                 message_bytes,
             ) = parts
+            if send_trace["ThreadName"] == "":
+              del(send_trace["ThreadName"])
             is_send_trace = True
         elif self.get_add_security_trace_parts(line, parts):
             timestamp, tid, connection, security_footer_length, message_bytes = parts