diff --git a/rclcpp/CMakeLists.txt b/rclcpp/CMakeLists.txt index 5800113..7fb7fc9 100644 --- a/rclcpp/CMakeLists.txt +++ b/rclcpp/CMakeLists.txt @@ -64,6 +64,28 @@ set(${PROJECT_NAME}_SRCS src/rclcpp/utilities.cpp ) +# "watch" template for changes +configure_file( + "resource/logging.hpp.em" + "logging.hpp.em.watch" + COPYONLY +) +# generate header with logging macros +set(python_code + "import em" + "em.invoke(['-o', 'include/rclcpp/logging.hpp', '${CMAKE_CURRENT_SOURCE_DIR}/resource/logging.hpp.em'])") +string(REPLACE ";" "$" python_code "${python_code}") +add_custom_command(OUTPUT include/rclcpp/logging.hpp + COMMAND ${CMAKE_COMMAND} -E make_directory "include/rclcpp" + COMMAND ${PYTHON_EXECUTABLE} ARGS -c "${python_code}" + DEPENDS "${CMAKE_CURRENT_BINARY_DIR}/logging.hpp.em.watch" + COMMENT "Expanding logging.hpp.em" + VERBATIM +) +list(APPEND ${PROJECT_NAME}_SRCS + include/rclcpp/logging.hpp) +include_directories("${CMAKE_CURRENT_BINARY_DIR}/include") + add_library(${PROJECT_NAME} SHARED ${${PROJECT_NAME}_SRCS}) ament_target_dependencies(${PROJECT_NAME} @@ -251,6 +273,9 @@ if(BUILD_TESTING) "rcl") target_link_libraries(test_time ${PROJECT_NAME}) endif() + + ament_add_gmock(test_logging test/test_logging.cpp) + target_link_libraries(test_logging ${PROJECT_NAME}) endif() ament_package( @@ -263,6 +288,6 @@ install( ) install( - DIRECTORY include/ + DIRECTORY include/ ${CMAKE_CURRENT_BINARY_DIR}/include/ DESTINATION include ) diff --git a/rclcpp/Doxyfile b/rclcpp/Doxyfile index 5e9b9e6..2a7846b 100644 --- a/rclcpp/Doxyfile +++ b/rclcpp/Doxyfile @@ -4,7 +4,12 @@ PROJECT_NAME = "rclcpp" PROJECT_NUMBER = master PROJECT_BRIEF = "C++ ROS Client Library API" +# Use these lines to include the generated logging.hpp (update install path if needed) +#INPUT = ../../../../install_isolated/rclcpp/include +#STRIP_FROM_PATH = /Users/william/ros2_ws/install_isolated/rclcpp/include +# Otherwise just generate for the local (non-generated header files) INPUT = ./include + RECURSIVE = YES OUTPUT_DIRECTORY = doc_output diff --git a/rclcpp/include/rclcpp/macros.hpp b/rclcpp/include/rclcpp/macros.hpp index 1681037..f224abe 100644 --- a/rclcpp/include/rclcpp/macros.hpp +++ b/rclcpp/include/rclcpp/macros.hpp @@ -110,6 +110,4 @@ #define RCLCPP_STRING_JOIN(arg1, arg2) RCLCPP_DO_STRING_JOIN(arg1, arg2) #define RCLCPP_DO_STRING_JOIN(arg1, arg2) arg1 ## arg2 -#define RCLCPP_INFO(Args) std::cout << Args << std::endl; - #endif // RCLCPP__MACROS_HPP_ diff --git a/rclcpp/include/rclcpp/rclcpp.hpp b/rclcpp/include/rclcpp/rclcpp.hpp index 5d2d146..4374b2f 100644 --- a/rclcpp/include/rclcpp/rclcpp.hpp +++ b/rclcpp/include/rclcpp/rclcpp.hpp @@ -110,6 +110,13 @@ * - rclcpp::context::Context * - rclcpp/context.hpp * - rclcpp/contexts/default_context.hpp + * - Logging macros: + * - Some examples (not exhaustive): + * - RCLCPP_DEBUG() + * - RCLCPP_INFO() + * - RCLCPP_WARN_ONCE() + * - RCLCPP_ERROR_SKIPFIRST() + * - rclcpp/logging.hpp * - Various utilities: * - rclcpp/function_traits.hpp * - rclcpp/macros.hpp @@ -126,6 +133,7 @@ #include #include "rclcpp/executors.hpp" +#include "rclcpp/logging.hpp" #include "rclcpp/node.hpp" #include "rclcpp/parameter.hpp" #include "rclcpp/parameter_client.hpp" diff --git a/rclcpp/package.xml b/rclcpp/package.xml index 9641983..d22a4fd 100644 --- a/rclcpp/package.xml +++ b/rclcpp/package.xml @@ -27,6 +27,7 @@ ament_cmake + ament_cmake_gmock ament_cmake_gtest ament_lint_auto ament_lint_common diff --git a/rclcpp/resource/logging.hpp.em b/rclcpp/resource/logging.hpp.em new file mode 100644 index 0000000..badef9b --- /dev/null +++ b/rclcpp/resource/logging.hpp.em @@ -0,0 +1,101 @@ +// generated from rclcpp/resource/logging.hpp.em + +// Copyright 2017 Open Source Robotics Foundation, Inc. +// +// 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 RCLCPP__LOGGING_HPP_ +#define RCLCPP__LOGGING_HPP_ + +#include "rcutils/logging_macros.h" + +// These are used for compiling out logging macros lower than a minimum severity. +#define RCLCPP_LOG_MIN_SEVERITY_DEBUG 0 +#define RCLCPP_LOG_MIN_SEVERITY_INFO 1 +#define RCLCPP_LOG_MIN_SEVERITY_WARN 2 +#define RCLCPP_LOG_MIN_SEVERITY_ERROR 3 +#define RCLCPP_LOG_MIN_SEVERITY_FATAL 4 +#define RCLCPP_LOG_MIN_SEVERITY_NONE 5 + +/** + * \def RCLCPP_LOG_MIN_SEVERITY + * Define RCLCPP_LOG_MIN_SEVERITY=RCLCPP_LOG_MIN_SEVERITY_[DEBUG|INFO|WARN|ERROR|FATAL] + * in your build options to compile out anything below that severity. + * Use RCUTILS_LOG_MIN_SEVERITY_NONE to compile out all macros. + */ +#ifndef RCLCPP_LOG_MIN_SEVERITY +#define RCLCPP_LOG_MIN_SEVERITY RCLCPP_LOG_MIN_SEVERITY_DEBUG +#endif + + +@{ +from rcutils.logging import feature_combinations +from rcutils.logging import get_macro_parameters +from rcutils.logging import get_suffix_from_features +from rcutils.logging import severities + +# TODO(dhood): Implement the throttle macro using time sources available in rclcpp +excluded_features = ['named', 'throttle'] +def is_supported_feature_combination(feature_combination): + is_excluded = any([ef in feature_combination for ef in excluded_features]) + return not is_excluded +}@ +@[for severity in severities]@ +/** @@name Logging macros for severity @(severity). + */ +///@@{ +#if (RCLCPP_LOG_MIN_SEVERITY > RCLCPP_LOG_MIN_SEVERITY_@(severity)) +// empty logging macros for severity @(severity) when being disabled at compile time +@[ for feature_combination in [fc for fc in feature_combinations if is_supported_feature_combination(fc)]]@ +@{suffix = get_suffix_from_features(feature_combination)}@ +/// Empty logging macro due to the preprocessor definition of RCLCPP_LOG_MIN_SEVERITY. +#define RCLCPP_@(severity)@(suffix)(...) +@[ end for]@ + +#else +@[ for feature_combination in [fc for fc in feature_combinations if is_supported_feature_combination(fc)]]@ +@{suffix = get_suffix_from_features(feature_combination)}@ +/** + * \def RCLCPP_@(severity)@(suffix) + * Log a message with severity @(severity)@ +@[ if feature_combinations[feature_combination].doc_lines]@ + with the following conditions: +@[ else]@ +. +@[ end if]@ +@[ for doc_line in feature_combinations[feature_combination].doc_lines]@ + * @(doc_line) +@[ end for]@ + * \param name The name of the logger +@[ for param_name, doc_line in feature_combinations[feature_combination].params.items()]@ + * \param @(param_name) @(doc_line) +@[ end for]@ + * \param ... The format string, followed by the variable arguments for the format string + */ +// TODO(dhood): Replace the name argument with a logger object. +#define RCLCPP_@(severity)@(suffix)(name, @(''.join([p + ', ' for p in get_macro_parameters(feature_combination).keys()]))...) \ + RCUTILS_LOG_@(severity)@(suffix)_NAMED( \ +@{params = get_macro_parameters(feature_combination).keys()}@ +@[ if params]@ +@(''.join([' ' + p + ', \\\n' for p in params]))@ +@[ end if]@ + std::string(name).c_str(), \ + __VA_ARGS__) + +@[ end for]@ +#endif +///@@} + +@[end for]@ + +#endif // RCLCPP__LOGGING_HPP_ diff --git a/rclcpp/test/test_logging.cpp b/rclcpp/test/test_logging.cpp new file mode 100644 index 0000000..5f7f890 --- /dev/null +++ b/rclcpp/test/test_logging.cpp @@ -0,0 +1,158 @@ +// Copyright 2017 Open Source Robotics Foundation, Inc. +// +// 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. + +#include + +#include +#include +#include +#include + +#include "rclcpp/logging.hpp" +#include "rcutils/logging.h" +#include "rcutils/time.h" + +#define RCLCPP_TEST_LOGGING_MACRO_NAME "name" // Used in testing below + +using ::testing::EndsWith; + +size_t g_log_calls = 0; + +struct LogEvent +{ + rcutils_log_location_t * location; + int level; + std::string name; + std::string message; +}; +LogEvent g_last_log_event; + +class TestLoggingMacros : public ::testing::Test +{ +public: + rcutils_logging_output_handler_t previous_output_handler; + void SetUp() + { + g_log_calls = 0; + ASSERT_EQ(RCUTILS_RET_OK, rcutils_logging_initialize()); + rcutils_logging_set_default_severity_threshold(RCUTILS_LOG_SEVERITY_DEBUG); + + auto rcutils_logging_console_output_handler = []( + rcutils_log_location_t * location, + int level, const char * name, const char * format, va_list * args) -> void + { + g_log_calls += 1; + g_last_log_event.location = location; + g_last_log_event.level = level; + g_last_log_event.name = name ? name : ""; + char buffer[1024]; + vsnprintf(buffer, sizeof(buffer), format, *args); + g_last_log_event.message = buffer; + }; + + this->previous_output_handler = rcutils_logging_get_output_handler(); + rcutils_logging_set_output_handler(rcutils_logging_console_output_handler); + } + + void TearDown() + { + rcutils_logging_set_output_handler(this->previous_output_handler); + g_rcutils_logging_initialized = false; + EXPECT_FALSE(g_rcutils_logging_initialized); + } +}; + +TEST_F(TestLoggingMacros, test_logging_named) { + for (int i : {1, 2, 3}) { + RCLCPP_DEBUG("name", "message %d", i); + } + EXPECT_EQ(3u, g_log_calls); + EXPECT_TRUE(g_last_log_event.location != NULL); + if (g_last_log_event.location) { + EXPECT_STREQ("TestBody", g_last_log_event.location->function_name); + EXPECT_THAT(g_last_log_event.location->file_name, EndsWith("test_logging.cpp")); + EXPECT_EQ(78u, g_last_log_event.location->line_number); + } + EXPECT_EQ(RCUTILS_LOG_SEVERITY_DEBUG, g_last_log_event.level); + EXPECT_EQ("name", g_last_log_event.name); + EXPECT_EQ("message 3", g_last_log_event.message); + + // Test different name inputs + std::string std_string_name = "name"; + RCLCPP_DEBUG(std_string_name, "message"); + EXPECT_EQ("name", g_last_log_event.name); + + const char * c_string_name = "name"; + RCLCPP_DEBUG(c_string_name, "message"); + EXPECT_EQ("name", g_last_log_event.name); + + RCLCPP_DEBUG(std_string_name + c_string_name, "message"); + EXPECT_EQ("namename", g_last_log_event.name); + + RCLCPP_DEBUG(RCLCPP_TEST_LOGGING_MACRO_NAME, "message"); + EXPECT_EQ(RCLCPP_TEST_LOGGING_MACRO_NAME, g_last_log_event.name); + RCLCPP_DEBUG(std::string(RCLCPP_TEST_LOGGING_MACRO_NAME) + std_string_name, "message"); + EXPECT_EQ("namename", g_last_log_event.name); +} + +TEST_F(TestLoggingMacros, test_logging_once) { + for (int i : {1, 2, 3}) { + RCLCPP_INFO_ONCE("name", "message %d", i); + } + EXPECT_EQ(1u, g_log_calls); + EXPECT_EQ(RCUTILS_LOG_SEVERITY_INFO, g_last_log_event.level); + EXPECT_EQ("name", g_last_log_event.name); + EXPECT_EQ("message 1", g_last_log_event.message); + + // Check that another instance has a context that's independent to the call above's + g_log_calls = 0; + for (int i : {1, 2, 3}) { + RCLCPP_INFO_ONCE("name", "second message %d", i); + } + EXPECT_EQ(1u, g_log_calls); + EXPECT_EQ(RCUTILS_LOG_SEVERITY_INFO, g_last_log_event.level); + EXPECT_EQ("name", g_last_log_event.name); + EXPECT_EQ("second message 1", g_last_log_event.message); +} + +TEST_F(TestLoggingMacros, test_logging_expression) { + for (int i : {1, 2, 3, 4, 5, 6}) { + RCLCPP_INFO_EXPRESSION("name", i % 3, "message %d", i); + } + EXPECT_EQ(4u, g_log_calls); + EXPECT_EQ("message 5", g_last_log_event.message); +} + +int g_counter = 0; + +bool mod3() +{ + return (g_counter % 3) != 0; +} + +TEST_F(TestLoggingMacros, test_logging_function) { + for (int i : {1, 2, 3, 4, 5, 6}) { + g_counter = i; + RCLCPP_INFO_FUNCTION("name", &mod3, "message %d", i); + } + EXPECT_EQ(4u, g_log_calls); + EXPECT_EQ("message 5", g_last_log_event.message); +} + +TEST_F(TestLoggingMacros, test_logging_skipfirst) { + for (uint32_t i : {1, 2, 3, 4, 5}) { + RCLCPP_WARN_SKIPFIRST("name", "message %u", i); + EXPECT_EQ(i - 1, g_log_calls); + } +}