Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

add support for STREAM logging macros #926

Merged
merged 2 commits into from Nov 18, 2019
Merged

Conversation

@dirk-thomas
Copy link
Member

dirk-thomas commented Nov 15, 2019

Fixes #915. Requires ros2/rcutils#192.

The changes to the logging.hpp.em template only result in additional lines and don't change/remove any existing lines.

Since the STREAM macros only differ in the vargs / stream_arg handling the new test only covers one of the feature combinations.

The first commit is a pure refactoring without changing the expanded template. The second commit adds stream to the feature combinations.

The following details show the added lines for the DEBUG log level:

New empty STREAM macros for all existing feature combinations in case logging has been disabled.

/// Empty logging macro due to the preprocessor definition of RCLCPP_LOG_MIN_SEVERITY.
#define RCLCPP_DEBUG_STREAM(...)
/// Empty logging macro due to the preprocessor definition of RCLCPP_LOG_MIN_SEVERITY.
#define RCLCPP_DEBUG_STREAM_ONCE(...)
/// Empty logging macro due to the preprocessor definition of RCLCPP_LOG_MIN_SEVERITY.
#define RCLCPP_DEBUG_STREAM_EXPRESSION(...)
/// Empty logging macro due to the preprocessor definition of RCLCPP_LOG_MIN_SEVERITY.
#define RCLCPP_DEBUG_STREAM_FUNCTION(...)
/// Empty logging macro due to the preprocessor definition of RCLCPP_LOG_MIN_SEVERITY.
#define RCLCPP_DEBUG_STREAM_SKIPFIRST(...)
/// Empty logging macro due to the preprocessor definition of RCLCPP_LOG_MIN_SEVERITY.
#define RCLCPP_DEBUG_STREAM_THROTTLE(...)
/// Empty logging macro due to the preprocessor definition of RCLCPP_LOG_MIN_SEVERITY.
#define RCLCPP_DEBUG_STREAM_SKIPFIRST_THROTTLE(...)

New STREAM macros for all existing feature combinations.

// The RCLCPP_DEBUG_STREAM macro is surrounded by do { .. } while (0)
// to implement the standard C macro idiom to make the macro safe in all
// contexts; see http://c-faq.com/cpp/multistmt.html for more information.
/**

  • \def RCLCPP_DEBUG_STREAM
  • Log a message with severity DEBUG.
  • \param logger The rclcpp::Logger to use
  • \param stream_arg The argument << into a stringstream
    */
    #define RCLCPP_DEBUG_STREAM(logger, stream_arg)
    do {
    static_assert(
    ::std::is_same<typename std::remove_cv<typename std::remove_reference<decltype(logger)>::type>::type,
    typename ::rclcpp::Logger>::value,
    "First argument to logging macros must be an rclcpp::Logger");

    std::stringstream ss;
    ss << stream_arg;
    RCUTILS_LOG_DEBUG_NAMED(
    logger.get_name(),
    "%s", rclcpp::get_c_string(ss.str()));
    } while (0)

// The RCLCPP_DEBUG_STREAM_ONCE macro is surrounded by do { .. } while (0)
// to implement the standard C macro idiom to make the macro safe in all
// contexts; see http://c-faq.com/cpp/multistmt.html for more information.
/**

  • \def RCLCPP_DEBUG_STREAM_ONCE
  • Log a message with severity DEBUG with the following conditions:
  • All subsequent log calls except the first one are being ignored.
  • \param logger The rclcpp::Logger to use
  • \param stream_arg The argument << into a stringstream
    */
    #define RCLCPP_DEBUG_STREAM_ONCE(logger, stream_arg)
    do {
    static_assert(
    ::std::is_same<typename std::remove_cv<typename std::remove_reference<decltype(logger)>::type>::type,
    typename ::rclcpp::Logger>::value,
    "First argument to logging macros must be an rclcpp::Logger");

    std::stringstream ss;
    ss << stream_arg;
    RCUTILS_LOG_DEBUG_ONCE_NAMED(
    logger.get_name(),
    "%s", rclcpp::get_c_string(ss.str()));
    } while (0)

// The RCLCPP_DEBUG_STREAM_EXPRESSION macro is surrounded by do { .. } while (0)
// to implement the standard C macro idiom to make the macro safe in all
// contexts; see http://c-faq.com/cpp/multistmt.html for more information.
/**

  • \def RCLCPP_DEBUG_STREAM_EXPRESSION
  • Log a message with severity DEBUG with the following conditions:
  • Log calls are being ignored when the expression evaluates to false.
  • \param logger The rclcpp::Logger to use
  • \param expression The expression determining if the message should be logged
  • \param stream_arg The argument << into a stringstream
    */
    #define RCLCPP_DEBUG_STREAM_EXPRESSION(logger, expression, stream_arg)
    do {
    static_assert(
    ::std::is_same<typename std::remove_cv<typename std::remove_reference<decltype(logger)>::type>::type,
    typename ::rclcpp::Logger>::value,
    "First argument to logging macros must be an rclcpp::Logger");

    std::stringstream ss;
    ss << stream_arg;
    RCUTILS_LOG_DEBUG_EXPRESSION_NAMED(
    expression,
    logger.get_name(),
    "%s", rclcpp::get_c_string(ss.str()));
    } while (0)

// The RCLCPP_DEBUG_STREAM_FUNCTION macro is surrounded by do { .. } while (0)
// to implement the standard C macro idiom to make the macro safe in all
// contexts; see http://c-faq.com/cpp/multistmt.html for more information.
/**

  • \def RCLCPP_DEBUG_STREAM_FUNCTION
  • Log a message with severity DEBUG with the following conditions:
  • Log calls are being ignored when the function returns false.
  • \param logger The rclcpp::Logger to use
  • \param function The functions return value determines if the message should be logged
  • \param stream_arg The argument << into a stringstream
    */
    #define RCLCPP_DEBUG_STREAM_FUNCTION(logger, function, stream_arg)
    do {
    static_assert(
    ::std::is_same<typename std::remove_cv<typename std::remove_reference<decltype(logger)>::type>::type,
    typename ::rclcpp::Logger>::value,
    "First argument to logging macros must be an rclcpp::Logger");

    std::stringstream ss;
    ss << stream_arg;
    RCUTILS_LOG_DEBUG_FUNCTION_NAMED(
    function,
    logger.get_name(),
    "%s", rclcpp::get_c_string(ss.str()));
    } while (0)

// The RCLCPP_DEBUG_STREAM_SKIPFIRST macro is surrounded by do { .. } while (0)
// to implement the standard C macro idiom to make the macro safe in all
// contexts; see http://c-faq.com/cpp/multistmt.html for more information.
/**

  • \def RCLCPP_DEBUG_STREAM_SKIPFIRST
  • Log a message with severity DEBUG with the following conditions:
  • The first log call is being ignored but all subsequent calls are being processed.
  • \param logger The rclcpp::Logger to use
  • \param stream_arg The argument << into a stringstream
    */
    #define RCLCPP_DEBUG_STREAM_SKIPFIRST(logger, stream_arg)
    do {
    static_assert(
    ::std::is_same<typename std::remove_cv<typename std::remove_reference<decltype(logger)>::type>::type,
    typename ::rclcpp::Logger>::value,
    "First argument to logging macros must be an rclcpp::Logger");

    std::stringstream ss;
    ss << stream_arg;
    RCUTILS_LOG_DEBUG_SKIPFIRST_NAMED(
    logger.get_name(),
    "%s", rclcpp::get_c_string(ss.str()));
    } while (0)

// The RCLCPP_DEBUG_STREAM_THROTTLE macro is surrounded by do { .. } while (0)
// to implement the standard C macro idiom to make the macro safe in all
// contexts; see http://c-faq.com/cpp/multistmt.html for more information.
/**

  • \def RCLCPP_DEBUG_STREAM_THROTTLE
  • Log a message with severity DEBUG with the following conditions:
  • Log calls are being ignored if the last logged message is not longer ago than the specified duration.
  • \param logger The rclcpp::Logger to use
  • \param clock rclcpp::Clock that will be used to get the time point.
  • \param duration The duration of the throttle interval
  • \param stream_arg The argument << into a stringstream
    */
    #define RCLCPP_DEBUG_STREAM_THROTTLE(logger, clock, duration, stream_arg)
    do {
    static_assert(
    ::std::is_same<typename std::remove_cv<typename std::remove_reference<decltype(logger)>::type>::type,
    typename ::rclcpp::Logger>::value,
    "First argument to logging macros must be an rclcpp::Logger");

    auto get_time_point = [&clock](rcutils_time_point_value_t * time_point) -> rcutils_ret_t {
    try {
    *time_point = clock.now().nanoseconds();
    } catch (...) {
    RCUTILS_SAFE_FWRITE_TO_STDERR(
    "[rclcpp|logging.hpp] RCLCPP_DEBUG_STREAM_THROTTLE could not get current time stamp\n");
    return RCUTILS_RET_ERROR;
    }
    return RCUTILS_RET_OK;
    };

    std::stringstream ss;
    ss << stream_arg;
    RCUTILS_LOG_DEBUG_THROTTLE_NAMED(
    get_time_point,
    duration,
    logger.get_name(),
    "%s", rclcpp::get_c_string(ss.str()));
    } while (0)

// The RCLCPP_DEBUG_STREAM_SKIPFIRST_THROTTLE macro is surrounded by do { .. } while (0)
// to implement the standard C macro idiom to make the macro safe in all
// contexts; see http://c-faq.com/cpp/multistmt.html for more information.
/**

  • \def RCLCPP_DEBUG_STREAM_SKIPFIRST_THROTTLE
  • Log a message with severity DEBUG with the following conditions:
  • The first log call is being ignored but all subsequent calls are being processed.
  • Log calls are being ignored if the last logged message is not longer ago than the specified duration.
  • \param logger The rclcpp::Logger to use
  • \param clock rclcpp::Clock that will be used to get the time point.
  • \param duration The duration of the throttle interval
  • \param stream_arg The argument << into a stringstream
    */
    #define RCLCPP_DEBUG_STREAM_SKIPFIRST_THROTTLE(logger, clock, duration, stream_arg)
    do {
    static_assert(
    ::std::is_same<typename std::remove_cv<typename std::remove_reference<decltype(logger)>::type>::type,
    typename ::rclcpp::Logger>::value,
    "First argument to logging macros must be an rclcpp::Logger");

    auto get_time_point = [&clock](rcutils_time_point_value_t * time_point) -> rcutils_ret_t {
    try {
    *time_point = clock.now().nanoseconds();
    } catch (...) {
    RCUTILS_SAFE_FWRITE_TO_STDERR(
    "[rclcpp|logging.hpp] RCLCPP_DEBUG_STREAM_SKIPFIRST_THROTTLE could not get current time stamp\n");
    return RCUTILS_RET_ERROR;
    }
    return RCUTILS_RET_OK;
    };

    std::stringstream ss;
    ss << stream_arg;
    RCUTILS_LOG_DEBUG_SKIPFIRST_THROTTLE_NAMED(
    get_time_point,
    duration,
    logger.get_name(),
    "%s", rclcpp::get_c_string(ss.str()));
    } while (0)
  • Linux Build Status
  • Linux-aarch64 Build Status
  • macOS Build Status
  • Windows Build Status
    • unrelated linter failures
dirk-thomas added 2 commits Nov 15, 2019
Signed-off-by: Dirk Thomas <dirk-thomas@users.noreply.github.com>
Signed-off-by: Dirk Thomas <dirk-thomas@users.noreply.github.com>
@dirk-thomas dirk-thomas force-pushed the dirk-thomas/logging-streams branch from 970bbe9 to 12fe8ac Nov 15, 2019
@hidmic
hidmic approved these changes Nov 15, 2019
Copy link
Contributor

hidmic left a comment

LGTM pending green CI

@hidmic

This comment has been minimized.

Copy link
Contributor

hidmic commented Nov 15, 2019

Thinking out loud, it'd be nice if, instead, we could instantiate an std::basic_ostream that can then be used as an interface for logging. It's much harder to implement though.

@wjwwood wjwwood mentioned this pull request Nov 15, 2019
30 of 34 tasks complete
@mjcarroll mjcarroll merged commit 6963c2d into master Nov 18, 2019
1 of 2 checks passed
1 of 2 checks passed
Epr__rclcpp__ubuntu_bionic_amd64 Build finished.
Details
DCO DCO
Details
@wuffle-ros wuffle-ros bot removed the in review label Nov 18, 2019
@delete-merged-branch delete-merged-branch bot deleted the dirk-thomas/logging-streams branch Nov 18, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
3 participants
You can’t perform that action at this time.