Add demo for logging + logger config

logging_demo/CMakeLists.txt

@@ -0,0 +1,121 @@
+cmake_minimum_required(VERSION 3.5)
+
+project(logging_demo)
+
+# Default to C++14
+if(NOT CMAKE_CXX_STANDARD)
+  set(CMAKE_CXX_STANDARD 14)
+endif()
+
+if(CMAKE_COMPILER_IS_GNUCXX OR CMAKE_CXX_COMPILER_ID MATCHES "Clang")
+  # we dont use add_compile_options with pedantic in packages generating python
+  # messages because the Python C extensions dont comply with it
+  # pedantic is not possible here also because of class_loader macros
+  add_compile_options(-Wall -Wextra)
+endif()
+
+find_package(ament_cmake REQUIRED)
+find_package(ament_index_cpp REQUIRED)
+find_package(class_loader REQUIRED)
+find_package(rclcpp REQUIRED)
+find_package(rcutils REQUIRED)
+find_package(std_msgs REQUIRED)
+
+find_package(rosidl_default_generators REQUIRED)
+rosidl_generate_interfaces(${PROJECT_NAME}
+  "srv/ConfigLogger.srv"
+)
+
+include_directories(include)
+
+add_library(logger_config_component SHARED
+  src/logger_config_component.cpp)
+target_compile_definitions(logger_config_component
+  PRIVATE "LOGGING_DEMO_BUILDING_DLL")
+ament_target_dependencies(logger_config_component
+  "class_loader"
+  "rclcpp")
+rosidl_target_interfaces(logger_config_component
+  ${PROJECT_NAME} "rosidl_typesupport_cpp")
+rclcpp_register_node_plugins(logger_config_component "logging_demo::LoggerConfig")
+
+add_library(logger_usage_component SHARED
+  src/logger_usage_component.cpp)
+target_compile_definitions(logger_usage_component
+  PRIVATE "LOGGING_DEMO_BUILDING_DLL")
+ament_target_dependencies(logger_usage_component
+  "class_loader"
+  "rclcpp"
+  "std_msgs")
+rclcpp_register_node_plugins(logger_usage_component "logging_demo::LoggerUsage")
+
+add_executable(logging_demo_main
+  src/logging_demo_main.cpp)
+target_link_libraries(logging_demo_main
+  logger_config_component
+  logger_usage_component)
+ament_target_dependencies(logging_demo_main
+  "rclcpp")
+
+install(TARGETS
+  logger_config_component
+  logger_usage_component
+  ARCHIVE DESTINATION lib
+  LIBRARY DESTINATION lib
+  RUNTIME DESTINATION bin)
+
+install(TARGETS
+  logging_demo_main
+  DESTINATION lib/${PROJECT_NAME})
+
+if(BUILD_TESTING)
+  find_package(ament_lint_auto REQUIRED)
+  ament_lint_auto_find_test_dependencies()
+
+  find_package(ament_cmake_pytest REQUIRED)
+  find_package(rmw_implementation_cmake REQUIRED)
+
+  set(generated_python_files)
+  macro(tests)
+    set(LOGGING_DEMO_MAIN_EXECUTABLE $<TARGET_FILE:logging_demo_main>)
+    set(
+      EXPECTED_OUTPUT_LOGGING_DEMO_MAIN_DEFAULT_SEVERITY
+      "${CMAKE_CURRENT_SOURCE_DIR}/test/logging_demo_main_default_severity")
+    set(
+      EXPECTED_OUTPUT_LOGGING_DEMO_MAIN_DEBUG_SEVERITY
+      "${CMAKE_CURRENT_SOURCE_DIR}/test/logging_demo_main_debug_severity")
+
+    configure_file(
+      test/test_logging_demo.py.in
+      test_logging_demo${target_suffix}.py.genexp
+      @ONLY
+    )
+    file(GENERATE
+      OUTPUT test_logging_demo${target_suffix}_$<CONFIG>.py
+      INPUT test_logging_demo${target_suffix}.py.genexp)
+    ament_add_pytest_test(test_logging_demo${target_suffix}
+      "${CMAKE_CURRENT_BINARY_DIR}/test_logging_demo${target_suffix}_$<CONFIG>.py"
+      ENV RMW_IMPLEMENTATION=${rmw_implementation}
+      APPEND_LIBRARY_DIRS "${append_library_dirs}"
+      TIMEOUT 20)
+    list(
+      APPEND generated_python_files
+      "${CMAKE_CURRENT_BINARY_DIR}/test_logging_demo${target_suffix}_$<CONFIG>.py")
+  endmacro()
+
+  set(append_library_dirs "${CMAKE_CURRENT_BINARY_DIR}")
+  if(WIN32)
+    set(append_library_dirs "${append_library_dirs}/$<CONFIG>")
+  endif()
+
+  call_for_each_rmw_implementation(tests)
+
+  find_package(ament_cmake_flake8 REQUIRED)
+  ament_flake8(
+    TESTNAME "flake8_generated_launch"
+    # the generated code might contain longer lines if from a template
+    MAX_LINE_LENGTH 999
+    ${generated_python_files})
+endif()
+
+ament_package()

logging_demo/README.md

@@ -0,0 +1,75 @@
+# Logging and logger configuration
+
+See [the logging page]() for details on available functionality.
+
+In this demo, different types of log calls are shown and the severity level of different loggers is configured locally and externally.
+
+Start the demo with:
+```
+ros2 run logging_demo logging_demo_main
+```
+
+Over time you will see output from various log calls with different properties.
+To start with you will only see output from log calls with severity `INFO` and above (`WARN`, `ERROR`, `FATAL`).
+Note that the first message will only be logged once as that is a property of the log call used for that message.
+
+### Logger level configuration: locally
+
+After 10 iterations the severity threshold of the logger will be set to `DEBUG`, which will cause additional messages to be logged.
+
+Some of these debug messages cause additional functions/expressions to be evaluated, which were previously skipped as `DEBUG` log calls were not enabled.
+See [the source code]() of the demo for further explanation of the calls used, and see the [`rclcpp` logging documentation]() for a full list of supported logging calls.
+
+### Logger level configuration: externally
+
+In the future there will be a generalized approach to external configuration of loggers at runtime (similar to how [`rqt_logger_level`](http://wiki.ros.org/rqt_logger_level) in ROS 1 allows logger configuration via remote procedural calls).
+**This concept is not yet officially supported in ROS 2.** In the meantime, this demo provides an **example** service that can be called externally to request configuration of logger levels for known names of loggers in the process.
+
+The demo previously started is already running this example service.
+To set the severity threshold of the demo's logger back to `INFO`, call the service with:
+
+```
+ros2 service call /config_logger logging_demo/ConfigLogger "{logger_name: 'logger_usage_demo', severity_threshold: INFO}"
+```
+
+This service call will work on any logger that is running in the process provided that you know its name.
+This includes the loggers in the ROS 2 core, such as `rcl` (the common client library package).
+To enable debug logging for `rcl`, call:
+
+```
+ros2 service call /config_logger logging_demo/ConfigLogger "{logger_name: 'rcl', severity_threshold: DEBUG}"
+```
+
+You should see debug output from `rcl` start to show.
+
+#### Using the logger config component
+
+The server that responds to the logger configuration requests has been developed as a component so that it may be added to an existing composition-based system.
+For example, if you are using [a container to run your nodes](https://github.com/ros2/ros2/wiki/Composition#using-components), to be able to configure your loggers you only need to request that it additionally load the `logging_demo::LoggerConfig` component into the container.
+
+As an example, if you want to debug the `composition::Talker` demo, you can start the talker as normal with:
+
+Shell 1:
+```
+ros2 run composition api_composition
+```
+Shell 2:
+```
+ros2 run composition api_composition_cli composition composition::Talker
+```
+
+And then when you want to enable debug logging, load the `LoggerConfig` component with:
+
+Shell 2
+```
+ros2 run composition api_composition_cli logging_demo logging_demo::LoggerConfig
+```
+
+And finally, configure all unset loggers to the debug severity by addressing the empty-named logger.
+Note that loggers that have been specifically configured to use a particular severity will not be affected by this call.
+
+Shell 2:
+```
+ros2 service call /config_logger logging_demo/ConfigLogger "{logger_name: '', severity_threshold: DEBUG}"
+```
+You should see debug output from any previously unset loggers in the process start to appear, including from the ROS 2 core.

logging_demo/include/logging_demo/logger_config_component.hpp

@@ -0,0 +1,37 @@
+// 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 LOGGING_DEMO__LOGGER_CONFIG_COMPONENT_HPP_
+#define LOGGING_DEMO__LOGGER_CONFIG_COMPONENT_HPP_
+
+#include "logging_demo/srv/config_logger.hpp"
+#include "logging_demo/visibility_control.h"
+#include "rclcpp/rclcpp.hpp"
+
+namespace logging_demo
+{
+
+class LoggerConfig : public rclcpp::Node
+{
+public:
+  LOGGING_DEMO_PUBLIC
+  LoggerConfig();
+
+private:
+  rclcpp::service::Service<logging_demo::srv::ConfigLogger>::SharedPtr srv_;
+};
+
+}  // namespace logging_demo
+
+#endif  // LOGGING_DEMO__LOGGER_CONFIG_COMPONENT_HPP_

logging_demo/include/logging_demo/logger_usage_component.hpp

@@ -0,0 +1,46 @@
+// 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 LOGGING_DEMO__LOGGER_USAGE_COMPONENT_HPP_
+#define LOGGING_DEMO__LOGGER_USAGE_COMPONENT_HPP_
+
+#include <string>
+
+#include "logging_demo/visibility_control.h"
+#include "rclcpp/rclcpp.hpp"
+#include "std_msgs/msg/string.hpp"
+
+namespace logging_demo
+{
+
+class LoggerUsage : public rclcpp::Node
+{
+public:
+  LOGGING_DEMO_PUBLIC
+  LoggerUsage();
+
+protected:
+  void on_timer();
+
+private:
+  size_t count_;
+  rclcpp::Publisher<std_msgs::msg::String>::SharedPtr pub_;
+  rclcpp::timer::TimerBase::SharedPtr one_shot_timer_, timer_;
+  std::function<bool()> debug_function_to_evaluate_;
+};
+
+bool is_divisor_of_twelve(size_t val, std::string logger_name);
+}  // namespace logging_demo
+
+#endif  // LOGGING_DEMO__LOGGER_USAGE_COMPONENT_HPP_

logging_demo/include/logging_demo/visibility_control.h

@@ -0,0 +1,58 @@
+// Copyright 2016 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 LOGGING_DEMO__VISIBILITY_CONTROL_H_
+#define LOGGING_DEMO__VISIBILITY_CONTROL_H_
+
+#if __cplusplus
+extern "C"
+{
+#endif
+
+// This logic was borrowed (then namespaced) from the examples on the gcc wiki:
+//     https://gcc.gnu.org/wiki/Visibility
+
+#if defined _WIN32 || defined __CYGWIN__
+  #ifdef __GNUC__
+    #define LOGGING_DEMO_EXPORT __attribute__ ((dllexport))
+    #define LOGGING_DEMO_IMPORT __attribute__ ((dllimport))
+  #else
+    #define LOGGING_DEMO_EXPORT __declspec(dllexport)
+    #define LOGGING_DEMO_IMPORT __declspec(dllimport)
+  #endif
+  #ifdef LOGGING_DEMO_BUILDING_DLL
+    #define LOGGING_DEMO_PUBLIC LOGGING_DEMO_EXPORT
+  #else
+    #define LOGGING_DEMO_PUBLIC LOGGING_DEMO_IMPORT
+  #endif
+  #define LOGGING_DEMO_PUBLIC_TYPE LOGGING_DEMO_PUBLIC
+  #define LOGGING_DEMO_LOCAL
+#else
+  #define LOGGING_DEMO_EXPORT __attribute__ ((visibility("default")))
+  #define LOGGING_DEMO_IMPORT
+  #if __GNUC__ >= 4
+    #define LOGGING_DEMO_PUBLIC __attribute__ ((visibility("default")))
+    #define LOGGING_DEMO_LOCAL  __attribute__ ((visibility("hidden")))
+  #else
+    #define LOGGING_DEMO_PUBLIC
+    #define LOGGING_DEMO_LOCAL
+  #endif
+  #define LOGGING_DEMO_PUBLIC_TYPE
+#endif
+
+#if __cplusplus
+}
+#endif
+
+#endif  // LOGGING_DEMO__VISIBILITY_CONTROL_H_

logging_demo/logging_wiki.md

@@ -0,0 +1,41 @@
+# Logging and logger configuration
+
+The logging functionality currently supported is:
+- Client libraries (`rclcpp` and `rclpy `) using a common logging library to provide log calls with a variety of filters on hierarchical loggers.
+- Console output (file output and functionality akin to [`rosout`](http://wiki.ros.org/rosout) for remote consumption of messages is forthcoming).
+- Programmatic configuration of logger levels (config files and runtime configuration is forthcoming).
+
+## Logging usage
+
+<!-- the `rclcpp` documentation won't include logging until we make a new doc dump -->
+In C++:
+- See the [logging demo]() for example usage.
+- See the [`rclcpp` documentation]() for an extensive list of functionality.
+
+In Python:
+- See the [`rclpy` tests](https://github.com/ros2/rclpy/blob/master/rclpy/test/test_logging.py) for example usage.
+
+## Logger configuration
+
+Logger configuration is still under development.
+For now, the severity of individual loggers can be configured programmatically with, e.g.:
+
+In C++:
+```
+rcutils_logging_set_logger_severity_threshold("logger_name", RCUTILS_LOG_SEVERITY_DEBUG);
+```
+
+In Python:
+```
+rclpy.logging.set_logger_severity_threshold('logger_name', rclpy.logging.LoggingSeverity.DEBUG)
+```
+
+The [logging demo]() provides an example of manually exposing a service so that loggers can be configured externally; in the future we expect runtime configuration capabilities of loggers to be exposed automatically.
+
+## Console output configuration
+
+<!-- the rcutils docs won't mention this env var until we make a new doc dump -->
+By default, console output will be formatted to include the message severity, logger name, and the message.
+Information such as the file name, function name and line number of the log call are also available.
+Custom console output format can be configured with the `RCUTILS_CONSOLE_OUTPUT_FORMAT` environment variable: see the [`rcutils` documentation for details]().
+As `rclpy` and `rclcpp` both use `rcutils` for logging, this will effect all Python and C++ nodes.