System Log error: infinite loop when setting thread affinity fails (#5611) (#5630)

mergify[bot] · juanjo4936 · web-flow · commit 831c8bd8290a · 2025-02-11T07:49:18.000+01:00
* Refs #22624: Regression test Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> * Refs #22624: Corrected bug Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> * Refs #22624: improved structure of the test Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> * Refs #22624: added reviewer suggestions Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> * Refs #22624: fixed reference to new file Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> * Refs #22624: fixed typo Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> * Refs #22624: Added reviwer suggestions Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> * Refs #22624: modified guard Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> * Refs #22624: fixed typo Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> --------- Signed-off-by: Juanjo Garcia <juanjosegarcia@eprosima.com> (cherry picked from commit 8097762) Co-authored-by: juanjo4936 <69901369+juanjo4936@users.noreply.github.com>
diff --git a/src/cpp/utils/threading/thread_logging.hpp b/src/cpp/utils/threading/thread_logging.hpp
@@ -0,0 +1,34 @@
+// Copyright 2025 Proyectos y Sistemas de Mantenimiento SL (eProsima).
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+/*!
+ * @file thread_logging.hpp
+ */
+
+#ifndef THREAD_LOGGING_HPP
+#define THREAD_LOGGING_HPP
+
+#define THREAD_EPROSIMA_LOG_ERROR(thread_name, msg)                         \
+    do{                                                                     \
+        if (strcmp(thread_name, "dds.log") == 0)                            \
+        {                                                                   \
+            std::cerr << msg << std::endl;                                  \
+        }                                                                   \
+        else                                                                \
+        {                                                                   \
+            EPROSIMA_LOG_ERROR(SYSTEM, msg);                                \
+        }                                                                   \
+    } while (0)
+
+#endif  // THREAD_LOGGING_HPP
diff --git a/src/cpp/utils/threading/threading_osx.ipp b/src/cpp/utils/threading/threading_osx.ipp
@@ -22,6 +22,7 @@
 
 #include <fastdds/dds/log/Log.hpp>
 #include <fastdds/rtps/attributes/ThreadSettings.hpp>
+#include <utils/threading/thread_logging.hpp>
 
 namespace eprosima {
 
@@ -98,13 +99,13 @@ static void configure_current_thread_scheduler(
             result = setpriority(PRIO_PROCESS, tid, sched_priority);
             if (0 != result)
             {
-                EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set priority of thread with id [" << tid << "," << thread_name << "] to value " << sched_priority << ". Error '" << strerror(
+                THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set priority of thread with id [" << tid << "," << thread_name << "] to value " << sched_priority << ". Error '" << strerror(
                             result) << "'");
             }
         }
         else if (0 != result)
         {
-            EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << ". Error '" << strerror(
+            THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << ". Error '" << strerror(
                         result) << "'");
         }
     }
@@ -118,7 +119,7 @@ static void configure_current_thread_scheduler(
         result = pthread_setschedparam(self_tid, sched_class, &param);
         if (0 != result)
         {
-            EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << " with priority " << param.sched_priority << ". Error '" << strerror(
+            THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << " with priority " << param.sched_priority << ". Error '" << strerror(
                         result) << "'");
         }
     }
@@ -138,7 +139,7 @@ static void configure_current_thread_affinity(
                         1);
         if (0 != result)
         {
-            EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set affinity of thread with id [" << self_tid << "," << thread_name << "] to value " << affinity << ". Error '" << strerror(
+            THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set affinity of thread with id [" << self_tid << "," << thread_name << "] to value " << affinity << ". Error '" << strerror(
                         result) << "'");
         }
     }
diff --git a/src/cpp/utils/threading/threading_pthread.ipp b/src/cpp/utils/threading/threading_pthread.ipp
@@ -25,6 +25,7 @@
 
 #include <fastdds/dds/log/Log.hpp>
 #include <fastdds/rtps/attributes/ThreadSettings.hpp>
+#include <utils/threading/thread_logging.hpp>
 
 #if defined(__GLIBC__) && ((__GLIBC__ > 2) || ((__GLIBC__ == 2) && (__GLIBC_MINOR__ <= 30)))
 #include <sys/syscall.h>
@@ -114,13 +115,13 @@ static void configure_current_thread_scheduler(
             result = setpriority(PRIO_PROCESS, gettid(), sched_priority);
             if (0 != result)
             {
-                EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set priority of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_priority << ". Error '" << strerror(
+                THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set priority of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_priority << ". Error '" << strerror(
                             result) << "'");
             }
         }
         else if (0 != result)
         {
-            EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << ". Error '" << strerror(
+            THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << ". Error '" << strerror(
                         result) << "'");
         }
     }
@@ -135,7 +136,7 @@ static void configure_current_thread_scheduler(
         result = pthread_setschedparam(self_tid, sched_class, &param);
         if (0 != result)
         {
-            EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << " with priority " << param.sched_priority << ". Error '" << strerror(
+            THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << " with priority " << param.sched_priority << ". Error '" << strerror(
                         result) << "'");
         }
     }
@@ -178,7 +179,7 @@ static void configure_current_thread_affinity(
 
     if (affinity_mask > 0)
     {
-        EPROSIMA_LOG_ERROR(SYSTEM, "Affinity mask has more processors than the ones present in the system");
+        THREAD_EPROSIMA_LOG_ERROR(thread_name, "Affinity mask has more processors than the ones present in the system");
     }
 
     if (result > 0)
@@ -192,7 +193,7 @@ static void configure_current_thread_affinity(
 
     if (0 != result)
     {
-        EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set affinity of thread with id [" << self_tid << "," << thread_name << "] to value " << affinity_mask << ". Error '" << strerror(
+        THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set affinity of thread with id [" << self_tid << "," << thread_name << "] to value " << affinity_mask << ". Error '" << strerror(
                     result) << "'");
     }
 }
diff --git a/src/cpp/utils/threading/threading_win32.ipp b/src/cpp/utils/threading/threading_win32.ipp
@@ -19,6 +19,7 @@
 #include <processthreadsapi.h>
 
 #include <fastdds/rtps/attributes/ThreadSettings.hpp>
+#include <utils/threading/thread_logging.hpp>
 
 namespace eprosima {
 
@@ -69,7 +70,7 @@ static void configure_current_thread_priority(
     {
         if (0 == SetThreadPriority(GetCurrentThread(), priority))
         {
-            EPROSIMA_LOG_ERROR(SYSTEM,
+            THREAD_EPROSIMA_LOG_ERROR(thread_name,
                     "Problem to set priority of thread with id [" << GetCurrentThreadId() << "," << thread_name << "] to value " << priority <<
                     ". Error '" << GetLastError() << "'");
         }
@@ -84,7 +85,7 @@ static void configure_current_thread_affinity(
     {
         if (0 == SetThreadAffinityMask(GetCurrentThread(), static_cast<DWORD_PTR>(affinity_mask)))
         {
-            EPROSIMA_LOG_ERROR(SYSTEM,
+            THREAD_EPROSIMA_LOG_ERROR(thread_name,
                     "Problem to set affinity of thread with id [" << GetCurrentThreadId() << "," << thread_name << "] to value " << affinity_mask <<
                     ". Error '" << GetLastError() << "'");
         }
diff --git a/test/unittest/logging/LogTests.cpp b/test/unittest/logging/LogTests.cpp
@@ -695,6 +695,24 @@ TEST_F(LogTests, thread_config)
     EXPECT_EQ(entries.size(), n_logs);
 }
 
+/**
+ * Regression test 22624: when setting thread affinity fails, eprosima log error throws another error,
+ * and calls eprosima log error. This causes a looping recursive call for eprosima log error.
+ */
+TEST_F(LogTests, thread_log_error_loop)
+{
+    // Set general verbosity
+    Log::SetVerbosity(Log::Error);
+
+    // Set thread settings
+    eprosima::fastdds::rtps::ThreadSettings thr_settings{};
+    thr_settings.affinity = 0xFFFFFFFFFFFFFFFF;
+    Log::SetThreadConfig(thr_settings);
+
+    // Start the error message
+    EPROSIMA_LOG_ERROR(SYSTEM, "Recursive error loop avoided");
+}
+
 int main(
         int argc,
         char** argv)

Original file line number	Diff line number	Diff line change
`@@ -22,6 +22,7 @@`
`22`	`22`
`23`	`23`	`#include <fastdds/dds/log/Log.hpp>`
`24`	`24`	`#include <fastdds/rtps/attributes/ThreadSettings.hpp>`
	`25`	`+#include <utils/threading/thread_logging.hpp>`
`25`	`26`
`26`	`27`	`namespace eprosima {`
`27`	`28`
`@@ -98,13 +99,13 @@ static void configure_current_thread_scheduler(`
`98`	`99`	`result = setpriority(PRIO_PROCESS, tid, sched_priority);`
`99`	`100`	`if (0 != result)`
`100`	`101`	`{`
`101`		`- EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set priority of thread with id [" << tid << "," << thread_name << "] to value " << sched_priority << ". Error '" << strerror(`
	`102`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set priority of thread with id [" << tid << "," << thread_name << "] to value " << sched_priority << ". Error '" << strerror(`
`102`	`103`	`result) << "'");`
`103`	`104`	`}`
`104`	`105`	`}`
`105`	`106`	`else if (0 != result)`
`106`	`107`	`{`
`107`		`- EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << ". Error '" << strerror(`
	`108`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << ". Error '" << strerror(`
`108`	`109`	`result) << "'");`
`109`	`110`	`}`
`110`	`111`	`}`
`@@ -118,7 +119,7 @@ static void configure_current_thread_scheduler(`
`118`	`119`	`result = pthread_setschedparam(self_tid, sched_class, &param);`
`119`	`120`	`if (0 != result)`
`120`	`121`	`{`
`121`		`- EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << " with priority " << param.sched_priority << ". Error '" << strerror(`
	`122`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << " with priority " << param.sched_priority << ". Error '" << strerror(`
`122`	`123`	`result) << "'");`
`123`	`124`	`}`
`124`	`125`	`}`
`@@ -138,7 +139,7 @@ static void configure_current_thread_affinity(`
`138`	`139`	`1);`
`139`	`140`	`if (0 != result)`
`140`	`141`	`{`
`141`		`- EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set affinity of thread with id [" << self_tid << "," << thread_name << "] to value " << affinity << ". Error '" << strerror(`
	`142`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set affinity of thread with id [" << self_tid << "," << thread_name << "] to value " << affinity << ". Error '" << strerror(`
`142`	`143`	`result) << "'");`
`143`	`144`	`}`
`144`	`145`	`}`
Original file line number	Diff line number	Diff line change
`@@ -25,6 +25,7 @@`
`25`	`25`
`26`	`26`	`#include <fastdds/dds/log/Log.hpp>`
`27`	`27`	`#include <fastdds/rtps/attributes/ThreadSettings.hpp>`
	`28`	`+#include <utils/threading/thread_logging.hpp>`
`28`	`29`
`29`	`30`	`#if defined(__GLIBC__) && ((__GLIBC__ > 2) \|\| ((__GLIBC__ == 2) && (__GLIBC_MINOR__ <= 30)))`
`30`	`31`	`#include <sys/syscall.h>`
`@@ -114,13 +115,13 @@ static void configure_current_thread_scheduler(`
`114`	`115`	`result = setpriority(PRIO_PROCESS, gettid(), sched_priority);`
`115`	`116`	`if (0 != result)`
`116`	`117`	`{`
`117`		`- EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set priority of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_priority << ". Error '" << strerror(`
	`118`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set priority of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_priority << ". Error '" << strerror(`
`118`	`119`	`result) << "'");`
`119`	`120`	`}`
`120`	`121`	`}`
`121`	`122`	`else if (0 != result)`
`122`	`123`	`{`
`123`		`- EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << ". Error '" << strerror(`
	`124`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << ". Error '" << strerror(`
`124`	`125`	`result) << "'");`
`125`	`126`	`}`
`126`	`127`	`}`
`@@ -135,7 +136,7 @@ static void configure_current_thread_scheduler(`
`135`	`136`	`result = pthread_setschedparam(self_tid, sched_class, &param);`
`136`	`137`	`if (0 != result)`
`137`	`138`	`{`
`138`		`- EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << " with priority " << param.sched_priority << ". Error '" << strerror(`
	`139`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set scheduler of thread with id [" << self_tid << "," << thread_name << "] to value " << sched_class << " with priority " << param.sched_priority << ". Error '" << strerror(`
`139`	`140`	`result) << "'");`
`140`	`141`	`}`
`141`	`142`	`}`
`@@ -178,7 +179,7 @@ static void configure_current_thread_affinity(`
`178`	`179`
`179`	`180`	`if (affinity_mask > 0)`
`180`	`181`	`{`
`181`		`- EPROSIMA_LOG_ERROR(SYSTEM, "Affinity mask has more processors than the ones present in the system");`
	`182`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name, "Affinity mask has more processors than the ones present in the system");`
`182`	`183`	`}`
`183`	`184`
`184`	`185`	`if (result > 0)`
`@@ -192,7 +193,7 @@ static void configure_current_thread_affinity(`
`192`	`193`
`193`	`194`	`if (0 != result)`
`194`	`195`	`{`
`195`		`- EPROSIMA_LOG_ERROR(SYSTEM, "Problem to set affinity of thread with id [" << self_tid << "," << thread_name << "] to value " << affinity_mask << ". Error '" << strerror(`
	`196`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name, "Problem to set affinity of thread with id [" << self_tid << "," << thread_name << "] to value " << affinity_mask << ". Error '" << strerror(`
`196`	`197`	`result) << "'");`
`197`	`198`	`}`
`198`	`199`	`}`
Original file line number	Diff line number	Diff line change
`@@ -19,6 +19,7 @@`
`19`	`19`	`#include <processthreadsapi.h>`
`20`	`20`
`21`	`21`	`#include <fastdds/rtps/attributes/ThreadSettings.hpp>`
	`22`	`+#include <utils/threading/thread_logging.hpp>`
`22`	`23`
`23`	`24`	`namespace eprosima {`
`24`	`25`
`@@ -69,7 +70,7 @@ static void configure_current_thread_priority(`
`69`	`70`	`{`
`70`	`71`	`if (0 == SetThreadPriority(GetCurrentThread(), priority))`
`71`	`72`	`{`
`72`		`- EPROSIMA_LOG_ERROR(SYSTEM,`
	`73`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name,`
`73`	`74`	`"Problem to set priority of thread with id [" << GetCurrentThreadId() << "," << thread_name << "] to value " << priority <<`
`74`	`75`	`". Error '" << GetLastError() << "'");`
`75`	`76`	`}`
`@@ -84,7 +85,7 @@ static void configure_current_thread_affinity(`
`84`	`85`	`{`
`85`	`86`	`if (0 == SetThreadAffinityMask(GetCurrentThread(), static_cast<DWORD_PTR>(affinity_mask)))`
`86`	`87`	`{`
`87`		`- EPROSIMA_LOG_ERROR(SYSTEM,`
	`88`	`+ THREAD_EPROSIMA_LOG_ERROR(thread_name,`
`88`	`89`	`"Problem to set affinity of thread with id [" << GetCurrentThreadId() << "," << thread_name << "] to value " << affinity_mask <<`
`89`	`90`	`". Error '" << GetLastError() << "'");`
`90`	`91`	`}`