ros2GH-65 Introduce and use better logging macros

rosbag2/CMakeLists.txt

@@ -119,6 +119,11 @@ if(BUILD_TESTING)
     src/rosbag2/typesupport_helpers.cpp
     WORKING_DIRECTORY ${CMAKE_CURRENT_BINARY_DIR})
   if(TARGET rosbag2_rosbag_node_test)
+    target_include_directories(rosbag2_rosbag_node_test
+      PUBLIC
+      $<BUILD_INTERFACE:${CMAKE_CURRENT_SOURCE_DIR}/include>
+      $<INSTALL_INTERFACE:include>
+    )
     ament_target_dependencies(rosbag2_rosbag_node_test
       ament_index_cpp
       Poco

rosbag2/include/rosbag2/logging.hpp

@@ -0,0 +1,61 @@
+// Copyright 2018, Bosch Software Innovations GmbH.
+//
+// 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.
+
+#ifndef ROSBAG2__LOGGING_HPP_
+#define ROSBAG2__LOGGING_HPP_
+
+#include <sstream>
+#include <string>
+
+#include "rcutils/logging_macros.h"
+
+#define ROSBAG2_PACKAGE_NAME "rosbag2"
+
+#define ROSBAG2_LOG_INFO(...) \
+  RCUTILS_LOG_INFO_NAMED(ROSBAG2_PACKAGE_NAME, __VA_ARGS__)
+
+#define ROSBAG2_LOG_INFO_STREAM(args) do { \
+    std::stringstream __ss; \
+    __ss << args; \
+    RCUTILS_LOG_INFO_NAMED(ROSBAG2_PACKAGE_NAME, __ss.str().c_str()); \
+} while (0)
+
+#define ROSBAG2_LOG_ERROR(...) \
+  RCUTILS_LOG_ERROR_NAMED(ROSBAG2_PACKAGE_NAME, __VA_ARGS__)
+
+#define ROSBAG2_LOG_ERROR_STREAM(args) do { \
+    std::stringstream __ss; \
+    __ss << args; \
+    RCUTILS_LOG_ERROR_NAMED(ROSBAG2_PACKAGE_NAME, __ss.str().c_str()); \
+} while (0)
+
+#define ROSBAG2_LOG_WARN(...) \
+  RCUTILS_LOG_WARN_NAMED(ROSBAG2_PACKAGE_NAME, __VA_ARGS__)
+
+#define ROSBAG2_LOG_WARN_STREAM(args) do { \
+    std::stringstream __ss; \
+    __ss << args; \
+    RCUTILS_LOG_WARN_NAMED(ROSBAG2_PACKAGE_NAME, __ss.str().c_str()); \
+} while (0)
+
+#define ROSBAG2_LOG_DEBUG(...) \
+  RCUTILS_LOG_DEBUG_NAMED(ROSBAG2_PACKAGE_NAME, __VA_ARGS__)
+
+#define ROSBAG2_LOG_DEBUG_STREAM(args) do { \
+    std::stringstream __ss; \
+    __ss << args; \
+    RCUTILS_LOG_DEBUG_NAMED(ROSBAG2_PACKAGE_NAME, __ss.str().c_str()); \
+} while (0)
+
+#endif  // ROSBAG2__LOGGING_HPP_

rosbag2/src/rosbag2/generic_subscription.cpp

@@ -20,6 +20,8 @@
 #include "rclcpp/any_subscription_callback.hpp"
 #include "rclcpp/subscription.hpp"
 
+#include "rosbag2/logging.hpp"
+
 namespace rosbag2
 {
 
@@ -98,9 +100,8 @@ GenericSubscription::borrow_serialized_message(size_t capacity)
         auto fini_return = rmw_serialized_message_fini(msg);
         delete msg;
         if (fini_return != RCL_RET_OK) {
-          RCUTILS_LOG_ERROR_NAMED(
-            "rosbag2",
-            "failed to destroy serialized message: %s", rcl_get_error_string_safe());
+          ROSBAG2_LOG_ERROR_STREAM(
+            "Failed to destroy serialized message: " << rcl_get_error_string_safe());
         }
       });
 

rosbag2/src/rosbag2/rosbag2.cpp

@@ -24,6 +24,7 @@
 #include "rclcpp/rclcpp.hpp"
 #include "rcutils/logging_macros.h"
 
+#include "rosbag2/logging.hpp"
 #include "rosbag2_storage/serialized_bag_message.hpp"
 #include "rosbag2_storage/storage_factory.hpp"
 #include "rosbag2_storage/storage_interfaces/read_only_interface.hpp"
@@ -50,7 +51,6 @@ void Rosbag2::record(
 
   if (!storage) {
     throw std::runtime_error("No storage could be initialized. Abort");
-    return;
   }
 
   auto node = std::make_shared<Rosbag2Node>("rosbag2");
@@ -79,10 +79,9 @@ void Rosbag2::record(
 
   if (subscriptions_.empty()) {
     throw std::runtime_error("No topics could be subscribed. Abort");
-    return;
   }
 
-  RCUTILS_LOG_INFO_NAMED(ROS_PACKAGE_NAME, "Waiting for messages...");
+  ROSBAG2_LOG_INFO("Waiting for messages...");
   while (rclcpp::ok()) {
     rclcpp::spin(node);
   }
@@ -106,9 +105,8 @@ Rosbag2::create_subscription(
       rcutils_time_point_value_t time_stamp;
       int error = rcutils_system_time_now(&time_stamp);
       if (error != RCUTILS_RET_OK) {
-        RCUTILS_LOG_ERROR_NAMED(
-          ROS_PACKAGE_NAME,
-          "Error getting current time. Error: %s", rcutils_get_error_string_safe());
+        ROSBAG2_LOG_ERROR_STREAM(
+          "Error getting current time. Error:" << rcutils_get_error_string_safe());
       }
       bag_message->time_stamp = time_stamp;
 
@@ -134,7 +132,7 @@ void Rosbag2::play(const std::string & file_name)
       // without the sleep_for() many messages are lost.
       std::this_thread::sleep_for(std::chrono::milliseconds(50));
       publishers_[message->topic_name]->publish(message->serialized_data);
-      RCUTILS_LOG_INFO_NAMED(ROS_PACKAGE_NAME, "published message");
+      ROSBAG2_LOG_INFO("Published message");
     }
   }
 }

rosbag2/src/rosbag2/rosbag2_node.cpp

@@ -21,6 +21,7 @@
 #include <vector>
 #include <utility>
 
+#include "rosbag2/logging.hpp"
 #include "typesupport_helpers.hpp"
 
 namespace rosbag2
@@ -55,8 +56,7 @@ std::shared_ptr<GenericSubscription> Rosbag2Node::create_generic_subscription(
 
     get_node_topics_interface()->add_subscription(subscription, nullptr);
   } catch (const std::runtime_error & ex) {
-    RCUTILS_LOG_ERROR_NAMED(
-      "rosbag2", "Error subscribing to topic %s. Error: %s", topic.c_str(), ex.what());
+    ROSBAG2_LOG_ERROR_STREAM("Error subscribing to topic '" << topic << "'. Error: " << ex.what());
   }
 
   return subscription;
@@ -104,10 +104,8 @@ std::map<std::string, std::string> Rosbag2Node::sanitize_topics_and_types(
     std::inserter(filtered_topics_and_types, filtered_topics_and_types.end()),
     [](auto element) {
       if (element.second.size() > 1) {
-        RCUTILS_LOG_ERROR_NAMED(
-          "rosbag2",
-          "Topic '%s' has several types associated. Only topics with one type are supported.",
-          element.first.c_str());
+        ROSBAG2_LOG_ERROR_STREAM("Topic '" << element.first <<
+        "' has several types associated. Only topics with one type are supported");
         return true;
       } else {
         char type_separator = '/';
@@ -118,10 +116,8 @@ std::map<std::string, std::string> Rosbag2Node::sanitize_topics_and_types(
         sep_position_back == 0 ||
         sep_position_back == element.second[0].length() - 1)
         {
-          RCUTILS_LOG_ERROR_NAMED(
-            "rosbag2",
-            "Topic '%s' has non-ROS type %s . Only ROS topics are supported.",
-            element.first.c_str(), element.second[0].c_str());
+          ROSBAG2_LOG_ERROR_STREAM("Topic '" << element.first <<
+          "' has non-ROS type '" << element.second[0] << "'. Only ROS topics are supported.");
           return true;
         }
         return false;

rosbag2_storage/include/rosbag2_storage/logging.hpp

@@ -0,0 +1,61 @@
+// Copyright 2018, Bosch Software Innovations GmbH.
+//
+// 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.
+
+#ifndef ROSBAG2_STORAGE__LOGGING_HPP_
+#define ROSBAG2_STORAGE__LOGGING_HPP_
+
+#include <sstream>
+#include <string>
+
+#include "rcutils/logging_macros.h"
+
+#define ROSBAG2_STORAGE_PACKAGE_NAME "rosbag2_storage"
+
+#define ROSBAG2_STORAGE_LOG_INFO(...) \
+  RCUTILS_LOG_INFO_NAMED(ROSBAG2_STORAGE_PACKAGE_NAME, __VA_ARGS__)
+
+#define ROSBAG2_STORAGE_LOG_INFO_STREAM(args) do { \
+    std::stringstream __ss; \
+    __ss << args; \
+    RCUTILS_LOG_INFO_NAMED(ROSBAG2_STORAGE_PACKAGE_NAME, __ss.str().c_str()); \
+} while (0)
+
+#define ROSBAG2_STORAGE_LOG_ERROR(...) \
+  RCUTILS_LOG_ERROR_NAMED(ROSBAG2_STORAGE_PACKAGE_NAME, __VA_ARGS__)
+
+#define ROSBAG2_STORAGE_LOG_ERROR_STREAM(args) do { \
+    std::stringstream __ss; \
+    __ss << args; \
+    RCUTILS_LOG_ERROR_NAMED(ROSBAG2_STORAGE_PACKAGE_NAME, __ss.str().c_str()); \
+} while (0)
+
+#define ROSBAG2_STORAGE_LOG_WARN(...) \
+  RCUTILS_LOG_WARN_NAMED(ROSBAG2_STORAGE_PACKAGE_NAME, __VA_ARGS__)
+
+#define ROSBAG2_STORAGE_LOG_WARN_STREAM(args) do { \
+    std::stringstream __ss; \
+    __ss << args; \
+    RCUTILS_LOG_WARN_NAMED(ROSBAG2_STORAGE_PACKAGE_NAME, __ss.str().c_str()); \
+} while (0)
+
+#define ROSBAG2_STORAGE_LOG_DEBUG(...) \
+  RCUTILS_LOG_DEBUG_NAMED(ROSBAG2_STORAGE_PACKAGE_NAME, __VA_ARGS__)
+
+#define ROSBAG2_STORAGE_LOG_DEBUG_STREAM(args) do { \
+    std::stringstream __ss; \
+    __ss << args; \
+    RCUTILS_LOG_DEBUG_NAMED(ROSBAG2_STORAGE_PACKAGE_NAME, __ss.str().c_str()); \
+} while (0)
+
+#endif  // ROSBAG2_STORAGE__LOGGING_HPP_

rosbag2_storage/src/impl/storage_factory_impl.hpp

@@ -22,19 +22,17 @@
 #include <vector>
 
 #include "pluginlib/class_loader.hpp"
-#include "rcutils/logging_macros.h"
 
 #include "rosbag2_storage/storage_interfaces/read_only_interface.hpp"
 #include "rosbag2_storage/storage_interfaces/read_write_interface.hpp"
 
 #include "rosbag2_storage/storage_factory.hpp"
 #include "rosbag2_storage/storage_traits.hpp"
+#include "rosbag2_storage/logging.hpp"
 
 namespace rosbag2_storage
 {
 
-constexpr const char * ROS_PACKAGE_NAME = "rosbag2_storage";
-
 using storage_interfaces::ReadOnlyInterface;
 using storage_interfaces::ReadWriteInterface;
 
@@ -43,7 +41,7 @@ std::shared_ptr<pluginlib::ClassLoader<InterfaceT>>
 get_class_loader()
 {
   const char * lookup_name = StorageTraits<InterfaceT>::name;
-  return std::make_shared<pluginlib::ClassLoader<InterfaceT>>(ROS_PACKAGE_NAME, lookup_name);
+  return std::make_shared<pluginlib::ClassLoader<InterfaceT>>("rosbag2_storage", lookup_name);
 }
 
 template<
@@ -59,8 +57,7 @@ get_interface_instance(
   const auto & registered_classes = class_loader->getDeclaredClasses();
   auto class_exists = std::find(registered_classes.begin(), registered_classes.end(), storage_id);
   if (class_exists == registered_classes.end()) {
-    RCUTILS_LOG_DEBUG_NAMED(ROS_PACKAGE_NAME,
-      "Requested storage id %s does not exist", storage_id.c_str());
+    ROSBAG2_STORAGE_LOG_DEBUG_STREAM("Requested storage id '" << storage_id << "' does not exist");
     return nullptr;
   }
 
@@ -69,17 +66,17 @@ get_interface_instance(
     auto unmanaged_instance = class_loader->createUnmanagedInstance(storage_id);
     instance = std::shared_ptr<InterfaceT>(unmanaged_instance);
   } catch (const std::runtime_error & ex) {
-    RCUTILS_LOG_ERROR_NAMED(ROS_PACKAGE_NAME,
-      "unable to load instance of read write interface: %s", ex.what());
+    ROSBAG2_STORAGE_LOG_ERROR_STREAM(
+      "Unable to load instance of read write interface: " << ex.what());
     return nullptr;
   }
 
   try {
     instance->open(uri, flag);
     return instance;
   } catch (const std::runtime_error & ex) {
-    RCUTILS_LOG_ERROR_NAMED(ROS_PACKAGE_NAME,
-      "Could not open '%s' with %s. Error: %s", uri.c_str(), storage_id.c_str(), ex.what());
+    ROSBAG2_STORAGE_LOG_ERROR_STREAM(
+      "Could not open '" << uri << "' with '" << storage_id << "'. Error: " << ex.what());
     return nullptr;
   }
 }
@@ -92,16 +89,14 @@ class StorageFactoryImpl
     try {
       read_write_class_loader_ = get_class_loader<ReadWriteInterface>();
     } catch (const std::exception & e) {
-      RCUTILS_LOG_ERROR_NAMED(
-        ROS_PACKAGE_NAME, "unable to create class load instance: %s", e.what());
+      ROSBAG2_STORAGE_LOG_ERROR_STREAM("Unable to create class load instance: " << e.what());
       throw e;
     }
 
     try {
       read_only_class_loader_ = get_class_loader<ReadOnlyInterface>();
     } catch (const std::exception & e) {
-      RCUTILS_LOG_ERROR_NAMED(
-        ROS_PACKAGE_NAME, "unable to create class load instance: %s", e.what());
+      ROSBAG2_STORAGE_LOG_ERROR_STREAM("Unable to create class load instance: " << e.what());
       throw e;
     }
   }
@@ -113,8 +108,8 @@ class StorageFactoryImpl
   {
     auto instance = get_interface_instance(read_write_class_loader_, storage_id, uri);
 
-    RCUTILS_LOG_ERROR_NAMED(
-      ROS_PACKAGE_NAME, "Could not load/open plugin with storage id '%s'", storage_id.c_str())
+    ROSBAG2_STORAGE_LOG_ERROR_STREAM(
+      "Could not load/open plugin with storage id '" << storage_id << "'.");
 
     return instance;
   }
@@ -130,8 +125,8 @@ class StorageFactoryImpl
         read_write_class_loader_, storage_id, uri);
     }
 
-    RCUTILS_LOG_ERROR_NAMED(
-      ROS_PACKAGE_NAME, "Could not load/open plugin with storage id '%s'", storage_id.c_str())
+    ROSBAG2_STORAGE_LOG_ERROR_STREAM(
+      "Could not load/open plugin with storage id '" << storage_id << "'.");
 
     return instance;
   }

rosbag2_storage/src/rosbag2_storage/ros_helper.cpp

@@ -17,8 +17,8 @@
 #include <memory>
 #include <string>
 
-#include "rcutils/logging_macros.h"
 #include "rcutils/types.h"
+#include "rosbag2_storage/logging.hpp"
 
 namespace rosbag2_storage
 {
@@ -41,9 +41,8 @@ make_serialized_message(const void * data, size_t size)
         int error = rcutils_char_array_fini(msg);
         delete msg;
         if (error != RCUTILS_RET_OK) {
-          RCUTILS_LOG_ERROR_NAMED(
-            "rosbag2_storage",
-            "Leaking memory. Error: %s", rcutils_get_error_string_safe());
+          ROSBAG2_STORAGE_LOG_ERROR_STREAM(
+            "Leaking memory. Error: " << rcutils_get_error_string_safe());
         }
       });