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

Allocator and error handling in c utilities #16

Merged
merged 15 commits into from
Apr 19, 2017

Conversation

wjwwood
Copy link
Member

@wjwwood wjwwood commented Apr 12, 2017

This should help with ros2/rmw#94 and #6.

Pull requests to remove the duplicate functionality in rmw and rcl will follow, but the pr for gmock (ament/ament_cmake#91) can be merged at anytime.

I tried to take care to have a "move" commit and then a "change" commit.

@wjwwood wjwwood added enhancement New feature or request in progress Actively being worked on (Kanban column) labels Apr 12, 2017
@wjwwood wjwwood self-assigned this Apr 12, 2017
@wjwwood wjwwood force-pushed the allocator_and_error_handling_in_c_utilities branch from 4d16a5c to 516b15e Compare April 12, 2017 07:59
@wjwwood
Copy link
Member Author

wjwwood commented Apr 12, 2017

I still haven't figure out what to do with the memory tools that have been copied here. They are also used in rcl even after removing the allocator stuff later. I don't really want to create a new package for it, so I might expose the source files from this repository via a cmake macro, since they're useful for testing C or C++ in other packages.

CMakeLists.txt Outdated
test/test_split.cpp
)
if(TARGET test_split)
target_link_libraries(test_split c_utilities)
endif()

ament_add_gtest(test_find
ament_add_gmock(test_find
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why are the existing unmodified gtests changed into gmocks?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I thought I should only use gmock or gtest, but not both. I can change them back if that's not the case.

Copy link
Member Author

@wjwwood wjwwood Apr 14, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I never heard back from you on this, so I just did it anyways as not to delay this further: 3d746c0

@wjwwood wjwwood force-pushed the allocator_and_error_handling_in_c_utilities branch from 516b15e to 6b6bd1a Compare April 14, 2017 23:45
@wjwwood wjwwood force-pushed the allocator_and_error_handling_in_c_utilities branch from a642c12 to 3d746c0 Compare April 14, 2017 23:54
@wjwwood
Copy link
Member Author

wjwwood commented Apr 15, 2017

With respect to how to de-duplicate the memory_tools here and in rcl, I will address this in a follow on pull request after we do the renaming (#17). For two reasons, first I want to merge these pr's before doing the renaming and de-duplicating memory_tools is going to take a lot of time, and second because I want to refactor memory tools even more to be namespaced under this package's name and I'd rather not do it twice.

@wjwwood
Copy link
Member Author

wjwwood commented Apr 17, 2017

CI (fixed cmake linter error in 5a422fb):

  • Linux:
    • Build Status
  • Linux-aarch64:
    • Build Status
  • macOS:
    • Build Status (known compiler warning which should be fixed in latest version of Fast-RTPS)
  • Windows:
    • Build Status

I'm running new CI with some fixes, but this (and all related prs) can go in review now.

@wjwwood wjwwood added in review Waiting for review (Kanban column) and removed in progress Actively being worked on (Kanban column) labels Apr 17, 2017
@wjwwood
Copy link
Member Author

wjwwood commented Apr 17, 2017

Updated CI:

  • Linux:
    • Build Status
  • Linux-aarch64:
    • Build Status
  • macOS:
    • Build Status
  • Windows:
    • Build Status (known flaky test)

Copy link
Member

@mikaelarguedas mikaelarguedas left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks good, mostly nitpick at this point. I'll try to review this more thoroughly tomorrow. Thanks for pounding on this

#include <c_utilities/macros.h>

#ifndef UTILITIES_REPORT_ERROR_HANDLING_ERRORS
#define UTILITIES_REPORT_ERROR_HANDLING_ERRORS 1
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A comment here explaining what this is used for would be useful)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

#if UTILITIES_REPORT_ERROR_HANDLING_ERRORS
// Only warn of overwritting if the new error string is different from the old ones.
if (error_string != old_error_string && error_string != old_error_state->message) {
fprintf(
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should this use SAFE_FWRITE_TO_STDERR like the other error messages?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

or simply fwrite like above to be consistent

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This error message uses formatting (like %s), fwrite cannot do that. I only fallback to fwrite when memory allocation fails, because apparently it can still work on some systems even when malloc fails.

{
char * error_string = *error_string_ptr;
if (error_string) {
if (error_string) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe you meant:

if(error_string_ptr) {
  char * error_string = *error_string_ptr;
  if(error_string) {

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think so, I guess it was wrong in rmw as well.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if (error_state_ptr_ptr) {
utilities_error_state_t * error_state_ptr = *error_state_ptr_ptr;
if (error_state_ptr) {
utilities_allocator_t allocator = error_state_ptr->allocator;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

what happens if allocator is null? wouldnt deallocate not be defined?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

error_state_ptr may be null, but error_state_ptr->allocator cannot be null. error_state_ptr->allocator->deallocate can be null though. The assumption is (and I think it holds) that if error_state_ptr is not null, then the allocator will be valid as well. I can make it more defensive though.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

list(APPEND extra_test_env
DYLD_INSERT_LIBRARIES=$<TARGET_FILE:${PROJECT_NAME}_memory_tools_interpose>)
endif()
if(UNIX AND NOT APPLE)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: elseif(UNIX)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ASSERT_NE(mem, nullptr);
remem = realloc(mem, 2048);
ASSERT_NE(remem, nullptr);
if (!remem) {free(mem);}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Question: redundant condition? previous assert would have raised if this condition was not true, same below

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.


#include "./memory_tools.hpp"

/* Tests the allocatation checking tools.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

typo allocatation => allocation

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.


#include <string>

#include "gmock/gmock.h"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: should thi be included as system header?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Some of the other files are combining it with the system headers, but it's not a system header imo, i.e. it's not part of the standard library. So I don't think so, but I can I guess.

const char *
utilities_get_error_string_safe(void);

/// Resets the error state by clearing any previously set error state.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Typo/Consistency : Resets => Reset

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@wjwwood
Copy link
Member Author

wjwwood commented Apr 19, 2017

CI:

  • Linux:
    • Build Status
  • Linux-aarch64:
    • Build Status
  • macOS:
    • Build Status
  • Windows:
    • Build Status

I'm not sure about the issues on macOS, because I cannot reproduce them locally. I wasn't getting those errors until very recently. I'll look into it before merging.

@wjwwood
Copy link
Member Author

wjwwood commented Apr 19, 2017

Looks like something is amiss with mini1, dosa reports green for macOS:

Build Status

I'll merge now.

@wjwwood wjwwood merged commit 8d683f9 into master Apr 19, 2017
@wjwwood wjwwood deleted the allocator_and_error_handling_in_c_utilities branch April 19, 2017 19:37
@wjwwood wjwwood removed the in review Waiting for review (Kanban column) label Apr 19, 2017
list(APPEND extra_lib_dirs $<TARGET_FILE_DIR:${PROJECT_NAME}_memory_tools>)
target_link_libraries(${PROJECT_NAME}_memory_tools ${extra_test_libraries})
target_compile_definitions(${PROJECT_NAME}_memory_tools
PRIVATE "RCL_MEMORY_TOOLS_BUILDING_DLL")
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This RCL prefix hasn't been changed to RCUTILS.

The same for all the prefixes in the memory_tools.hpp.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for catching that, see: #24

thomas-moulard pushed a commit to aws-ros-dev/rcutils that referenced this pull request Apr 19, 2019
Call rcutils_logging_shutdown() in TearDown
to avoid leaking logging internal objects.

As any change to this file makes test_logging_named
fail, this releaxes the EXACT_EQ call on
g_last_log_event.location->line_number[1]. Instead
of looking for a particular value, we test an invariant
of the field (line numbers are positive).

Finally, in test_logging_function, initialize g_counter
and g_function_called values to make sure the test will
not fail even if `--gtest_repeat=2` is passed.

Other tests are still failing when this flag is passed:
[  FAILED  ] TestLoggingMacros.test_logging_once
[  FAILED  ] TestLoggingMacros.test_logging_skipfirst
[  FAILED  ] TestLoggingMacros.test_logging_skipfirst_throttle

However, fixing those tests would require actually changing
the logging implementation which is out of the scope of this
change.

Before:

    $ ./test_logging_macros
    Running main() from gmock_main.cc
    [==========] Running 8 tests from 1 test case.
    [----------] Global test environment set-up.
    [----------] 8 tests from TestLoggingMacros
    [ RUN      ] TestLoggingMacros.test_logging_named
    [       OK ] TestLoggingMacros.test_logging_named (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_once
    [       OK ] TestLoggingMacros.test_logging_once (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_expression
    [       OK ] TestLoggingMacros.test_logging_expression (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_function
    [       OK ] TestLoggingMacros.test_logging_function (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_skipfirst
    [       OK ] TestLoggingMacros.test_logging_skipfirst (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_throttle
    [       OK ] TestLoggingMacros.test_logging_throttle (302 ms)
    [ RUN      ] TestLoggingMacros.test_logging_skipfirst_throttle
    [       OK ] TestLoggingMacros.test_logging_skipfirst_throttle (302 ms)
    [ RUN      ] TestLoggingMacros.test_logger_hierarchy
    [       OK ] TestLoggingMacros.test_logger_hierarchy (0 ms)
    [----------] 8 tests from TestLoggingMacros (605 ms total)

    [----------] Global test environment tear-down
    [==========] 8 tests from 1 test case ran. (605 ms total)
    [  PASSED  ] 8 tests.

    =================================================================
    ==19903==ERROR: LeakSanitizer: detected memory leaks

    Direct leak of 504 byte(s) in 7 object(s) allocated from:
        #0 0x7fd640c1fb50 in __interceptor_malloc (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xdeb50)
        ros2#1 0x7fd64091cbb5 in __default_allocate (/home/.../ros2_ws/install-asan/rcutils/lib/librcutils.so+0x8bb5)
        ros2#2 0x7fd64092f1b0 in rcutils_string_map_init (/home/.../ros2_ws/install-asan/rcutils/lib/librcutils.so+0x1b1b0)
        ros2#3 0x7fd640926641 in rcutils_logging_initialize_with_allocator (/home/.../ros2_ws/install-asan/rcutils/lib/librcutils.so+0x12641)
        ros2#4 0x7fd6409261ab in rcutils_logging_initialize (/home/.../ros2_ws/install-asan/rcutils/lib/librcutils.so+0x121ab)
        ros2#5 0x564405fc6627 in TestLoggingMacros::SetUp() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x29627)
        ros2#6 0x564406045999 in void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0xa8999)
        ros2#7 0x564406037b7d in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x9ab7d)
        ros2#8 0x564405fe4503 in testing::Test::Run() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x47503)
        ros2#9 0x564405fe59e4 in testing::TestInfo::Run() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x489e4)
        ros2#10 0x564405fe6588 in testing::TestCase::Run() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x49588)
        ros2#11 0x564406001699 in testing::internal::UnitTestImpl::RunAllTests() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x64699)
        ros2#12 0x56440604844c in bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0xab44c)
        ros2#13 0x564406039e46 in bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x9ce46)
        ros2#14 0x564405ffe42d in testing::UnitTest::Run() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x6142d)
        ros2#15 0x564405fd197d in RUN_ALL_TESTS() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x3497d)
        ros2#16 0x564405fd18c3 in main (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x348c3)
        ros2#17 0x7fd63fd84b96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)

After:

    $ ./test_logging_macros
    Running main() from gmock_main.cc
    [==========] Running 9 tests from 1 test case.
    [----------] Global test environment set-up.
    [----------] 9 tests from TestLoggingMacros
    [ RUN      ] TestLoggingMacros.test_empty
    [       OK ] TestLoggingMacros.test_empty (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_named
    [       OK ] TestLoggingMacros.test_logging_named (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_once
    [       OK ] TestLoggingMacros.test_logging_once (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_expression
    [       OK ] TestLoggingMacros.test_logging_expression (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_function
    [       OK ] TestLoggingMacros.test_logging_function (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_skipfirst
    [       OK ] TestLoggingMacros.test_logging_skipfirst (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_throttle
    [       OK ] TestLoggingMacros.test_logging_throttle (303 ms)
    [ RUN      ] TestLoggingMacros.test_logging_skipfirst_throttle
    [       OK ] TestLoggingMacros.test_logging_skipfirst_throttle (302 ms)
    [ RUN      ] TestLoggingMacros.test_logger_hierarchy
    [       OK ] TestLoggingMacros.test_logger_hierarchy (0 ms)
    [----------] 9 tests from TestLoggingMacros (605 ms total)

    [----------] Global test environment tear-down
    [==========] 9 tests from 1 test case ran. (606 ms total)
    [  PASSED  ] 9 tests.

[1] https://testing.googleblog.com/2015/01/testing-on-toilet-change-detector-tests.html

Signed-off-by: Thomas Moulard <tmoulard@amazon.com>
wjwwood pushed a commit that referenced this pull request Apr 19, 2019
Call rcutils_logging_shutdown() in TearDown
to avoid leaking logging internal objects.

As any change to this file makes test_logging_named
fail, this releaxes the EXACT_EQ call on
g_last_log_event.location->line_number[1]. Instead
of looking for a particular value, we test an invariant
of the field (line numbers are positive).

Finally, in test_logging_function, initialize g_counter
and g_function_called values to make sure the test will
not fail even if `--gtest_repeat=2` is passed.

Other tests are still failing when this flag is passed:
[  FAILED  ] TestLoggingMacros.test_logging_once
[  FAILED  ] TestLoggingMacros.test_logging_skipfirst
[  FAILED  ] TestLoggingMacros.test_logging_skipfirst_throttle

However, fixing those tests would require actually changing
the logging implementation which is out of the scope of this
change.

Before:

    $ ./test_logging_macros
    Running main() from gmock_main.cc
    [==========] Running 8 tests from 1 test case.
    [----------] Global test environment set-up.
    [----------] 8 tests from TestLoggingMacros
    [ RUN      ] TestLoggingMacros.test_logging_named
    [       OK ] TestLoggingMacros.test_logging_named (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_once
    [       OK ] TestLoggingMacros.test_logging_once (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_expression
    [       OK ] TestLoggingMacros.test_logging_expression (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_function
    [       OK ] TestLoggingMacros.test_logging_function (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_skipfirst
    [       OK ] TestLoggingMacros.test_logging_skipfirst (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_throttle
    [       OK ] TestLoggingMacros.test_logging_throttle (302 ms)
    [ RUN      ] TestLoggingMacros.test_logging_skipfirst_throttle
    [       OK ] TestLoggingMacros.test_logging_skipfirst_throttle (302 ms)
    [ RUN      ] TestLoggingMacros.test_logger_hierarchy
    [       OK ] TestLoggingMacros.test_logger_hierarchy (0 ms)
    [----------] 8 tests from TestLoggingMacros (605 ms total)

    [----------] Global test environment tear-down
    [==========] 8 tests from 1 test case ran. (605 ms total)
    [  PASSED  ] 8 tests.

    =================================================================
    ==19903==ERROR: LeakSanitizer: detected memory leaks

    Direct leak of 504 byte(s) in 7 object(s) allocated from:
        #0 0x7fd640c1fb50 in __interceptor_malloc (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xdeb50)
        #1 0x7fd64091cbb5 in __default_allocate (/home/.../ros2_ws/install-asan/rcutils/lib/librcutils.so+0x8bb5)
        #2 0x7fd64092f1b0 in rcutils_string_map_init (/home/.../ros2_ws/install-asan/rcutils/lib/librcutils.so+0x1b1b0)
        #3 0x7fd640926641 in rcutils_logging_initialize_with_allocator (/home/.../ros2_ws/install-asan/rcutils/lib/librcutils.so+0x12641)
        #4 0x7fd6409261ab in rcutils_logging_initialize (/home/.../ros2_ws/install-asan/rcutils/lib/librcutils.so+0x121ab)
        #5 0x564405fc6627 in TestLoggingMacros::SetUp() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x29627)
        #6 0x564406045999 in void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0xa8999)
        #7 0x564406037b7d in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x9ab7d)
        #8 0x564405fe4503 in testing::Test::Run() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x47503)
        #9 0x564405fe59e4 in testing::TestInfo::Run() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x489e4)
        #10 0x564405fe6588 in testing::TestCase::Run() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x49588)
        #11 0x564406001699 in testing::internal::UnitTestImpl::RunAllTests() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x64699)
        #12 0x56440604844c in bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0xab44c)
        #13 0x564406039e46 in bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x9ce46)
        #14 0x564405ffe42d in testing::UnitTest::Run() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x6142d)
        #15 0x564405fd197d in RUN_ALL_TESTS() (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x3497d)
        #16 0x564405fd18c3 in main (/home/.../ros2_ws/build-asan/rcutils/test_logging_macros+0x348c3)
        #17 0x7fd63fd84b96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)

After:

    $ ./test_logging_macros
    Running main() from gmock_main.cc
    [==========] Running 9 tests from 1 test case.
    [----------] Global test environment set-up.
    [----------] 9 tests from TestLoggingMacros
    [ RUN      ] TestLoggingMacros.test_empty
    [       OK ] TestLoggingMacros.test_empty (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_named
    [       OK ] TestLoggingMacros.test_logging_named (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_once
    [       OK ] TestLoggingMacros.test_logging_once (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_expression
    [       OK ] TestLoggingMacros.test_logging_expression (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_function
    [       OK ] TestLoggingMacros.test_logging_function (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_skipfirst
    [       OK ] TestLoggingMacros.test_logging_skipfirst (0 ms)
    [ RUN      ] TestLoggingMacros.test_logging_throttle
    [       OK ] TestLoggingMacros.test_logging_throttle (303 ms)
    [ RUN      ] TestLoggingMacros.test_logging_skipfirst_throttle
    [       OK ] TestLoggingMacros.test_logging_skipfirst_throttle (302 ms)
    [ RUN      ] TestLoggingMacros.test_logger_hierarchy
    [       OK ] TestLoggingMacros.test_logger_hierarchy (0 ms)
    [----------] 9 tests from TestLoggingMacros (605 ms total)

    [----------] Global test environment tear-down
    [==========] 9 tests from 1 test case ran. (606 ms total)
    [  PASSED  ] 9 tests.

[1] https://testing.googleblog.com/2015/01/testing-on-toilet-change-detector-tests.html

Signed-off-by: Thomas Moulard <tmoulard@amazon.com>
thomas-moulard pushed a commit to aws-ros-dev/rcutils that referenced this pull request Apr 20, 2019
Add rcutils_logging_shutdown() every time needed
in test_logging.cpp. Remove spurious `g_rcutils_logging_initialized = false;`
preventing rcutils_logging_shutdown() from freeing memory.

Before:
  $ ./test_logging
  Running main() from ../../../install-asan/gtest_vendor/src/gtest_vendor/src/gtest_main.cc
  [==========] Running 5 tests from 1 test case.
  [----------] Global test environment set-up.
  [----------] 5 tests from TestLogging
  [ RUN      ] TestLogging.test_logging_initialization
  [       OK ] TestLogging.test_logging_initialization (0 ms)
  [ RUN      ] TestLogging.test_logging
  [       OK ] TestLogging.test_logging (0 ms)
  [ RUN      ] TestLogging.test_log_severity
  [       OK ] TestLogging.test_log_severity (0 ms)
  [ RUN      ] TestLogging.test_logger_severities
  [       OK ] TestLogging.test_logger_severities (0 ms)
  [ RUN      ] TestLogging.test_logger_severity_hierarchy
  [       OK ] TestLogging.test_logger_severity_hierarchy (0 ms)
  [----------] 5 tests from TestLogging (0 ms total)

  [----------] Global test environment tear-down
  [==========] 5 tests from 1 test case ran. (0 ms total)
  [  PASSED  ] 5 tests.

  =================================================================
  ==1676==ERROR: LeakSanitizer: detected memory leaks

  Direct leak of 72 byte(s) in 1 object(s) allocated from:
      #0 0x7f7a7229db50 in __interceptor_malloc (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xdeb50)
      ros2#1 0x7f7a71f9abb5 in __default_allocate (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x8bb5)
      ros2#2 0x7f7a71fad1b0 in rcutils_string_map_init (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x1b1b0)
      ros2#3 0x7f7a71fa4641 in rcutils_logging_initialize_with_allocator (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x12641)
      ros2#4 0x7f7a71fa41ab in rcutils_logging_initialize (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x121ab)
      ros2#5 0x561e9d22c972 in TestLogging_test_logging_Test::TestBody() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x1a972)
      ros2#6 0x561e9d2b545d in void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0xa345d)
      ros2#7 0x561e9d2a71c7 in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x951c7)
      ros2#8 0x561e9d2534c9 in testing::Test::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x414c9)
      ros2#9 0x561e9d2548f4 in testing::TestInfo::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x428f4)
      ros2#10 0x561e9d255498 in testing::TestCase::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x43498)
      ros2#11 0x561e9d2705a9 in testing::internal::UnitTestImpl::RunAllTests() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x5e5a9)
      ros2#12 0x561e9d2b7f10 in bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0xa5f10)
      ros2#13 0x561e9d2a9490 in bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x97490)
      ros2#14 0x561e9d26d33d in testing::UnitTest::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x5b33d)
      ros2#15 0x561e9d24088c in RUN_ALL_TESTS() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x2e88c)
      ros2#16 0x561e9d2407d2 in main (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x2e7d2)
      ros2#17 0x7f7a71402b96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)

  Direct leak of 72 byte(s) in 1 object(s) allocated from:
      #0 0x7f7a7229db50 in __interceptor_malloc (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xdeb50)
      ros2#1 0x7f7a71f9abb5 in __default_allocate (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x8bb5)
      ros2#2 0x7f7a71fad1b0 in rcutils_string_map_init (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x1b1b0)
      ros2#3 0x7f7a71fa4641 in rcutils_logging_initialize_with_allocator (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x12641)
      ros2#4 0x7f7a71fa41ab in rcutils_logging_initialize (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x121ab)
      ros2#5 0x561e9d22a9b6 in TestLogging_test_logging_initialization_Test::TestBody() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x189b6)
      ros2#6 0x561e9d2b545d in void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0xa345d)
      ros2#7 0x561e9d2a71c7 in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x951c7)
      ros2#8 0x561e9d2534c9 in testing::Test::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x414c9)
      ros2#9 0x561e9d2548f4 in testing::TestInfo::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x428f4)
      ros2#10 0x561e9d255498 in testing::TestCase::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x43498)
      ros2#11 0x561e9d2705a9 in testing::internal::UnitTestImpl::RunAllTests() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x5e5a9)
      ros2#12 0x561e9d2b7f10 in bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0xa5f10)
      ros2#13 0x561e9d2a9490 in bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x97490)
      ros2#14 0x561e9d26d33d in testing::UnitTest::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x5b33d)
      ros2#15 0x561e9d24088c in RUN_ALL_TESTS() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x2e88c)
      ros2#16 0x561e9d2407d2 in main (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x2e7d2)
      ros2#17 0x7f7a71402b96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)

  SUMMARY: AddressSanitizer: 144 byte(s) leaked in 2 allocation(s).

After:
  $ ./test_logging
  Running main() from ../../../install-asan/gtest_vendor/src/gtest_vendor/src/gtest_main.cc
  [==========] Running 5 tests from 1 test case.
  [----------] Global test environment set-up.
  [----------] 5 tests from TestLogging
  [ RUN      ] TestLogging.test_logging_initialization
  [       OK ] TestLogging.test_logging_initialization (0 ms)
  [ RUN      ] TestLogging.test_logging
  [       OK ] TestLogging.test_logging (0 ms)
  [ RUN      ] TestLogging.test_log_severity
  [       OK ] TestLogging.test_log_severity (0 ms)
  [ RUN      ] TestLogging.test_logger_severities
  [       OK ] TestLogging.test_logger_severities (0 ms)
  [ RUN      ] TestLogging.test_logger_severity_hierarchy
  [       OK ] TestLogging.test_logger_severity_hierarchy (0 ms)
  [----------] 5 tests from TestLogging (1 ms total)

  [----------] Global test environment tear-down
  [==========] 5 tests from 1 test case ran. (1 ms total)
  [  PASSED  ] 5 tests.

Signed-off-by: Thomas Moulard <tmoulard@amazon.com>
wjwwood pushed a commit that referenced this pull request Apr 20, 2019
Add rcutils_logging_shutdown() every time needed
in test_logging.cpp. Remove spurious `g_rcutils_logging_initialized = false;`
preventing rcutils_logging_shutdown() from freeing memory.

Before:
  $ ./test_logging
  Running main() from ../../../install-asan/gtest_vendor/src/gtest_vendor/src/gtest_main.cc
  [==========] Running 5 tests from 1 test case.
  [----------] Global test environment set-up.
  [----------] 5 tests from TestLogging
  [ RUN      ] TestLogging.test_logging_initialization
  [       OK ] TestLogging.test_logging_initialization (0 ms)
  [ RUN      ] TestLogging.test_logging
  [       OK ] TestLogging.test_logging (0 ms)
  [ RUN      ] TestLogging.test_log_severity
  [       OK ] TestLogging.test_log_severity (0 ms)
  [ RUN      ] TestLogging.test_logger_severities
  [       OK ] TestLogging.test_logger_severities (0 ms)
  [ RUN      ] TestLogging.test_logger_severity_hierarchy
  [       OK ] TestLogging.test_logger_severity_hierarchy (0 ms)
  [----------] 5 tests from TestLogging (0 ms total)

  [----------] Global test environment tear-down
  [==========] 5 tests from 1 test case ran. (0 ms total)
  [  PASSED  ] 5 tests.

  =================================================================
  ==1676==ERROR: LeakSanitizer: detected memory leaks

  Direct leak of 72 byte(s) in 1 object(s) allocated from:
      #0 0x7f7a7229db50 in __interceptor_malloc (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xdeb50)
      #1 0x7f7a71f9abb5 in __default_allocate (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x8bb5)
      #2 0x7f7a71fad1b0 in rcutils_string_map_init (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x1b1b0)
      #3 0x7f7a71fa4641 in rcutils_logging_initialize_with_allocator (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x12641)
      #4 0x7f7a71fa41ab in rcutils_logging_initialize (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x121ab)
      #5 0x561e9d22c972 in TestLogging_test_logging_Test::TestBody() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x1a972)
      #6 0x561e9d2b545d in void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0xa345d)
      #7 0x561e9d2a71c7 in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x951c7)
      #8 0x561e9d2534c9 in testing::Test::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x414c9)
      #9 0x561e9d2548f4 in testing::TestInfo::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x428f4)
      #10 0x561e9d255498 in testing::TestCase::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x43498)
      #11 0x561e9d2705a9 in testing::internal::UnitTestImpl::RunAllTests() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x5e5a9)
      #12 0x561e9d2b7f10 in bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0xa5f10)
      #13 0x561e9d2a9490 in bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x97490)
      #14 0x561e9d26d33d in testing::UnitTest::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x5b33d)
      #15 0x561e9d24088c in RUN_ALL_TESTS() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x2e88c)
      #16 0x561e9d2407d2 in main (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x2e7d2)
      #17 0x7f7a71402b96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)

  Direct leak of 72 byte(s) in 1 object(s) allocated from:
      #0 0x7f7a7229db50 in __interceptor_malloc (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xdeb50)
      #1 0x7f7a71f9abb5 in __default_allocate (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x8bb5)
      #2 0x7f7a71fad1b0 in rcutils_string_map_init (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x1b1b0)
      #3 0x7f7a71fa4641 in rcutils_logging_initialize_with_allocator (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x12641)
      #4 0x7f7a71fa41ab in rcutils_logging_initialize (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/install-asan/rcutils/lib/librcutils.so+0x121ab)
      #5 0x561e9d22a9b6 in TestLogging_test_logging_initialization_Test::TestBody() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x189b6)
      #6 0x561e9d2b545d in void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0xa345d)
      #7 0x561e9d2a71c7 in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x951c7)
      #8 0x561e9d2534c9 in testing::Test::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x414c9)
      #9 0x561e9d2548f4 in testing::TestInfo::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x428f4)
      #10 0x561e9d255498 in testing::TestCase::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x43498)
      #11 0x561e9d2705a9 in testing::internal::UnitTestImpl::RunAllTests() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x5e5a9)
      #12 0x561e9d2b7f10 in bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0xa5f10)
      #13 0x561e9d2a9490 in bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x97490)
      #14 0x561e9d26d33d in testing::UnitTest::Run() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x5b33d)
      #15 0x561e9d24088c in RUN_ALL_TESTS() (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x2e88c)
      #16 0x561e9d2407d2 in main (/home/ANT.AMAZON.COM/tmoulard/ros2_ws/build-asan/rcutils/test_logging+0x2e7d2)
      #17 0x7f7a71402b96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)

  SUMMARY: AddressSanitizer: 144 byte(s) leaked in 2 allocation(s).

After:
  $ ./test_logging
  Running main() from ../../../install-asan/gtest_vendor/src/gtest_vendor/src/gtest_main.cc
  [==========] Running 5 tests from 1 test case.
  [----------] Global test environment set-up.
  [----------] 5 tests from TestLogging
  [ RUN      ] TestLogging.test_logging_initialization
  [       OK ] TestLogging.test_logging_initialization (0 ms)
  [ RUN      ] TestLogging.test_logging
  [       OK ] TestLogging.test_logging (0 ms)
  [ RUN      ] TestLogging.test_log_severity
  [       OK ] TestLogging.test_log_severity (0 ms)
  [ RUN      ] TestLogging.test_logger_severities
  [       OK ] TestLogging.test_logger_severities (0 ms)
  [ RUN      ] TestLogging.test_logger_severity_hierarchy
  [       OK ] TestLogging.test_logger_severity_hierarchy (0 ms)
  [----------] 5 tests from TestLogging (1 ms total)

  [----------] Global test environment tear-down
  [==========] 5 tests from 1 test case ran. (1 ms total)
  [  PASSED  ] 5 tests.

Signed-off-by: Thomas Moulard <tmoulard@amazon.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants