Fixed timed logging for MODE_ROSLOG

ethz-asl · Apr 5, 2024 · 5157822 · 5157822
1 parent 6c2c16f
commit 5157822
Show file tree

Hide file tree

Showing 5 changed files with 150 additions and 12 deletions.
diff --git a/CMakeLists.txt b/CMakeLists.txt
@@ -140,6 +140,7 @@ if (GLOG_FOUND AND catkin_FOUND AND LPP_BUILD_TESTS)
                 test/roslog/test_roslog_if_every_n.cc
                 test/roslog/test_roslog_log_string.cc
                 test/roslog/test_roslog_rosprintf.cc
+                test/roslog/test_roslog_timed.cc
                 test/roslog/test_roslog_vlog.cc)
 
         target_include_directories(${ROSLOG_TESTS} PRIVATE ${LPP_INCLUDE_DIRECTORIES} test/roslog)

diff --git a/include/log++.h b/include/log++.h
@@ -409,11 +409,13 @@ if      constexpr(LPP_INTL::LppSeverity::severity == LPP_INTL::LppSeverity::I
 
 #if defined MODE_ROSLOG || defined MODE_LPP
 #define LOG_EVERY_N(severity, n) LPP_INTL::InternalPolicyLog<int>(LPP_GET_KEY(), n, LPP_INTL::toBase(LPP_INTL::GlogSeverity::severity), LPP_INTL::PolicyType::EVERY_N)
+#define LOG_EVERY_T(severity, t) LPP_INTL::InternalPolicyLog<float>(LPP_GET_KEY(), t, LPP_INTL::toBase(LPP_INTL::GlogSeverity::severity), LPP_INTL::PolicyType::TIMED)
 #define LOG_IF_EVERY_N(severity, condition, n) if (condition) LOG_EVERY_N(severity, n)
 #define LOG_FIRST_N(severity, n) LPP_INTL::InternalPolicyLog<int>(LPP_GET_KEY(), n, LPP_INTL::toBase(LPP_INTL::GlogSeverity::severity), LPP_INTL::PolicyType::FIRST_N)
 
 #define DLOG(severity) LPP_ASSERT_GLOG(LPP_INTL::GlogSeverity::severity); LPP_INTL::InternalLog(LPP_INTL::BaseSeverity::DEBUG)
 #define DLOG_EVERY_N(severity, n) LPP_ASSERT_GLOG(LPP_INTL::GlogSeverity::severity); LPP_INTL::InternalPolicyLog<int>(LPP_GET_KEY(), n, LPP_INTL::BaseSeverity::DEBUG, LPP_INTL::PolicyType::EVERY_N)
+#define DLOG_EVERY_T(severity, t) LPP_ASSERT_GLOG(LPP_INTL::GlogSeverity::severity); LPP_INTL::InternalPolicyLog<float>(LPP_GET_KEY(), t, LPP_INTL::BaseSeverity::DEBUG, LPP_INTL::PolicyType::TIMED)
 #define DLOG_FIRST_N(severity, n) LPP_WARN("DLOG_FIRST_N is a Log++ extension"); LPP_ASSERT_GLOG(LPP_INTL::GlogSeverity::severity); \
 LPP_INTL::InternalPolicyLog<int>(LPP_GET_KEY(), n, LPP_INTL::BaseSeverity::DEBUG, LPP_INTL::PolicyType::FIRST_N)
 #define DLOG_IF_EVERY_N(severity, condition, n) LPP_ASSERT_GLOG(LPP_INTL::GlogSeverity::severity); if (condition) LPP_INTL::InternalPolicyLog<int>(LPP_GET_KEY(), n, LPP_INTL::BaseSeverity::DEBUG, LPP_INTL::PolicyType::EVERY_N)

diff --git a/test/common/async_tests.h b/test/common/async_tests.h
@@ -16,7 +16,8 @@
 
 enum CompareType {
   EQUAL,
-  IS_SUBSTRING
+  IS_SUBSTRING,
+  REMOVE_NUMBERS_FROM_STRING
 };
 
 enum StreamType {
@@ -128,6 +129,7 @@ class TestResult {
     switch (compare_type) {
       case EQUAL:return compareEquality(output, expected_output);
       case IS_SUBSTRING: return compareSubstring(output, expected_output);
+      case REMOVE_NUMBERS_FROM_STRING: return compareRemoveNumbersFromString(output, expected_output);
       default:return false;
     }
   }
@@ -143,6 +145,10 @@ class TestResult {
     return output == expected_output;
   };
 
+  static inline bool compareRemoveNumbersFromString(const std::string &output, const std::string &expected_output) {
+    return expected_output == removeNumbersFromString(output);
+  }
+
   inline void insert(const std::string &test_name, bool test_status) {
     test_results.insert({test_name, test_status});
   }

diff --git a/test/lpp/test_lpp_timed.cc b/test/lpp/test_lpp_timed.cc
@@ -9,17 +9,17 @@
 
 std::vector<AsyncTest> generateTests() {
   return {
-  {"lpp_timed_lpp_syntax_severity_debug_Test","DEBUG Test123\n",[]() { LOG_TIMED(D, 1, "Test" << 123); }, IS_SUBSTRING, STDOUT},
-  {"lpp_timed_lpp_syntax_severity_info_Test","INFO  Test123\n",[]() { LOG_TIMED(I, 1, "Test" << 123); }, IS_SUBSTRING, STDOUT},
-  {"lpp_timed_lpp_syntax_severity_warning_Test","WARN  Test123\n",[]() { LOG_TIMED(W, 1, "Test" << 123); }, IS_SUBSTRING, STDOUT},
-  {"lpp_timed_lpp_syntax_severity_error_Test","ERROR Test123\n",[]() { LOG_TIMED(E, 1, "Test" << 123); }, IS_SUBSTRING, STDOUT},
-  {"lpp_timed_lpp_syntax_severity_fatal_Test","FATAL Test123\n",[]() { LOG_TIMED(F, 1, "Test" << 123); }, IS_SUBSTRING, STDOUT},
-
-  {"lpp_timed_glog_syntax_severity_debug_Test","DEBUG Test123\n",[]() { DLOG_EVERY_T(INFO, 1) << "Test" << 123; }, IS_SUBSTRING, STDOUT},
-  {"lpp_timed_glog_syntax_severity_info_Test","INFO  Test123\n",[]() { LOG_EVERY_T(INFO, 1) << "Test" << 123; }, IS_SUBSTRING, STDOUT},
-  {"lpp_timed_glog_syntax_severity_warning_Test","WARN  Test123\n",[]() { LOG_EVERY_T(WARNING, 1) << "Test" << 123; }, IS_SUBSTRING, STDOUT},
-  {"lpp_timed_glog_syntax_severity_error_Test","ERROR Test123\n",[]() { LOG_EVERY_T(ERROR, 1) << "Test" << 123; }, IS_SUBSTRING, STDOUT},
-  {"lpp_timed_glog_syntax_severity_fatal_Test","FATAL Test123\n",[]() { LOG_EVERY_T(FATAL, 1) << "Test" << 123; }, IS_SUBSTRING, STDOUT},
+  {"lpp_timed_lpp_syntax_severity_debug_Test","DEBUG Test123\n",[]() { LOG_TIMED(D, 1, "Test" << 123); }, EQUAL, STDOUT},
+  {"lpp_timed_lpp_syntax_severity_info_Test","INFO  Test123\n",[]() { LOG_TIMED(I, 1, "Test" << 123); }, EQUAL, STDOUT},
+  {"lpp_timed_lpp_syntax_severity_warning_Test","WARN  Test123\n",[]() { LOG_TIMED(W, 1, "Test" << 123); }, EQUAL, STDOUT},
+  {"lpp_timed_lpp_syntax_severity_error_Test","ERROR Test123\n",[]() { LOG_TIMED(E, 1, "Test" << 123); }, EQUAL, STDOUT},
+  {"lpp_timed_lpp_syntax_severity_fatal_Test","FATAL Test123\n",[]() { LOG_TIMED(F, 1, "Test" << 123); }, EQUAL, STDOUT},
+
+  {"lpp_timed_glog_syntax_severity_debug_Test","DEBUG Test123\n",[]() { DLOG_EVERY_T(INFO, 1) << "Test" << 123; }, EQUAL, STDOUT},
+  {"lpp_timed_glog_syntax_severity_info_Test","INFO  Test123\n",[]() { LOG_EVERY_T(INFO, 1) << "Test" << 123; }, EQUAL, STDOUT},
+  {"lpp_timed_glog_syntax_severity_warning_Test","WARN  Test123\n",[]() { LOG_EVERY_T(WARNING, 1) << "Test" << 123; }, EQUAL, STDOUT},
+  {"lpp_timed_glog_syntax_severity_error_Test","ERROR Test123\n",[]() { LOG_EVERY_T(ERROR, 1) << "Test" << 123; }, EQUAL, STDOUT},
+  {"lpp_timed_glog_syntax_severity_fatal_Test","FATAL Test123\n",[]() { LOG_EVERY_T(FATAL, 1) << "Test" << 123; }, EQUAL, STDOUT},
 
   {"lpp_timed_ros_syntax_severity_debug_Test", "DEBUG Test123\n", []() {ROS_DEBUG_THROTTLE(1, "Test123"); }, EQUAL, STDOUT},
   {"lpp_timed_ros_syntax_severity_debug_stream_Test", "DEBUG Test123\n", []() {ROS_DEBUG_STREAM_THROTTLE(1, "Test" << 123); }, EQUAL, STDOUT},

diff --git a/test/roslog/test_roslog_timed.cc b/test/roslog/test_roslog_timed.cc
@@ -0,0 +1,129 @@
+//
+// Created by 4c3y (acey) on 16.09.22.
+//
+
+#include <gtest/gtest.h>
+#include <log++.h>
+#include <mutex>
+#include <async_tests.h>
+
+using namespace lpp::rostest;
+
+std::vector<AsyncTest> generateTests() {
+  return {
+  {"roslog_timed_lpp_syntax_severity_debug_Test", debug,[]() { LOG_TIMED(D, 1, "Test" << 123); }, REMOVE_NUMBERS_FROM_STRING, STDOUT},
+  {"roslog_timed_lpp_syntax_severity_info_Test", info,[]() { LOG_TIMED(I, 1, "Test" << 123); }, REMOVE_NUMBERS_FROM_STRING, STDOUT},
+  {"roslog_timed_lpp_syntax_severity_warning_Test", warning,[]() { LOG_TIMED(W, 1, "Test" << 123); }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  {"roslog_timed_lpp_syntax_severity_error_Test",error,[]() { LOG_TIMED(E, 1, "Test" << 123); }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  {"roslog_timed_lpp_syntax_severity_fatal_Test",fatal,[]() { LOG_TIMED(F, 1, "Test" << 123); }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+
+  {"roslog_timed_glog_syntax_severity_debug_Test",debug,[]() { DLOG_EVERY_T(INFO, 1) << "Test" << 123; }, REMOVE_NUMBERS_FROM_STRING, STDOUT},
+  {"roslog_timed_glog_syntax_severity_info_Test", info,[]() { LOG_EVERY_T(INFO, 1) << "Test" << 123; }, REMOVE_NUMBERS_FROM_STRING, STDOUT},
+  {"roslog_timed_glog_syntax_severity_warning_Test", warning,[]() { LOG_EVERY_T(WARNING, 1) << "Test" << 123; }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  {"roslog_timed_glog_syntax_severity_error_Test",error,[]() { LOG_EVERY_T(ERROR, 1) << "Test" << 123; }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  {"roslog_timed_glog_syntax_severity_fatal_Test",fatal,[]() { LOG_EVERY_T(FATAL, 1) << "Test" << 123; }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+
+  {"roslog_timed_ros_syntax_severity_debug_Test", debug, []() {ROS_DEBUG_THROTTLE(1, "Test123"); }, REMOVE_NUMBERS_FROM_STRING, STDOUT},
+  {"roslog_timed_ros_syntax_severity_debug_stream_Test", debug, []() {ROS_DEBUG_STREAM_THROTTLE(1, "Test" << 123); }, REMOVE_NUMBERS_FROM_STRING, STDOUT},
+  {"roslog_timed_ros_syntax_severity_info_Test",  info, []() {ROS_INFO_THROTTLE(1, "Test123"); }, REMOVE_NUMBERS_FROM_STRING, STDOUT},
+  {"roslog_timed_ros_syntax_severity_info_stream_Test",  info, []() {ROS_INFO_STREAM_THROTTLE(1, "Test" << 123); }, REMOVE_NUMBERS_FROM_STRING, STDOUT},
+  {"roslog_timed_ros_syntax_severity_warning_Test", warning, []() {ROS_WARN_THROTTLE(1, "Test123"); }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  {"roslog_timed_ros_syntax_severity_warning_stream_Test", warning, []() {ROS_WARN_STREAM_THROTTLE(1, "Test" << 123); }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  {"roslog_timed_ros_syntax_severity_error_Test", error, []() {ROS_ERROR_THROTTLE(1, "Test123"); }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  {"roslog_timed_ros_syntax_severity_error_stream_Test", error, []() {ROS_ERROR_STREAM_THROTTLE(1, "Test" << 123); }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  {"roslog_timed_ros_syntax_severity_fatal_Test", fatal, []() {ROS_FATAL_THROTTLE(1, "Test123"); }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  {"roslog_timed_ros_syntax_severity_fatal_stream_Test", fatal, []() {ROS_FATAL_STREAM_THROTTLE(1, "Test123"); }, REMOVE_NUMBERS_FROM_STRING, STDERR},
+  };
+}
+
+TEST(roslog_timed, lpp_syntax_floating_point_time) {
+  LOG_INIT(*test_argv);
+  for (int i = 0; i < 5; i++) {
+    std::string output = LPP_CAPTURE_STDOUT(LOG_TIMED(I, 0.1, "Test" << 123));
+    if (i % 2 == 0) {
+      ASSERT_EQ(removeNumbersFromString(output),  info);
+    }
+    //sleep 0.1s
+    std::this_thread::sleep_for(std::chrono::milliseconds(50));
+  }
+}
+
+TEST(roslog_timed, lpp_syntax_severity_debug) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, lpp_syntax_severity_info) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, lpp_syntax_severity_warning) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, lpp_syntax_severity_error) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, lpp_syntax_severity_fatal) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, glog_syntax_severity_debug) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, glog_syntax_severity_info) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, glog_syntax_severity_warning) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, glog_syntax_severity_error) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, glog_syntax_severity_fatal) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_debug) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_debug_stream) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_info) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_info_stream) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_warning) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_warning_stream) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_error) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_error_stream) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_fatal) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}
+
+TEST(roslog_timed, ros_syntax_severity_fatal_stream) {
+  ASSERT_TRUE(TestResult::getInstance().get(GET_CLASS_NAME(*this, nullptr)));
+}